From e695c2836475f13e3b7620bff7da50b6ce75c963 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:18:26 +0200 Subject: [PATCH 1/8] config/parser: add support for log on_notice_condition --- radicale/config.py | 78 ++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 78 insertions(+) diff --git a/radicale/config.py b/radicale/config.py index a592f2d0..5155876b 100644 --- a/radicale/config.py +++ b/radicale/config.py @@ -27,9 +27,11 @@ Use ``load()`` to obtain an instance of ``Configuration`` for use with """ import contextlib +import ipaddress import json import math import os +import re import string import sys from collections import OrderedDict @@ -167,6 +169,66 @@ def json_str(value: Any) -> dict: return ret +def json_str_condition(value: Any) -> dict: + if not value: + return {} + ret = json.loads(value) + for (token, props) in ret.items(): + checked_props = check_and_sanitize_props(props) + # check token + if token not in log.LOG_CONDITION_TOKEN: + raise ValueError("unsupported log condition token: %r" % token) + # check condition entry + for cond_name in checked_props: + if cond_name not in log.LOG_CONDITION_CONDITION: + raise ValueError("unsupported log condition: %r" % cond_name) + if cond_name == "match": + if log.LOG_CONDITION_TOKEN[token] == "str": + if checked_props[cond_name] not in log.LOG_CONDITION_MATCH_STR: + raise ValueError("unsupported log match: %r" % checked_props[cond_name]) + elif log.LOG_CONDITION_TOKEN[token] == "int": + if checked_props[cond_name] not in log.LOG_CONDITION_MATCH_INT: + raise ValueError("unsupported log match: %r" % checked_props[cond_name]) + elif log.LOG_CONDITION_TOKEN[token] == "ipaddress": + if checked_props[cond_name] not in log.LOG_CONDITION_MATCH_IPADDRESS + log.LOG_CONDITION_MATCH_IPNETWORK: + raise ValueError("unsupported log match: %r" % checked_props[cond_name]) + else: + raise RuntimeError("unsupported log match (fix code): %r" % cond_name) + if cond_name == "value": + if log.LOG_CONDITION_TOKEN[token] == "str": + if checked_props["match"] == "re": + try: + if re.match(checked_props[cond_name], "Test"): + pass + else: + pass + except Exception as e: + raise ValueError("unsupported log match value(re) for condition %r: %r (%s)" % (checked_props["match"], checked_props[cond_name], e)) + pass + elif log.LOG_CONDITION_TOKEN[token] == "int": + if str(int(checked_props[cond_name])) != checked_props[cond_name]: + raise ValueError("unsupported log match value(int): %r" % checked_props[cond_name]) + if token == "status": + # only 100-599 are valid + if int(checked_props[cond_name]) < 100 or int(checked_props[cond_name]) > 599: + raise ValueError("unsupported log match value(int) not in range 100-599: %r" % checked_props[cond_name]) + elif log.LOG_CONDITION_TOKEN[token] == "ipaddress": + try: + if checked_props["match"] in log.LOG_CONDITION_MATCH_IPADDRESS: + ip = ipaddress.ip_address(checked_props[cond_name]) # noqa: F841 + elif checked_props["match"] in log.LOG_CONDITION_MATCH_IPNETWORK: + ip_net = ipaddress.ip_network(checked_props[cond_name], strict=True) # noqa: F841 + except Exception as e: + raise ValueError("unsupported log match value(ipaddress) for condition %r: %r (%s)" % (checked_props["match"], checked_props[cond_name], e)) + # check condition entries are complete + for cond_name in log.LOG_CONDITION_CONDITION: + if cond_name not in checked_props: + raise ValueError("incomplete condition, misses: %r" % cond_name) + # all checks passed + ret[token] = checked_props + return ret + + INTERNAL_OPTIONS: Sequence[str] = ("_allow_extra",) # Default configuration DEFAULT_CONFIG_SCHEMA: types.CONFIG_SCHEMA = OrderedDict([ @@ -667,6 +729,22 @@ This is an automated message. Please do not reply.""", "value": "False", "help": "log response content on level=debug", "type": bool}), + ("request_header_on_notice_condition", { + "value": "{}", + "help": "log request header on level=notice with condition", + "type": json_str_condition}), + ("request_content_on_notice_condition", { + "value": "{}", + "help": "log request content on level=notice with condition", + "type": json_str_condition}), + ("response_header_on_notice_condition", { + "value": "{}", + "help": "log response header on level=notice with condition", + "type": json_str_condition}), + ("response_content_on_notice_condition", { + "value": "{}", + "help": "log response content on level=notice with condition", + "type": json_str_condition}), ("rights_rule_doesnt_match_on_debug", { "value": "False", "help": "log rights rules which doesn't match on level=debug", From 401f9c39ae02f1276b0d359d5e2f360c3e8f24b7 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:19:00 +0200 Subject: [PATCH 2/8] config/example: extend for log on_notice_condition --- config | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/config b/config index 77fe4805..59888a99 100644 --- a/config +++ b/config @@ -397,6 +397,18 @@ # Log response content on level=debug #response_content_on_debug = False +# Log request header on level=notice with condition +#request_header_on_notice_condition = {} + +# Log request content on level=notice with condition +#request_content_on_notice_condition = {} + +# Log response header on level=notice with condition +#response_header_on_notice_condition = {} + +# Log response content on level=notice with condition +#response_content_on_notice_condition = {} + # Log rights rule which doesn't match on level=debug #rights_rule_doesnt_match_on_debug = False From c4487dd37fda9a1fb96934e13f455fa69d784e2e Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:19:33 +0200 Subject: [PATCH 3/8] doc: extend for log on_notice_condition --- DOCUMENTATION.md | 59 ++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 59 insertions(+) diff --git a/DOCUMENTATION.md b/DOCUMENTATION.md index 3771013a..6736ae6e 100644 --- a/DOCUMENTATION.md +++ b/DOCUMENTATION.md @@ -1803,6 +1803,65 @@ Log response content (body) on `level = debug` Default: `False` +##### request_header_on_notice_condition + +_(>= 3.7.3)_ + +Log request header on `level = notice` if condition is fulfilled + +Default: `{}` + +Format: JSON structure as text + +Supported tokens: + * `method` + * `path` + * `useragent` + * `host` (IPv4/IPv6 address/network) + * `login` + * `status` (only supported on responses) + +Supported matches: + * str: `startswith`, `endswith`, `equal`, `re` + * int: `==`, `<`, `<=`, `>=`, `>`, `!=` + * IP address: `equal`, `==`, `!=` + * IP network: `included`, `excluded` + +Examples: + * `{"method": {"match": "equal", "value": "GET"}, "login": {"match": "equal", "value": "owner"}}` + * `{"method": {"match": "equal", "value": "PUT"}, "status": {"match": ">=", "value": "201"}, "host": {"match": "included", "value": "127.0.0.0/8"}}` + * `{"method": {"match": "equal", "value": "PUT"}, "path": {"match": "re", "value": "ev?nt[01]"}}` + +##### request_content_on_notice_condition + +_(>= 3.7.3)_ + +Log request content (body) on `level = notice` if condition is fulfilled + +Default: `{}` + +Format: see `request_header_on_notice_condition` + +##### response_header_on_notice_condition + +_(>= 3.7.3)_ + +Log response header on `level = notice` if condition is fulfilled + +Default: `{}` + +Format: see `request_header_on_notice_condition` + +##### response_content_on_notice_condition + +_(>= 3.7.3)_ + +Log response content (body) on `level = notice` if condition is fulfilled + +Default: `{}` + +Format: see `request_header_on_notice_condition` + ##### rights_rule_doesnt_match_on_debug _(>= 3.2.3)_ From b6805177f74ffc56170c95c7ed4cf4f3fece12e5 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:20:31 +0200 Subject: [PATCH 4/8] log on_notice_condition: read config values --- radicale/app/__init__.py | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/radicale/app/__init__.py b/radicale/app/__init__.py index 46814e44..6655233a 100644 --- a/radicale/app/__init__.py +++ b/radicale/app/__init__.py @@ -130,6 +130,14 @@ class Application(ApplicationPartDelete, ApplicationPartHead, logger.debug("log request content on debug: %s", self._request_content_on_debug) logger.debug("log response header on debug: %s", self._response_header_on_debug) logger.debug("log response content on debug: %s", self._response_content_on_debug) + self._request_header_on_notice_condition = configuration.get("logging", "request_header_on_notice_condition") + self._request_content_on_notice_condition = configuration.get("logging", "request_content_on_notice_condition") + self._response_header_on_notice_condition = configuration.get("logging", "response_header_on_notice_condition") + self._response_content_on_notice_condition = configuration.get("logging", "response_content_on_notice_condition") + logger.notice("log request header on notice condition: %s", self._request_header_on_notice_condition) + logger.notice("log request content on notice condition: %s", self._request_content_on_notice_condition) + logger.notice("log response header on notice condition: %s", self._response_header_on_notice_condition) + logger.notice("log response content on notice condition: %s", self._response_content_on_notice_condition) self._limit_content = configuration.get("logging", "limit_content") logger.debug("log limit for content: %d", self._limit_content) self._auth_delay = configuration.get("auth", "delay") From b9ec1c223f3c013f1dd4cb417f03105f8cb338d8 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:29:59 +0200 Subject: [PATCH 5/8] log on_notice_condition: implementation --- radicale/app/__init__.py | 59 ++++++++++++++++---- radicale/app/base.py | 50 ++++++++++++----- radicale/app/delete.py | 4 +- radicale/app/get.py | 4 +- radicale/app/head.py | 4 +- radicale/app/mkcalendar.py | 6 +-- radicale/app/mkcol.py | 4 +- radicale/app/move.py | 4 +- radicale/app/options.py | 2 +- radicale/app/post.py | 6 +-- radicale/app/propfind.py | 7 +-- radicale/app/proppatch.py | 11 ++-- radicale/app/put.py | 7 +-- radicale/app/report.py | 16 +++--- radicale/httputils.py | 25 ++++++--- radicale/log.py | 102 +++++++++++++++++++++++++++++++++++ radicale/sharing/__init__.py | 4 +- radicale/tests/custom/web.py | 6 +-- radicale/web/__init__.py | 8 ++- radicale/web/internal.py | 2 +- radicale/web/none.py | 2 +- 21 files changed, 263 insertions(+), 70 deletions(-) diff --git a/radicale/app/__init__.py b/radicale/app/__init__.py index 6655233a..2e9bb96d 100644 --- a/radicale/app/__init__.py +++ b/radicale/app/__init__.py @@ -282,7 +282,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead, """Manage a request.""" def response(status: int, headers: types.WSGIResponseHeaders, answer: Union[None, str, bytes], - xml_request: Union[None, str] = None) -> _IntermediateResponse: + xml_request: Union[None, str] = None, request_info: dict = {}) -> _IntermediateResponse: """Helper to create response from internal types.WSGIResponse""" headers = dict(headers) content_encoding = "plain" @@ -294,8 +294,16 @@ class Application(ApplicationPartDelete, ApplicationPartHead, if logger.isEnabledFor(logging.DEBUG): logger.debug("Response content (nonXML):\n%s", utils.textwrap_str(answer, self._limit_content)) else: - if logger.isEnabledFor(logging.DEBUG): - logger.debug("Response content: suppressed by config/option [logging] response_content_on_debug") + if self._response_content_on_notice_condition != {}: + if log.log_conditional( + "response-content", + condition=self._response_content_on_notice_condition, + value=request_info, + ): + logger.notice("Response content (nonXML, log condition passed):\n%s", utils.textwrap_str(answer, self._limit_content)) + else: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Response content: suppressed by config/option [logging] response_content_on_debug") headers["Content-Type"] += "; charset=%s" % self._encoding answer = answer.encode(self._encoding) accept_encoding = [ @@ -315,12 +323,22 @@ class Application(ApplicationPartDelete, ApplicationPartHead, # Add extra headers set in configuration headers.update(self._extra_headers) + request_info["status"] = status + if self._response_header_on_debug: if logger.isEnabledFor(logging.DEBUG): logger.debug("Response header:\n%s", utils.textwrap_str(pprint.pformat(headers), self._limit_content)) else: - if logger.isEnabledFor(logging.DEBUG): - logger.debug("Response header: suppressed by config/option [logging] response_header_on_debug") + if self._response_header_on_notice_condition != {}: + if log.log_conditional( + "response-header", + condition=self._response_header_on_notice_condition, + value=request_info, + ): + logger.notice("Response header (log condition passed):\n%s", utils.textwrap_str(pprint.pformat(headers), self._limit_content)) + else: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Response header: suppressed by config/option [logging] response_header_on_debug") # Start response # delay on error @@ -436,8 +454,10 @@ class Application(ApplicationPartDelete, ApplicationPartHead, if environ.get("HTTP_X_FORWARDED_HOST") or environ.get("HTTP_X_FORWARDED_PROTO") or environ.get("HTTP_X_FORWARDED_SERVER"): reverse_proxy = True remote_useragent = "" + remote_useragent_txt = "" if environ.get("HTTP_USER_AGENT"): - remote_useragent = " using %r" % environ["HTTP_USER_AGENT"] + remote_useragent = environ["HTTP_USER_AGENT"] + remote_useragent_txt = " using %r" % environ["HTTP_USER_AGENT"] depthinfo = "" if environ.get("HTTP_DEPTH"): depthinfo = " with depth %r" % environ["HTTP_DEPTH"] @@ -447,12 +467,14 @@ class Application(ApplicationPartDelete, ApplicationPartHead, https_info = "" logger.info("%s request for %r%s received from %s%s%s", request_method, unsafe_path, depthinfo, - remote_host, remote_useragent, https_info) + remote_host, remote_useragent_txt, https_info) if self._request_header_on_debug: logger.debug("Request header:\n%s", utils.textwrap_str(pprint.pformat(self._scrub_headers(environ)), self._limit_content)) else: - logger.debug("Request header: suppressed by config/option [logging] request_header_on_debug") + if not self._request_header_on_notice_condition != {}: + # conditional request header logging is later + logger.debug("Request header: suppressed by config/option [logging] request_header_on_debug") # SCRIPT_NAME is already removed from PATH_INFO, according to the # WSGI specification. @@ -535,6 +557,23 @@ class Application(ApplicationPartDelete, ApplicationPartHead, self._rights._user_groups = self._auth._ldap_groups except AttributeError: pass + + request_info: dict = { + "method": request_method, + "login": login, # not 'user' in this step + "path": path, + "useragent": remote_useragent, + "host": remote_host, + } + + if not self._request_header_on_debug and self._request_header_on_notice_condition != {}: + if log.log_conditional( + "request-header", + condition=self._request_header_on_notice_condition, + value=request_info, + ): + logger.notice("Request header (log condition passed):\n%s", utils.textwrap_str(pprint.pformat(self._scrub_headers(environ)), self._limit_content)) + if user and login == user: logger.info("Successful login: %r (%s)", user, info) elif user: @@ -619,7 +658,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead, try: status, headers, answer, xml_request = function( - environ, base_prefix, path, user, remote_host, remote_useragent) + environ, base_prefix, path, user, request_info) except PermissionError as e: logger.error("PermissionError: %s", e) status, headers, answer, xml_request = httputils.INTERNAL_SERVER_ERROR @@ -656,4 +695,4 @@ class Application(ApplicationPartDelete, ApplicationPartHead, "WWW-Authenticate": "Basic realm=\"%s\"" % self._auth_realm}) - return response(status, headers, answer, xml_request) + return response(status, headers, answer, xml_request, request_info) diff --git a/radicale/app/base.py b/radicale/app/base.py index 63993a9a..cd64e253 100644 --- a/radicale/app/base.py +++ b/radicale/app/base.py @@ -23,7 +23,7 @@ import unicodedata import xml.etree.ElementTree as ET from typing import Optional, Union -from radicale import (auth, config, hook, httputils, pathutils, rights, +from radicale import (auth, config, hook, httputils, log, pathutils, rights, sharing, storage, types, utils, web, xmlutils) from radicale.log import logger from radicale.rights import intersect @@ -137,12 +137,16 @@ class ApplicationBase: self._log_bad_put_request_content = configuration.get("logging", "bad_put_request_content") self._response_content_on_debug = configuration.get("logging", "response_content_on_debug") self._request_content_on_debug = configuration.get("logging", "request_content_on_debug") + self._response_content_on_notice_condition = configuration.get("logging", "response_content_on_notice_condition") + self._request_content_on_notice_condition = configuration.get("logging", "request_content_on_notice_condition") self._limit_content = configuration.get("logging", "limit_content") self._validate_user_value = configuration.get("server", "validate_user_value") self._validate_path_value = configuration.get("server", "validate_path_value") self._hook = hook.load(configuration) - def _read_xml_request_body(self, environ: types.WSGIEnviron + def _read_xml_request_body(self, + environ: types.WSGIEnviron, + request_info: dict, ) -> Optional[ET.Element]: content = httputils.decode_request( self.configuration, environ, @@ -154,19 +158,41 @@ class ApplicationBase: except ET.ParseError as e: logger.debug("Request content (Invalid XML):\n%s", content) raise RuntimeError("Failed to parse XML: %s" % e) from e - if logger.isEnabledFor(logging.DEBUG): - if self._request_content_on_debug: - logger.debug("Request content (XML):\n%s", - utils.textwrap_str(xmlutils.pretty_xml(xml_content))) + if self._request_content_on_debug: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Request content (XML):\n%s", utils.textwrap_str(xmlutils.pretty_xml(xml_content))) + else: + if self._request_content_on_notice_condition != {}: + if log.log_conditional( + "request-content", + condition=self._request_content_on_notice_condition, + value=request_info, + ): + logger.notice("Request content (XML, log condition passed):\n%s", utils.textwrap_str(xmlutils.pretty_xml(xml_content))) + else: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Request content (XML, log condition skipped): suppressed") else: - logger.debug("Request content (XML): suppressed by config/option [logging] request_content_on_debug") + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Request content (XML): suppressed by config/option [logging] request_content_on_debug") return xml_content - def _xml_response(self, xml_content: ET.Element) -> bytes: - if logger.isEnabledFor(logging.DEBUG): - if self._response_content_on_debug: + def _xml_response(self, xml_content: ET.Element, request_info: dict) -> bytes: + if self._response_content_on_debug: + if logger.isEnabledFor(logging.DEBUG): logger.debug("Response content (XML):\n%s", utils.textwrap_str(xmlutils.pretty_xml(xml_content), self._limit_content)) + else: + if self._response_content_on_notice_condition != {}: + if log.log_conditional( + "response-content", + condition=self._response_content_on_notice_condition, + value=request_info, + ): + logger.notice("Response content (XML, log condition passed):\n%s", utils.textwrap_str(xmlutils.pretty_xml(xml_content))) + else: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Response content (XML, log condition skipped): suppressed") else: logger.debug("Response content (XML): suppressed by config/option [logging] response_content_on_debug") f = io.BytesIO() @@ -174,11 +200,11 @@ class ApplicationBase: xml_declaration=True) return f.getvalue() - def _webdav_error_response(self, status: int, human_tag: str + def _webdav_error_response(self, status: int, human_tag: str, request_info: dict ) -> types.WSGIResponse: """Generate XML error response.""" headers = {"Content-Type": "text/xml; charset=%s" % self._encoding} - content = self._xml_response(xmlutils.webdav_error(human_tag)) + content = self._xml_response(xmlutils.webdav_error(human_tag), request_info) return status, headers, content, None diff --git a/radicale/app/delete.py b/radicale/app/delete.py index 5388e86d..38357f61 100644 --- a/radicale/app/delete.py +++ b/radicale/app/delete.py @@ -55,7 +55,7 @@ def xml_delete(base_prefix: str, path: str, collection: storage.BaseCollection, class ApplicationPartDelete(ApplicationBase): def do_DELETE(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage DELETE request.""" actor = user permissions_filter = None @@ -126,4 +126,4 @@ class ApplicationPartDelete(ApplicationBase): for notification_item in hook_notification_item_list: # Will be empty if hook not enabled self._hook.notify(notification_item) headers = {"Content-Type": "text/xml; charset=%s" % self._encoding} - return client.OK, headers, self._xml_response(xml_answer), None + return client.OK, headers, self._xml_response(xml_answer, request_info), None diff --git a/radicale/app/get.py b/radicale/app/get.py index a0139560..21bd0349 100644 --- a/radicale/app/get.py +++ b/radicale/app/get.py @@ -68,7 +68,7 @@ class ApplicationPartGet(ApplicationBase): return value def do_GET(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: """Manage GET request.""" # Redirect to /.web if the root path is requested if not pathutils.strip_path(path): @@ -84,7 +84,7 @@ class ApplicationPartGet(ApplicationBase): base_prefix + unsafe_path, location) return httputils.redirect(location, client.MOVED_PERMANENTLY) # Dispatch /.web path to web module - return self._web.get(environ, base_prefix, path, user) + return self._web.get(environ, base_prefix, path, user, request_info) permissions_filter = None share = None if self._sharing._enabled: diff --git a/radicale/app/head.py b/radicale/app/head.py index eec68bb5..2dfb6f3f 100644 --- a/radicale/app/head.py +++ b/radicale/app/head.py @@ -26,7 +26,7 @@ from radicale.app.get import ApplicationPartGet class ApplicationPartHead(ApplicationPartGet, ApplicationBase): def do_HEAD(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: """Manage HEAD request.""" # Body is dropped in `Application.__call__` for HEAD requests - return self.do_GET(environ, base_prefix, path, user, remote_host, remote_useragent) + return self.do_GET(environ, base_prefix, path, user, request_info) diff --git a/radicale/app/mkcalendar.py b/radicale/app/mkcalendar.py index 6932fa50..266998c5 100644 --- a/radicale/app/mkcalendar.py +++ b/radicale/app/mkcalendar.py @@ -32,12 +32,12 @@ from radicale.log import logger class ApplicationPartMkcalendar(ApplicationBase): def do_MKCALENDAR(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage MKCALENDAR request.""" if "w" not in self._rights.authorization(user, path): return httputils.NOT_ALLOWED try: - xml_content = self._read_xml_request_body(environ) + xml_content = self._read_xml_request_body(environ, request_info) except RuntimeError as e: logger.warning( "Bad MKCALENDAR request on %r: %s", path, e, exc_info=True) @@ -67,7 +67,7 @@ class ApplicationPartMkcalendar(ApplicationBase): item = next(iter(self._storage.discover(path)), None) if item: return self._webdav_error_response( - client.CONFLICT, "D:resource-must-be-null") + client.CONFLICT, "D:resource-must-be-null", request_info) parent_path = pathutils.parent_path(path) parent_item = next(iter(self._storage.discover(parent_path)), None) if not parent_item: diff --git a/radicale/app/mkcol.py b/radicale/app/mkcol.py index 77d81e22..26de7bd0 100644 --- a/radicale/app/mkcol.py +++ b/radicale/app/mkcol.py @@ -32,13 +32,13 @@ from radicale.log import logger class ApplicationPartMkcol(ApplicationBase): def do_MKCOL(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage MKCOL request.""" permissions = self._rights.authorization(user, path) if not rights.intersect(permissions, "Ww"): return httputils.NOT_ALLOWED try: - xml_content = self._read_xml_request_body(environ) + xml_content = self._read_xml_request_body(environ, request_info) except RuntimeError as e: logger.warning( "Bad MKCOL request on %r: %s", path, e, exc_info=True) diff --git a/radicale/app/move.py b/radicale/app/move.py index f16368f4..1d84c58b 100644 --- a/radicale/app/move.py +++ b/radicale/app/move.py @@ -49,7 +49,7 @@ def get_server_netloc(environ: types.WSGIEnviron, force_port: bool = False): class ApplicationPartMove(ApplicationBase): def do_MOVE(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage MOVE request.""" raw_dest = environ.get("HTTP_DESTINATION", "") @@ -136,7 +136,7 @@ class ApplicationPartMove(ApplicationBase): to_collection.has_uid(item.uid)): return self._webdav_error_response( client.CONFLICT, "%s:no-uid-conflict" % ( - "C" if collection_tag == "VCALENDAR" else "CR")) + "C" if collection_tag == "VCALENDAR" else "CR"), request_info) to_href = posixpath.basename(pathutils.strip_path(to_path)) try: self._storage.move(item, to_collection, to_href) diff --git a/radicale/app/options.py b/radicale/app/options.py index bcb3663e..2e81b45a 100644 --- a/radicale/app/options.py +++ b/radicale/app/options.py @@ -28,7 +28,7 @@ from radicale.app.base import ApplicationBase class ApplicationPartOptions(ApplicationBase): def do_OPTIONS(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage OPTIONS request.""" headers = { "Allow": ", ".join( diff --git a/radicale/app/post.py b/radicale/app/post.py index a70fc736..b2f44a89 100644 --- a/radicale/app/post.py +++ b/radicale/app/post.py @@ -26,10 +26,10 @@ from radicale.app.base import ApplicationBase class ApplicationPartPost(ApplicationBase): def do_POST(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage POST request.""" if path == "/.web" or path.startswith("/.web/"): - return self._web.post(environ, base_prefix, path, user) + return self._web.post(environ, base_prefix, path, user, request_info) elif path == "/.sharing" or path.startswith("/.sharing/"): - return self._sharing.post(environ, base_prefix, path, user) + return self._sharing.post(environ, base_prefix, path, user, request_info) return httputils.METHOD_NOT_ALLOWED diff --git a/radicale/app/propfind.py b/radicale/app/propfind.py index 9424547c..151577f4 100644 --- a/radicale/app/propfind.py +++ b/radicale/app/propfind.py @@ -574,7 +574,7 @@ class ApplicationPartPropfind(ApplicationBase): yield item, permission, raw_permissions def do_PROPFIND(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage PROPFIND request.""" http_depth = environ.get("HTTP_DEPTH", "0") permissions_filter = None @@ -594,7 +594,7 @@ class ApplicationPartPropfind(ApplicationBase): if not access.check("r"): return httputils.NOT_ALLOWED try: - xml_content = self._read_xml_request_body(environ) + xml_content = self._read_xml_request_body(environ, request_info) except RuntimeError as e: logger.warning( "Bad PROPFIND request on %r: %s", path, e, exc_info=True) @@ -659,4 +659,5 @@ class ApplicationPartPropfind(ApplicationBase): allowed_items, user, self._encoding, max_resource_size=self._max_resource_size, shares=shares) if xml_answer is None: return httputils.NOT_ALLOWED - return client.MULTI_STATUS, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content) + request_info["status"] = client.MULTI_STATUS + return client.MULTI_STATUS, headers, self._xml_response(xml_answer, request_info), xmlutils.pretty_xml(xml_content) diff --git a/radicale/app/proppatch.py b/radicale/app/proppatch.py index f97d4737..90145329 100644 --- a/radicale/app/proppatch.py +++ b/radicale/app/proppatch.py @@ -97,7 +97,7 @@ def xml_proppatch(base_prefix: str, path: str, class ApplicationPartProppatch(ApplicationBase): def do_PROPPATCH(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage PROPPATCH request.""" actor = user permissions_filter = None @@ -155,7 +155,8 @@ class ApplicationPartProppatch(ApplicationBase): logger.info("PROPPATCH request on shared %r: write-permissions, overlay not enforced, but enforced by permission 'E'", path_orig) share_overlay = True try: - xml_content = self._read_xml_request_body(environ) + xml_content = self._read_xml_request_body(environ, request_info) + except RuntimeError as e: logger.warning( "Bad PROPPATCH request on %r: %s", path, e, exc_info=True) @@ -193,7 +194,8 @@ class ApplicationPartProppatch(ApplicationBase): logger.warning( "Bad PROPPATCH request on %r: %s", path, e, exc_info=True) return httputils.BAD_REQUEST - return client.MULTI_STATUS, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content) + request_info["status"] = client.MULTI_STATUS + return client.MULTI_STATUS, headers, self._xml_response(xml_answer, request_info), xmlutils.pretty_xml(xml_content) with self._storage.acquire_lock("w", user, path=path, request="PROPPATCH"): item = next(iter(self._storage.discover(path)), None) @@ -242,4 +244,5 @@ class ApplicationPartProppatch(ApplicationBase): logger.warning( "Bad PROPPATCH request on %r: %s", path, e, exc_info=True) return httputils.BAD_REQUEST - return client.MULTI_STATUS, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content) + request_info["status"] = client.MULTI_STATUS + return client.MULTI_STATUS, headers, self._xml_response(xml_answer, request_info), xmlutils.pretty_xml(xml_content) diff --git a/radicale/app/put.py b/radicale/app/put.py index 7d14955e..1536c127 100644 --- a/radicale/app/put.py +++ b/radicale/app/put.py @@ -179,7 +179,7 @@ def prepare(vobject_items: List[vobject.base.Component], path: str, class ApplicationPartPut(ApplicationBase): def do_PUT(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage PUT request.""" actor = user permissions_filter = None @@ -196,7 +196,7 @@ class ApplicationPartPut(ApplicationBase): if not access.check("w"): return httputils.NOT_ALLOWED try: - content = httputils.read_request_body(self.configuration, environ) + content = httputils.read_request_body(self.configuration, environ, request_info) except RuntimeError as e: logger.warning("Bad PUT request on %r (read_request_body): %s", path, e, exc_info=True) return httputils.BAD_REQUEST @@ -344,9 +344,10 @@ class ApplicationPartPut(ApplicationBase): prepared_item, = prepared_items if (item and item.uid != prepared_item.uid or not item and parent_item.has_uid(prepared_item.uid)): + request_info["status"] = client.CONFLICT return self._webdav_error_response( client.CONFLICT, "%s:no-uid-conflict" % ( - "C" if tag == "VCALENDAR" else "CR")) + "C" if tag == "VCALENDAR" else "CR"), request_info) href = posixpath.basename(pathutils.strip_path(path)) try: diff --git a/radicale/app/report.py b/radicale/app/report.py index f9b4defd..93461e2e 100644 --- a/radicale/app/report.py +++ b/radicale/app/report.py @@ -149,7 +149,7 @@ def free_busy_report(base_prefix: str, path: str, xml_request: Optional[ET.Eleme def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element], collection: storage.BaseCollection, encoding: str, unlock_storage_fn: Callable[[], None], - max_occurrence: int = 0, user: str = "", remote_addr: str = "", remote_useragent: str = "", + max_occurrence: int = 0, user: str = "", request_info: dict = {}, share: Union[dict, None] = None) -> Tuple[int, ET.Element]: """Read and answer REPORT requests that return XML. @@ -216,8 +216,11 @@ def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element], sync_token, names = collection.sync(old_sync_token) except ValueError as e: # Invalid sync token + remote_useragent_txt = "" + if request_info["useragent"] != "": + remote_useragent_txt = " using %r" % request_info["useragent"] logger.warning("Client provided invalid sync token for path %r (user %r from %s%s): %s", - path, user, remote_addr, remote_useragent, e, exc_info=True) + path, user, request_info["host"], remote_useragent_txt, e, exc_info=True) # client.CONFLICT doesn't work with some clients (e.g. InfCloud) return (client.FORBIDDEN, xmlutils.webdav_error("D:valid-sync-token")) @@ -851,7 +854,7 @@ def test_filter(collection_tag: str, item: radicale_item.Item, class ApplicationPartReport(ApplicationBase): def do_REPORT(self, environ: types.WSGIEnviron, base_prefix: str, - path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse: + path: str, user: str, request_info: dict) -> types.WSGIResponse: """Manage REPORT request.""" permissions_filter = None share = None @@ -867,7 +870,7 @@ class ApplicationPartReport(ApplicationBase): if not access.check("r"): return httputils.NOT_ALLOWED try: - xml_content = self._read_xml_request_body(environ) + xml_content = self._read_xml_request_body(environ, request_info) except RuntimeError as e: logger.warning("Bad REPORT request on %r: %s", path, e, exc_info=True) @@ -905,10 +908,11 @@ class ApplicationPartReport(ApplicationBase): try: status, xml_answer = xml_report( base_prefix, path, xml_content, collection, self._encoding, - lock_stack.close, max_occurrence, user, remote_host, remote_useragent, share=share) + lock_stack.close, max_occurrence, user, request_info, share=share) except ValueError as e: logger.warning( "Bad REPORT request on %r: %s", path, e, exc_info=True) return httputils.BAD_REQUEST headers = {"Content-Type": "text/xml; charset=%s" % self._encoding} - return status, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content) + request_info["status"] = status + return status, headers, self._xml_response(xml_answer, request_info), xmlutils.pretty_xml(xml_content) diff --git a/radicale/httputils.py b/radicale/httputils.py index 424f178e..e030cdce 100644 --- a/radicale/httputils.py +++ b/radicale/httputils.py @@ -32,7 +32,7 @@ import time from http import client from typing import List, Mapping, Union, cast -from radicale import config, pathutils, types, utils +from radicale import config, log, pathutils, types, utils from radicale.log import logger if sys.version_info < (3, 9): @@ -151,16 +151,29 @@ def read_raw_request_body(configuration: "config.Configuration", def read_request_body(configuration: "config.Configuration", - environ: types.WSGIEnviron) -> str: + environ: types.WSGIEnviron, request_info: dict) -> str: content = decode_request(configuration, environ, read_raw_request_body(configuration, environ)) - if logger.isEnabledFor(logging.DEBUG): - if configuration.get("logging", "request_content_on_debug"): - _limit_content = configuration.get("logging", "limit_content") + _limit_content = configuration.get("logging", "limit_content") + if configuration.get("logging", "request_content_on_debug"): + if logger.isEnabledFor(logging.DEBUG): logger.debug("Request content (sha256sum): %s", utils.sha256_str(content)) logger.debug("Request content:\n%s", utils.textwrap_str(content, _limit_content)) + else: + _request_content_on_notice_condition = configuration.get("logging", "request_content_on_notice_condition") + if _request_content_on_notice_condition != {}: + if log.log_conditional( + "request-content", + condition=_request_content_on_notice_condition, + value=request_info, + ): + logger.notice("Request content (log condition passed):\n%s", utils.textwrap_str(content, _limit_content)) + else: + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Request content (log condition skipped): suppressed") else: - logger.debug("Request content: suppressed by config/option [logging] request_content_on_debug") + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Request content: suppressed by config/option [logging] request_content_on_debug") return content diff --git a/radicale/log.py b/radicale/log.py index 408f7f62..1436166c 100644 --- a/radicale/log.py +++ b/radicale/log.py @@ -28,8 +28,10 @@ Log messages are sent to the first available target of: import contextlib import io +import ipaddress import logging import os +import re import socket import struct import sys @@ -48,6 +50,19 @@ LOGGER_FORMATS: Mapping[str, str] = { } DATE_FORMAT: str = "%Y-%m-%d %H:%M:%S %z" +LOG_CONDITION_TOKEN: dict = {"method": "str", + "path": "str", + "useragent": "str", + "host": "ipaddress", + "login": "str", + "status": "int", + } +LOG_CONDITION_CONDITION: list = ["match", "value"] +LOG_CONDITION_MATCH_STR: list = ["startswith", "endswith", "equal", "re", "==", "="] +LOG_CONDITION_MATCH_INT: list = ["=", ">", "<", "<=", ">=", "equal", "==", "<>", "!="] +LOG_CONDITION_MATCH_IPADDRESS: list = ["==", "equal", "=", "<>", "!="] +LOG_CONDITION_MATCH_IPNETWORK: list = ["included", "excluded", "incl", "excl"] + LOG_LEVEL_OPTIONS: list = ["trace", "debug", "info", "notice", "warning", "error", "critical", "alert"] LOG_LEVEL_TRACE: int = 5 @@ -326,3 +341,90 @@ def set_level(level: Union[int, str], backtrace_on_debug: bool, trace_filter: st logger.addFilter(PassTRACETOKENFilter(trace_filter)) else: logger.trace("Logging messages on 'trace' level enabled") + + +def log_conditional(name: str, condition: dict, value: dict) -> bool: + logger.trace("log/conditional/%s/CHECK : condition=%r value=%r", name, condition, value) + # "and" combination + condition_active = False + for token in condition: + condition_active = True + if LOG_CONDITION_TOKEN[token] == "str": + logger.trace("log/conditional/%s/%s/string/CHECK : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + if condition[token]["match"] in ["equal", "==", "="]: + if not condition[token]["value"] == value[token]: + return False + elif condition[token]["match"] in ["startswith"]: + if not value[token].startswith(condition[token]["value"]): + return False + elif condition[token]["match"] in ["endswith"]: + if not value[token].endswith(condition[token]["value"]): + return False + elif condition[token]["match"] in ["re"]: + if not re.search(condition[token]["value"], value[token]): + return False + logger.trace("log/conditional/%s/%s/string/PASSED : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + + elif LOG_CONDITION_TOKEN[token] == "int": + condition[token]["value"] = int(condition[token]["value"]) + logger.trace("log/conditional/%s/%s/integer/CHECK : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + if condition[token]["match"] in ["equal", "==", "="]: + if not condition[token]["value"] == value[token]: + return False + elif condition[token]["match"] in ["<"]: + if not condition[token]["value"] < value[token]: + return False + elif condition[token]["match"] in ["<="]: + if not condition[token]["value"] <= value[token]: + return False + elif condition[token]["match"] in [">"]: + if not condition[token]["value"] > value[token]: + return False + elif condition[token]["match"] in [">="]: + if not condition[token]["value"] >= value[token]: + return False + elif condition[token]["match"] in ["<>", "!="]: + if not condition[token]["value"] != value[token]: + return False + logger.trace("log/conditional/%s/%s/integer/PASSED : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + + elif LOG_CONDITION_TOKEN[token] == "ipaddress": + logger.trace("log/conditional/%s/%s/ip/CHECK : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + # simple IP address check + if condition[token]["match"] in ["equal", "==", "="]: + if not condition[token]["value"] == value[token]: + return False + elif condition[token]["match"] in ["<>", "!="]: + if not condition[token]["value"] != value[token]: + return False + elif condition[token]["match"] in ["included", "incl", "excluded", "excl"]: + if condition[token]["match"] in ["included", "incl"]: + if value[token] == "unknown": + return False + else: + ip_net = ipaddress.ip_network(value[token]) + ip = ipaddress.ip_network(condition[token]["value"]) + if type(ip_net) is ipaddress.IPv4Network and type(ip) is ipaddress.IPv4Network: + if not ip_net.subnet_of(ip): + return False + elif type(ip_net) is ipaddress.IPv6Network and type(ip) is ipaddress.IPv6Network: + if not ip_net.subnet_of(ip): + return False + else: + return False + elif condition[token]["match"] in ["excluded", "excl"]: + if value[token] != "unknown": + ip_net = ipaddress.ip_network(value[token]) + if type(ip_net) is ipaddress.IPv4Network and type(ip) is ipaddress.IPv4Network: + if ip_net.subnet_of(ip): + return False + elif type(ip_net) is ipaddress.IPv6Network and type(ip) is ipaddress.IPv6Network: + if ip_net.subnet_of(ip): + return False + logger.trace("log/conditional/%s/%s/ip/PASSED : %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + else: + logger.trace("log/conditional/%s/%s/ip/SKIPPED: %r %s %r", name, token, condition[token]["value"], condition[token]["match"], value[token]) + + # only return 'True' if at least one condition was found + logger.trace("log/conditional/%s/PASSED: condition=%r value=%r", name, condition, value) + return condition_active diff --git a/radicale/sharing/__init__.py b/radicale/sharing/__init__.py index b1b1078e..fb162ffc 100644 --- a/radicale/sharing/__init__.py +++ b/radicale/sharing/__init__.py @@ -511,7 +511,7 @@ class BaseSharing: return None # *** POST API *** - def post(self, environ: types.WSGIEnviron, base_prefix: str, path: str, user: str) -> types.WSGIResponse: + def post(self, environ: types.WSGIEnviron, base_prefix: str, path: str, user: str, request_info: dict) -> types.WSGIResponse: # Late import to avoid circular dependency in config from radicale.app import base as app_base from radicale.app.base import Access @@ -616,7 +616,7 @@ class BaseSharing: logger.trace("sharing/API: called by authenticated user: %r", user) # read POST data try: - request_body = httputils.read_request_body(self.configuration, environ) + request_body = httputils.read_request_body(self.configuration, environ, request_info) except RuntimeError as e: logger.warning("Bad POST request on %r (read_request_body): %s", path, e, exc_info=True) return httputils.bad_request("Failed read POST request body") diff --git a/radicale/tests/custom/web.py b/radicale/tests/custom/web.py index ee8bc6e6..7afdd510 100644 --- a/radicale/tests/custom/web.py +++ b/radicale/tests/custom/web.py @@ -28,10 +28,10 @@ from radicale import httputils, types, web class Web(web.BaseWeb): def get(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: return client.OK, {"Content-Type": "text/plain"}, "custom", None def post(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: - content = httputils.read_request_body(self.configuration, environ) + user: str, request_info: dict) -> types.WSGIResponse: + content = httputils.read_request_body(self.configuration, environ, request_info) return client.OK, {"Content-Type": "text/plain"}, "echo:" + content, None diff --git a/radicale/web/__init__.py b/radicale/web/__init__.py index a8f2b731..526452aa 100644 --- a/radicale/web/__init__.py +++ b/radicale/web/__init__.py @@ -49,7 +49,7 @@ class BaseWeb: self.configuration = configuration def get(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: """GET request. ``base_prefix`` is sanitized and never ends with "/". @@ -58,11 +58,13 @@ class BaseWeb: ``user`` is empty for anonymous users. + ``request_info`` dict of additional information + """ return httputils.METHOD_NOT_ALLOWED def post(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: """POST request. ``base_prefix`` is sanitized and never ends with "/". @@ -71,6 +73,8 @@ class BaseWeb: ``user`` is empty for anonymous users. + ``request_info`` dict of additional information + Use ``httputils.read*_request_body(self.configuration, environ)`` to read the body. diff --git a/radicale/web/internal.py b/radicale/web/internal.py index 01516b5b..312ad961 100644 --- a/radicale/web/internal.py +++ b/radicale/web/internal.py @@ -34,6 +34,6 @@ FALLBACK_MIMETYPE = httputils.FALLBACK_MIMETYPE # deprecated class Web(web.BaseWeb): def get(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: return httputils.serve_resource("radicale.web", "internal_data", base_prefix, path) diff --git a/radicale/web/none.py b/radicale/web/none.py index 59cc341e..7f6b4bba 100644 --- a/radicale/web/none.py +++ b/radicale/web/none.py @@ -28,7 +28,7 @@ from radicale import httputils, pathutils, types, web class Web(web.BaseWeb): def get(self, environ: types.WSGIEnviron, base_prefix: str, path: str, - user: str) -> types.WSGIResponse: + user: str, request_info: dict) -> types.WSGIResponse: assert path == "/.web" or path.startswith("/.web/") assert pathutils.sanitize_path(path) == path if path != "/.web": From 5a1f6cbd0229a118f1d340441013cceae21e3f3d Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:32:31 +0200 Subject: [PATCH 6/8] log also exception text --- radicale/config.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/radicale/config.py b/radicale/config.py index 5155876b..319f2478 100644 --- a/radicale/config.py +++ b/radicale/config.py @@ -934,8 +934,7 @@ class Configuration: except Exception as e: raise RuntimeError( "Invalid %s value for option %r in section %r in %s: " - "%r" % (type_.__name__, option, section, source, - raw_value)) from e + "%r (%s)" % (type_.__name__, option, section, source, raw_value, e)) from e self._configs.append((config, source, bool(privileged))) for section in new_values: self._values[section] = self._values.get(section, {}) From da668035baa9f45a7b3d98533f9d82ac24aaa133 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:33:10 +0200 Subject: [PATCH 7/8] log on_notice_condition: test cases --- radicale/tests/test_base.py | 230 ++++++++++++++++++++++++++++++++++++ 1 file changed, 230 insertions(+) diff --git a/radicale/tests/test_base.py b/radicale/tests/test_base.py index d3ee1a9a..3855e259 100644 --- a/radicale/tests/test_base.py +++ b/radicale/tests/test_base.py @@ -2458,3 +2458,233 @@ permissions: RrWw""") self.mkcalendar("/calendar.ics/") event = get_file_content("event_timezone_seconds.ics") self.put("/calendar.ics/event.ics", event) + + def test_logging_conditional_basic(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "request_header_on_notice_condition": '{"method": {"match": "equal", "value": "GET"}, "login": {"match": "equal", "value": "owner"}}', + "request_content_on_notice_condition": '{"method": {"match": "equal", "value": "PUT"}, "useragent": {"match": "startswith", "value": "caldavsync"}}', + "response_header_on_notice_condition": '{"method": {"match": "equal", "value": "PUT"}, "status": {"match": ">=", "value": "201"}, "host": {"match": "included", "value": "127.0.0.0/8"}}', + "response_content_on_notice_condition": '{"method": {"match": "equal", "value": "GET"}, "path": {"match": "endswith", "value": ".ics"}}', + }}) + self.mkcalendar("/test/") + event = get_file_content("event1.ics") + path = "/test/event1.ics" + path2 = "/test/event2.ics" + + logging.info("\n*** check log condition: Response header (found)") + caplog.clear() + self.put(path, event, remote_host='127.0.0.1') + assert "Response header (log condition passed)" in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response header (not found)") + caplog.clear() + self.put(path, event, remote_host='192.0.2.1', check=204) + assert "Response header (log condition passed)" not in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response content (found)") + caplog.clear() + self.get(path) + assert "Response content (nonXML, log condition passed)" in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response content (not found)") + caplog.clear() + self.get(path2, check=404) + assert "Response content (log condition passed)" not in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Request header (found)") + caplog.clear() + self.get(path2, check=401, login="owner:ownerpw") + assert "Request header (log condition passed)" in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Request content (found)") + caplog.clear() + self.put(path, event, remote_useragent='caldavsync', check=204) + assert "Request content (log condition passed)" in "\n".join(caplog.messages) + + def test_logging_conditional_ip_included(self, caplog) -> None: + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_header_on_notice_condition": '{"host": {"match": "included", "value": "127.0.0.0/8"}}', + }}) + + self.mkcalendar("/test/") + event = get_file_content("event1.ics") + path = "/test/event1.ics" + + logging.info("\n*** check log condition: Response header (not found)") + caplog.clear() + self.put(path, event, remote_host='192.0.2.1') + assert "Response header (log condition passed)" not in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response header (found)") + caplog.clear() + self.put(path, event, remote_host='127.0.0.1', check=204) + assert "Response header (log condition passed)" in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response header (not found, no remote_host)") + caplog.clear() + self.put(path, event, check=204) + assert "Response header (log condition passed)" not in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response header (IPv6, not found)") + caplog.clear() + self.put(path, event, check=204, remote_host='2001:db8::1') + assert "Response header (log condition passed)" not in "\n".join(caplog.messages) + + def test_logging_conditional_report(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_content_on_notice_condition": '{"status": {"match": "equal", "value": "207"}, "method": {"match": "equal", "value": "REPORT"}}', + }}) + self.mkcalendar("/test/") + + logging.info("\n*** check log condition: Response content (found)") + caplog.clear() + _, responses = self.report("/test/", """\ + + + + + +""") + assert "Response content (XML, log condition passed)" in "\n".join(caplog.messages) + + def test_logging_conditional_propfind(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_content_on_notice_condition": '{"status": {"match": "equal", "value": "207"}, "method": {"match": "equal", "value": "PROPFIND"}}', + }}) + self.mkcalendar("/test/") + + logging.info("\n*** check log condition: Response content (found)") + caplog.clear() + _, responses = self.propfind("/test/") + assert "Response content (XML, log condition passed)" in "\n".join(caplog.messages) + + def test_logging_conditional_proppatch(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_content_on_notice_condition": '{"status": {"match": "equal", "value": "207"}, "method": {"match": "equal", "value": "PROPPATCH"}}', + }}) + self.mkcalendar("/test/") + proppatch = get_file_content("proppatch_set_calendar_color.xml") + + logging.info("\n*** check log condition: Response content (found)") + caplog.clear() + _, responses = self.proppatch("/test/", proppatch) + assert "Response content (XML, log condition passed)" in "\n".join(caplog.messages) + + def test_logging_conditional_mkcalendar(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "request_header_on_notice_condition": '{"method": {"match": "equal", "value": "MKCALENDAR"}}', + }}) + + logging.info("\n*** check log condition: Request content (found)") + caplog.clear() + self.mkcalendar("/test/") + assert "Request header (log condition passed)" in "\n".join(caplog.messages) + + def test_logging_conditional_mkcol(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "True", + "request_content_on_notice_condition": '{"method": {"match": "equal", "value": "MKCOL"}}', + }}) + + logging.info("\n*** check log condition: Request content (found)") + caplog.clear() + self.create_addressbook("/test/") + + def test_logging_conditional_regex_basic(self, caplog) -> None: + caplog.set_level(logging.INFO) + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_header_on_notice_condition": '{"method": {"match": "equal", "value": "PUT"}, "path": {"match": "re", "value": "ev?nt[01]"}}', + }}) + self.mkcalendar("/test/") + event = get_file_content("event1.ics") + event2 = get_file_content("event2.ics") + path = "/test/event1.ics" + path2 = "/test/event2.ics" + + logging.info("\n*** check log condition: Response header (found/re)") + caplog.clear() + self.put(path, event, remote_host='127.0.0.1') + assert "Response header (log condition passed)" in "\n".join(caplog.messages) + + logging.info("\n*** check log condition: Response header (found/re)") + caplog.clear() + self.put(path2, event2, remote_host='127.0.0.1') + assert "Response header (log condition passed)" not in "\n".join(caplog.messages) + + def test_logging_conditional_problems(self, caplog) -> None: + logging.info("\n*** check log condition config: re ok") + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "request_header_on_notice_condition": '{"path": {"match": "re", "value": "ev?.*nt[01]"}}', + }}) + self.mkcalendar("/test1/") + + logging.info("\n*** check log condition config: re broken") + try: + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "request_header_on_notice_condition": '{"path": {"match": "re", "value": "*.ics"}}', + }}) + except RuntimeError: + pass + else: + raise + + logging.info("\n*** check log condition config: status not supported <100") + try: + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_header_on_notice_condition": '{"status": {"match": "<=", "value": "99"}}', + }}) + except RuntimeError: + pass + else: + raise + + logging.info("\n*** check log condition config: status not supported >599") + try: + self.configure({"logging": {"request_header_on_debug": "False", + "request_content_on_debug": "False", + "response_header_on_debug": "False", + "response_content_on_debug": "False", + "response_header_on_notice_condition": '{"status": {"match": "<=", "value": "600"}}', + }}) + except RuntimeError: + pass + else: + raise From aefa99d5a4c43bb5ca5656753822f13dff62add1 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Tue, 12 May 2026 08:35:16 +0200 Subject: [PATCH 8/8] copyright update --- radicale/log.py | 2 +- radicale/tests/custom/web.py | 2 +- radicale/web/__init__.py | 3 ++- radicale/web/internal.py | 3 ++- radicale/web/none.py | 2 +- 5 files changed, 7 insertions(+), 5 deletions(-) diff --git a/radicale/log.py b/radicale/log.py index 1436166c..81fa5fb8 100644 --- a/radicale/log.py +++ b/radicale/log.py @@ -1,7 +1,7 @@ # This file is part of Radicale - CalDAV and CardDAV server # Copyright © 2011-2017 Guillaume Ayoub # Copyright © 2017-2023 Unrud -# Copyright © 2024-2024 Peter Bieringer +# Copyright © 2024-2026 Peter Bieringer # # This library is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by diff --git a/radicale/tests/custom/web.py b/radicale/tests/custom/web.py index 7afdd510..0834a9d7 100644 --- a/radicale/tests/custom/web.py +++ b/radicale/tests/custom/web.py @@ -1,6 +1,6 @@ # This file is part of Radicale - CalDAV and CardDAV server # Copyright © 2017-2021 Unrud -# Copyright © 2025-2025 Peter Bieringer +# Copyright © 2025-2026 Peter Bieringer # # This library is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by diff --git a/radicale/web/__init__.py b/radicale/web/__init__.py index 526452aa..094b8560 100644 --- a/radicale/web/__init__.py +++ b/radicale/web/__init__.py @@ -1,5 +1,6 @@ # This file is part of Radicale - CalDAV and CardDAV server -# Copyright © 2017-2018 Unrud +# Copyright © 2017-2021 Unrud +# Copyright © 2026-2026 Peter Bieringer # # This library is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by diff --git a/radicale/web/internal.py b/radicale/web/internal.py index 312ad961..1fd78e2d 100644 --- a/radicale/web/internal.py +++ b/radicale/web/internal.py @@ -1,5 +1,6 @@ # This file is part of Radicale - CalDAV and CardDAV server -# Copyright © 2017-2018 Unrud +# Copyright © 2017-2022 Unrud +# Copyright © 2026-2026 Peter Bieringer # # This library is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by diff --git a/radicale/web/none.py b/radicale/web/none.py index 7f6b4bba..e6ebb39b 100644 --- a/radicale/web/none.py +++ b/radicale/web/none.py @@ -1,6 +1,6 @@ # This file is part of Radicale - CalDAV and CardDAV server # Copyright © 2017-2022 Unrud -# Copyright © 2025-2025 Peter Bieringer +# Copyright © 2025-2026 Peter Bieringer # # This library is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by