From 02471b6c909e57aeb2c6d9a08b2df384fa419c69 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Sat, 19 Jul 2025 14:39:47 +0200 Subject: [PATCH 1/5] add trace options --- DOCUMENTATION.md | 18 ++++++++++++++++++ config | 6 ++++++ radicale/config.py | 8 ++++++++ 3 files changed, 32 insertions(+) diff --git a/DOCUMENTATION.md b/DOCUMENTATION.md index be7fe021..d00cd01a 100644 --- a/DOCUMENTATION.md +++ b/DOCUMENTATION.md @@ -1420,6 +1420,24 @@ Available levels: **debug**, **info**, **warning**, **error**, **critical** Default: `warning` _(< 3.2.0)_ `info` _(>= 3.2.0)_ +##### trace_on_debug + +_(> 3.5.4)_ + +Do not filter debug messages starting with 'TRACE' + +Default: `False` + +##### trace_filter + +_(> 3.5.4)_ + +Filter debug messages starting with 'TRACE/' + +Precondition: `trace_on_debug = True` + +Default: (empty) + ##### mask_passwords Don't include passwords in logs. diff --git a/config b/config index ab2ea7eb..51e5324c 100644 --- a/config +++ b/config @@ -272,6 +272,12 @@ # Value: debug | info | warning | error | critical #level = info +# do not filter debug messages starting with 'TRACE' +#trace_on_debug = False + +# filter debug messages starting with 'TRACE/' +#trace_filter = "" + # Don't include passwords in logs #mask_passwords = True diff --git a/radicale/config.py b/radicale/config.py index 15405063..7deee5ca 100644 --- a/radicale/config.py +++ b/radicale/config.py @@ -509,6 +509,14 @@ This is an automated message. Please do not reply.""", "value": "info", "help": "threshold for the logger", "type": logging_level}), + ("trace_on_debug", { + "value": "False", + "help": "do not filter debug messages starting with 'TRACE'", + "type": bool}), + ("trace_filter", { + "value": "", + "help": "filter debug messages starting with 'TRACE/'", + "type": str}), ("bad_put_request_content", { "value": "False", "help": "log bad PUT request content", From ef1c2b835fc5f2a5a290b49167f2f99be4c0afb6 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Sat, 19 Jul 2025 14:40:12 +0200 Subject: [PATCH 2/5] implement trace option --- radicale/__init__.py | 5 ++++- radicale/__main__.py | 5 ++++- radicale/log.py | 40 +++++++++++++++++++++++++++++++++++++++- 3 files changed, 47 insertions(+), 3 deletions(-) diff --git a/radicale/__init__.py b/radicale/__init__.py index 2554e5b2..8924d507 100644 --- a/radicale/__init__.py +++ b/radicale/__init__.py @@ -52,7 +52,10 @@ def _get_application_instance(config_path: str, wsgi_errors: types.ErrorStream configuration = config.load(config.parse_compound_paths( config.DEFAULT_CONFIG_PATH, config_path)) - log.set_level(cast(str, configuration.get("logging", "level")), configuration.get("logging", "backtrace_on_debug")) + log.set_level(cast(str, configuration.get("logging", "level")), + configuration.get("logging", "backtrace_on_debug"), + configuration.get("logging", "trace_on_debug"), + configuration.get("logging", "trace_filter")) # Log configuration after logger is configured default_config_active = True for source, miss in configuration.sources(): diff --git a/radicale/__main__.py b/radicale/__main__.py index 25d2b853..b3576a60 100644 --- a/radicale/__main__.py +++ b/radicale/__main__.py @@ -165,7 +165,10 @@ def run() -> None: sys.exit(1) # Configure logging - log.set_level(cast(str, configuration.get("logging", "level")), configuration.get("logging", "backtrace_on_debug")) + log.set_level(cast(str, configuration.get("logging", "level")), + configuration.get("logging", "backtrace_on_debug"), + configuration.get("logging", "trace_on_debug"), + configuration.get("logging", "trace_filter")) # Log configuration after logger is configured default_config_active = True diff --git a/radicale/log.py b/radicale/log.py index 1dde25d2..7f7df5e3 100644 --- a/radicale/log.py +++ b/radicale/log.py @@ -57,8 +57,35 @@ class RemoveTracebackFilter(logging.Filter): return True +class RemoveTRACEFilter(logging.Filter): + + def filter(self, record: logging.LogRecord) -> bool: + if record.msg.startswith("TRACE"): + return False + else: + return True + + +class PassTRACETOKENFilter(logging.Filter): + def __init__(self, trace_filter: str): + super().__init__() + self.trace_filter = trace_filter + self.prefix = "TRACE/" + self.trace_filter + + def filter(self, record: logging.LogRecord) -> bool: + if record.msg.startswith("TRACE"): + if record.msg.startswith(self.prefix): + return True + else: + return False + else: + return True + + REMOVE_TRACEBACK_FILTER: logging.Filter = RemoveTracebackFilter() +REMOVE_TRACE_FILTER: logging.Filter = RemoveTRACEFilter() + class IdentLogRecordFactory: """LogRecordFactory that adds ``ident`` attribute.""" @@ -231,7 +258,7 @@ logger_display_backtrace_disabled: bool = False logger_display_backtrace_enabled: bool = False -def set_level(level: Union[int, str], backtrace_on_debug: bool) -> None: +def set_level(level: Union[int, str], backtrace_on_debug: bool, trace_on_debug: bool = False, trace_filter: str = "") -> None: """Set logging level for global logger.""" global logger_display_backtrace_disabled global logger_display_backtrace_enabled @@ -255,3 +282,14 @@ def set_level(level: Union[int, str], backtrace_on_debug: bool) -> None: logger.debug("Logging of backtrace is enabled by option in this loglevel") logger_display_backtrace_enabled = True logger.removeFilter(REMOVE_TRACEBACK_FILTER) + if trace_on_debug: + if trace_filter != "": + logger.debug("Logging messages starting with 'TRACE/%s' enabled", trace_filter) + logger.addFilter(PassTRACETOKENFilter(trace_filter)) + logger.removeFilter(REMOVE_TRACE_FILTER) + else: + logger.debug("Logging messages starting with 'TRACE' enabled") + logger.removeFilter(REMOVE_TRACE_FILTER) + else: + logger.debug("Logging messages starting with 'TRACE' disabled") + logger.addFilter(REMOVE_TRACE_FILTER) From d5b589a5720027bd763a10560f0ab0302afedac0 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Sat, 19 Jul 2025 14:40:27 +0200 Subject: [PATCH 3/5] show trace status on startup --- radicale/server.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/radicale/server.py b/radicale/server.py index e437286a..55e112e2 100644 --- a/radicale/server.py +++ b/radicale/server.py @@ -340,6 +340,8 @@ def serve(configuration: config.Configuration, select_timeout = 1.0 max_connections: int = configuration.get("server", "max_connections") logger.info("Radicale server ready") + logger.debug("TRACE: Radicale server ready ('logging/trace_on_debug' is active)") + logger.debug("TRACE/SERVER: Radicale server ready ('logging/trace_on_debug' is active - either with 'SERVER' or empty filter)") while True: rlist: List[socket.socket] = [] # Wait for finished clients From be6fcd4b8a6d2737c166bf6fb64b45c2557324ae Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Sat, 19 Jul 2025 14:42:18 +0200 Subject: [PATCH 4/5] extend changelog related to trace --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index f78f5d6a..ec1b5eeb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,7 @@ * Feature: add hook for server-side e-mail notification * Fix: logging ignores not retrievable get_native_id if not supported by OS * Fix: report with enabled expand honors now provided filter proper +* Improve: add options [logging] trace_on_debug and trace_filter for supporting trace logging ## 3.5.4 * Improve: item filter enhanced for 3rd level supporting VALARM and honoring TRIGGER (offset or absolute) From f31f5779f547833029ed2dd8569abe7b7ffc3a5c Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Sat, 19 Jul 2025 14:46:46 +0200 Subject: [PATCH 5/5] add pytestdebug.log --- .gitignore | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.gitignore b/.gitignore index 5a0363a0..87b83643 100644 --- a/.gitignore +++ b/.gitignore @@ -23,3 +23,5 @@ coverage.xml .vscode .sass-cache Gemfile.lock + +pytestdebug.log