Merge branch 'master' of github.com:metallerok/Radicale into recurrence_all_day_comparsion

2026-02-04 19:34:52 +03:00
parent 76d798ccd5 f2f650f922
commit 4e88cbbbc2
78 changed files with 4807 additions and 974 deletions
--- a/radicale/app/init.py
+++ b/radicale/app/init.py
@@ -27,15 +27,19 @@ the built-in server (see ``radicale.server`` module).
 """

 import base64
+import cProfile
 import datetime
+import io
+import logging
 import pprint
+import pstats
 import random
 import time
 import zlib
 from http import client
 from typing import Iterable, List, Mapping, Tuple, Union

-from radicale import config, httputils, log, pathutils, types
+from radicale import config, httputils, log, pathutils, types, utils
 from radicale.app.base import ApplicationBase
 from radicale.app.delete import ApplicationPartDelete
 from radicale.app.get import ApplicationPartGet
@@ -49,11 +53,14 @@ from radicale.app.propfind import ApplicationPartPropfind
 from radicale.app.proppatch import ApplicationPartProppatch
 from radicale.app.put import ApplicationPartPut
 from radicale.app.report import ApplicationPartReport
+from radicale.auth import AuthContext
 from radicale.log import logger

 # Combination of types.WSGIStartResponse and WSGI application return value
 _IntermediateResponse = Tuple[str, List[Tuple[str, str]], Iterable[bytes]]

+REQUEST_METHODS = ["DELETE", "GET", "HEAD", "MKCALENDAR", "MKCOL", "MOVE", "OPTIONS", "POST", "PROPFIND", "PROPPATCH", "PUT", "REPORT"]
+

 class Application(ApplicationPartDelete, ApplicationPartHead,
                  ApplicationPartGet, ApplicationPartMkcalendar,
@@ -67,11 +74,18 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
    _auth_delay: float
    _internal_server: bool
    _max_content_length: int
+    _max_resource_size: int
    _auth_realm: str
+    _auth_type: str
+    _web_type: str
    _script_name: str
    _extra_headers: Mapping[str, str]
-    _permit_delete_collection: bool
-    _permit_overwrite_collection: bool
+    _profiling_per_request: bool = False
+    _profiling_per_request_method: bool = False
+    profiler_per_request_method: dict[str, cProfile.Profile] = {}
+    profiler_per_request_method_counter: dict[str, int] = {}
+    profiler_per_request_method_starttime: datetime.datetime
+    profiler_per_request_method_logtime: datetime.datetime

    def __init__(self, configuration: config.Configuration) -> None:
        """Initialize Application.
@@ -83,10 +97,28 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
        """
        super().__init__(configuration)
        self._mask_passwords = configuration.get("logging", "mask_passwords")
+        self._max_content_length = configuration.get("server", "max_content_length")
+        self._max_resource_size = configuration.get("server", "max_resource_size")
+        logger.info("max_content_length set to: %d bytes (%sbytes)", self._max_content_length, utils.format_unit(self._max_content_length, binary=True))
+        if (self._max_resource_size > (self._max_content_length * 0.8)):
+            max_resource_size_limited = int(self._max_content_length * 0.8)
+            logger.warning("max_resource_size set to: %d bytes (%sbytes) (capped from %d to 80%% of max_content_length)", max_resource_size_limited, utils.format_unit(max_resource_size_limited, binary=True), self._max_resource_size)
+            self._max_resource_size = max_resource_size_limited
+        else:
+            logger.info("max_resource_size  set to: %d bytes (%sbytes)", self._max_resource_size, utils.format_unit(self._max_resource_size, binary=True))
        self._bad_put_request_content = configuration.get("logging", "bad_put_request_content")
+        logger.info("log bad put request content: %s", self._bad_put_request_content)
        self._request_header_on_debug = configuration.get("logging", "request_header_on_debug")
+        self._request_content_on_debug = configuration.get("logging", "request_content_on_debug")
+        self._response_header_on_debug = configuration.get("logging", "response_header_on_debug")
        self._response_content_on_debug = configuration.get("logging", "response_content_on_debug")
+        logger.debug("log request  header  on debug: %s", self._request_header_on_debug)
+        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._auth_delay = configuration.get("auth", "delay")
+        self._auth_type = configuration.get("auth", "type")
+        self._web_type = configuration.get("web", "type")
        self._internal_server = configuration.get("server", "_internal_server")
        self._script_name = configuration.get("server", "script_name")
        if self._script_name:
@@ -111,6 +143,59 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
        self._extra_headers = dict()
        for key in self.configuration.options("headers"):
            self._extra_headers[key] = configuration.get("headers", key)
+        self._strict_preconditions = configuration.get("storage", "strict_preconditions")
+        logger.info("strict preconditions check: %s", self._strict_preconditions)
+        # Profiling options
+        self._profiling = configuration.get("logging", "profiling")
+        self._profiling_per_request_min_duration = configuration.get("logging", "profiling_per_request_min_duration")
+        self._profiling_per_request_header = configuration.get("logging", "profiling_per_request_header")
+        self._profiling_per_request_xml = configuration.get("logging", "profiling_per_request_xml")
+        self._profiling_per_request_method_interval = configuration.get("logging", "profiling_per_request_method_interval")
+        self._profiling_top_x_functions = configuration.get("logging", "profiling_top_x_functions")
+        if self._profiling in config.PROFILING:
+            logger.info("profiling: %r", self._profiling)
+            if self._profiling == "per_request":
+                self._profiling_per_request = True
+            elif self._profiling == "per_request_method":
+                self._profiling_per_request_method = True
+        if self._profiling_per_request or self._profiling_per_request_method:
+            logger.info("profiling top X functions: %d", self._profiling_top_x_functions)
+        if self._profiling_per_request:
+            logger.info("profiling per request minimum duration: %d (below are skipped)", self._profiling_per_request_min_duration)
+            logger.info("profiling per request header: %s", self._profiling_per_request_header)
+            logger.info("profiling per request xml   : %s", self._profiling_per_request_xml)
+        if self._profiling_per_request_method:
+            logger.info("profiling per request method interval: %d seconds", self._profiling_per_request_method_interval)
+        # Profiling per request method initialization
+        if self._profiling_per_request_method:
+            for method in REQUEST_METHODS:
+                self.profiler_per_request_method[method] = cProfile.Profile()
+                self.profiler_per_request_method_counter[method] = False
+        self.profiler_per_request_method_starttime = datetime.datetime.now()
+        self.profiler_per_request_method_logtime = self.profiler_per_request_method_starttime
+
+    def __del__(self) -> None:
+        """Shutdown application."""
+        if self._profiling_per_request_method:
+            # Profiling since startup
+            self._profiler_per_request_method(True)
+
+    def _profiler_per_request_method(self, shutdown: bool = False) -> None:
+        """Display profiler data per method."""
+        profiler_timedelta_start = (datetime.datetime.now() - self.profiler_per_request_method_starttime).total_seconds()
+        for method in REQUEST_METHODS:
+            if self.profiler_per_request_method_counter[method] > 0:
+                s = io.StringIO()
+                s.write("**Profiling statistics BEGIN**\n")
+                stats = pstats.Stats(self.profiler_per_request_method[method], stream=s).sort_stats('cumulative')
+                stats.print_stats(self._profiling_top_x_functions)  # Print top X functions
+                s.write("**Profiling statistics END**\n")
+                logger.info("Profiling data per request method %s after %d seconds and %d requests:\n%s", method, profiler_timedelta_start, self.profiler_per_request_method_counter[method], utils.textwrap_str(s.getvalue(), -1))
+            else:
+                if shutdown:
+                    logger.info("Profiling data per request method %s after %d seconds: (no request seen so far)", method, profiler_timedelta_start)
+                else:
+                    logger.debug("Profiling data per request method %s after %d seconds: (no request seen so far)", method, profiler_timedelta_start)

    def _scrub_headers(self, environ: types.WSGIEnviron) -> types.WSGIEnviron:
        """Mask passwords and cookies."""
@@ -132,7 +217,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                             "%s", environ.get("REQUEST_METHOD", "unknown"),
                             environ.get("PATH_INFO", ""), e, exc_info=True)
                # Make minimal response
-                status, raw_headers, raw_answer = (
+                status, raw_headers, raw_answer, xml_request = (
                    httputils.INTERNAL_SERVER_ERROR)
                assert isinstance(raw_answer, str)
                answer = raw_answer.encode("ascii")
@@ -151,20 +236,29 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
        request_method = environ["REQUEST_METHOD"].upper()
        unsafe_path = environ.get("PATH_INFO", "")
        https = environ.get("HTTPS", "")
+        profiler = None
+        profiler_active = False
+        xml_request = None
+
+        context = AuthContext()

        """Manage a request."""
        def response(status: int, headers: types.WSGIResponseHeaders,
-                     answer: Union[None, str, bytes]) -> _IntermediateResponse:
+                     answer: Union[None, str, bytes],
+                     xml_request: Union[None, str] = None) -> _IntermediateResponse:
            """Helper to create response from internal types.WSGIResponse"""
            headers = dict(headers)
+            content_encoding = "plain"
            # Set content length
            answers = []
            if answer is not None:
                if isinstance(answer, str):
                    if self._response_content_on_debug:
-                        logger.debug("Response content:\n%s", answer)
+                        if logger.isEnabledFor(logging.DEBUG):
+                            logger.debug("Response content (nonXML):\n%s", utils.textwrap_str(answer))
                    else:
-                        logger.debug("Response content: suppressed by config/option [logging] response_content_on_debug")
+                        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 = [
@@ -176,6 +270,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                    zcomp = zlib.compressobj(wbits=16 + zlib.MAX_WBITS)
                    answer = zcomp.compress(answer) + zcomp.flush()
                    headers["Content-Encoding"] = "gzip"
+                    content_encoding = "gzip"

                headers["Content-Length"] = str(len(answer))
                answers.append(answer)
@@ -183,13 +278,79 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
            # Add extra headers set in configuration
            headers.update(self._extra_headers)

+            if self._response_header_on_debug:
+                if logger.isEnabledFor(logging.DEBUG):
+                    logger.debug("Response header:\n%s", utils.textwrap_str(pprint.pformat(headers)))
+            else:
+                if logger.isEnabledFor(logging.DEBUG):
+                    logger.debug("Response header: suppressed by config/option [logging] response_header_on_debug")
+
            # Start response
            time_end = datetime.datetime.now()
+            time_delta_seconds = (time_end - time_begin).total_seconds()
            status_text = "%d %s" % (
                status, client.responses.get(status, "Unknown"))
-            logger.info("%s response status for %r%s in %.3f seconds: %s",
-                        request_method, unsafe_path, depthinfo,
-                        (time_end - time_begin).total_seconds(), status_text)
+            flags = []
+            if xml_request is not None:
+                if "<sync-token />" in xml_request:
+                    flags.append("sync-token")
+                if "<getetag />" in xml_request:
+                    flags.append("getetag")
+                if "<CS:getctag />" in xml_request:
+                    flags.append("getctag")
+                if "<sync-collection " in xml_request:
+                    flags.append("sync-collection")
+            if flags:
+                flags_text = " (" + " ".join(flags) + ")"
+            else:
+                flags_text = ""
+            if answer is not None:
+                logger.info("%s response status for %r%s in %.3f seconds %s %s bytes%s: %s",
+                            request_method, unsafe_path, depthinfo,
+                            (time_end - time_begin).total_seconds(), content_encoding, str(len(answer)),
+                            flags_text,
+                            status_text)
+            else:
+                logger.info("%s response status for %r%s in %.3f seconds: %s",
+                            request_method, unsafe_path, depthinfo,
+                            time_delta_seconds, status_text)
+
+            # Profiling end
+            if self._profiling_per_request:
+                if profiler_active is True:
+                    if profiler is not None:
+                        # Profiling per request
+                        if time_delta_seconds < self._profiling_per_request_min_duration:
+                            logger.debug("Profiling data per request %s for %r%s: (suppressed because duration below minimum %.3f < %.3f)", request_method, unsafe_path, depthinfo, time_delta_seconds, self._profiling_per_request_min_duration)
+                        else:
+                            s = io.StringIO()
+                            s.write("**Profiling statistics BEGIN**\n")
+                            stats = pstats.Stats(profiler, stream=s).sort_stats('cumulative')
+                            stats.print_stats(self._profiling_top_x_functions)  # Print top X functions
+                            s.write("**Profiling statistics END**\n")
+                            if self._profiling_per_request_header:
+                                s.write("**Profiling request header BEGIN**\n")
+                                s.write(pprint.pformat(self._scrub_headers(environ)))
+                                s.write("\n**Profiling request header END**")
+                            if self._profiling_per_request_xml:
+                                if xml_request is not None:
+                                    s.write("\n**Profiling request content (XML) BEGIN**\n")
+                                    if xml_request is not None:
+                                        s.write(xml_request)
+                                    s.write("**Profiling request content (XML) END**")
+                            logger.info("Profiling data per request %s for %r%s:\n%s", request_method, unsafe_path, depthinfo, utils.textwrap_str(s.getvalue(), -1))
+                    else:
+                        logger.debug("Profiling data per request %s for %r%s: (suppressed because of no data)", request_method, unsafe_path, depthinfo)
+                else:
+                    logger.info("Profiling data per request %s for %r%s: (not available because of concurrent running profiling request)", request_method, unsafe_path, depthinfo)
+            elif self._profiling_per_request_method:
+                self.profiler_per_request_method[request_method].disable()
+                self.profiler_per_request_method_counter[request_method] += 1
+                profiler_timedelta = (datetime.datetime.now() - self.profiler_per_request_method_logtime).total_seconds()
+                if profiler_timedelta > self._profiling_per_request_method_interval:
+                    self._profiler_per_request_method()
+                    self.profiler_per_request_method_logtime = datetime.datetime.now()
+
            # Return response content
            return status_text, list(headers.items()), answers

@@ -197,12 +358,16 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
        remote_host = "unknown"
        if environ.get("REMOTE_HOST"):
            remote_host = repr(environ["REMOTE_HOST"])
-        elif environ.get("REMOTE_ADDR"):
-            remote_host = environ["REMOTE_ADDR"]
+        if environ.get("REMOTE_ADDR"):
+            if remote_host == 'unknown':
+                remote_host = environ["REMOTE_ADDR"]
+            context.remote_addr = environ["REMOTE_ADDR"]
        if environ.get("HTTP_X_FORWARDED_FOR"):
            reverse_proxy = True
            remote_host = "%s (forwarded for %r)" % (
                remote_host, environ["HTTP_X_FORWARDED_FOR"])
+        if environ.get("HTTP_X_REMOTE_ADDR"):
+            context.x_remote_addr = environ["HTTP_X_REMOTE_ADDR"]
        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 = ""
@@ -220,7 +385,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                    remote_host, remote_useragent, https_info)
        if self._request_header_on_debug:
            logger.debug("Request header:\n%s",
-                         pprint.pformat(self._scrub_headers(environ)))
+                         utils.textwrap_str(pprint.pformat(self._scrub_headers(environ))))
        else:
            logger.debug("Request header: suppressed by config/option [logging] request_header_on_debug")

@@ -257,7 +422,10 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                logger.debug("Called by reverse proxy, remove base prefix %r from path: %r => %r", base_prefix, path, path_new)
                path = path_new
            else:
-                logger.warning("Called by reverse proxy, cannot remove base prefix %r from path: %r as not matching", base_prefix, path)
+                if self._auth_type in ['remote_user', 'http_remote_user', 'http_x_remote_user'] and self._web_type == 'internal':
+                    logger.warning("Called by reverse proxy, cannot remove base prefix %r from path: %r as not matching (may cause authentication issues using internal WebUI)", base_prefix, path)
+                else:
+                    logger.debug("Called by reverse proxy, cannot remove base prefix %r from path: %r as not matching", base_prefix, path)

        # Get function corresponding to method
        function = getattr(self, "do_%s" % request_method, None)
@@ -288,7 +456,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                self.configuration, environ, base64.b64decode(
                    authorization.encode("ascii"))).split(":", 1)

-        (user, info) = self._auth.login(login, password) or ("", "") if login else ("", "")
+        (user, info) = self._auth.login(login, password, context) or ("", "") if login else ("", "")
        if self.configuration.get("auth", "type") == "ldap":
            try:
                logger.debug("Groups received from LDAP: %r", ",".join(self._auth._ldap_groups))
@@ -323,7 +491,7 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                if "W" in self._rights.authorization(user, principal_path):
                    with self._storage.acquire_lock("w", user):
                        try:
-                            new_coll = self._storage.create_collection(principal_path)
+                            new_coll, _, _ = self._storage.create_collection(principal_path)
                            if new_coll:
                                jsn_coll = self.configuration.get("storage", "predefined_collections")
                                for (name_coll, props) in jsn_coll.items():
@@ -349,15 +517,42 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                    return response(*httputils.REQUEST_ENTITY_TOO_LARGE)

        if not login or user:
-            status, headers, answer = function(
-                environ, base_prefix, path, user)
-            if (status, headers, answer) == httputils.NOT_ALLOWED:
+            # Profiling
+            if self._profiling_per_request:
+                profiler = cProfile.Profile()
+                try:
+                    profiler.enable()
+                except ValueError:
+                    profiler_active = False
+                else:
+                    profiler_active = True
+            elif self._profiling_per_request_method:
+                try:
+                    self.profiler_per_request_method[request_method].enable()
+                except ValueError:
+                    profiler_active = False
+                else:
+                    profiler_active = True
+
+            status, headers, answer, xml_request = function(
+                environ, base_prefix, path, user, remote_host, remote_useragent)
+
+            # Profiling
+            if self._profiling_per_request:
+                if profiler is not None:
+                    if profiler_active is True:
+                        profiler.disable()
+            elif self._profiling_per_request_method:
+                if profiler_active is True:
+                    self.profiler_per_request_method[request_method].disable()
+
+            if (status, headers, answer, xml_request) == httputils.NOT_ALLOWED:
                logger.info("Access to %r denied for %s", path,
                            repr(user) if user else "anonymous user")
        else:
-            status, headers, answer = httputils.NOT_ALLOWED
+            status, headers, answer, xml_request = httputils.NOT_ALLOWED

-        if ((status, headers, answer) == httputils.NOT_ALLOWED and not user and
+        if ((status, headers, answer, xml_request) == httputils.NOT_ALLOWED and not user and
                not external_login):
            # Unknown or unauthorized user
            logger.debug("Asking client for authentication")
@@ -367,4 +562,4 @@ class Application(ApplicationPartDelete, ApplicationPartHead,
                "WWW-Authenticate":
                "Basic realm=\"%s\"" % self._auth_realm})

-        return response(status, headers, answer)
+        return response(status, headers, answer, xml_request)
--- a/radicale/app/base.py
+++ b/radicale/app/base.py
@@ -23,7 +23,7 @@ import xml.etree.ElementTree as ET
 from typing import Optional

 from radicale import (auth, config, hook, httputils, pathutils, rights,
-                      storage, types, web, xmlutils)
+                      storage, types, utils, web, xmlutils)
 from radicale.log import logger

 # HACK: https://github.com/tiran/defusedxml/issues/54
@@ -39,8 +39,10 @@ class ApplicationBase:
    _rights: rights.BaseRights
    _web: web.BaseWeb
    _encoding: str
+    _max_resource_size: int
    _permit_delete_collection: bool
    _permit_overwrite_collection: bool
+    _strict_preconditions: bool
    _hook: hook.BaseHook

    def __init__(self, configuration: config.Configuration) -> None:
@@ -70,7 +72,7 @@ class ApplicationBase:
        if logger.isEnabledFor(logging.DEBUG):
            if self._request_content_on_debug:
                logger.debug("Request content (XML):\n%s",
-                             xmlutils.pretty_xml(xml_content))
+                             utils.textwrap_str(xmlutils.pretty_xml(xml_content)))
            else:
                logger.debug("Request content (XML): suppressed by config/option [logging] request_content_on_debug")
        return xml_content
@@ -79,7 +81,7 @@ class ApplicationBase:
        if logger.isEnabledFor(logging.DEBUG):
            if self._response_content_on_debug:
                logger.debug("Response content (XML):\n%s",
-                             xmlutils.pretty_xml(xml_content))
+                             utils.textwrap_str(xmlutils.pretty_xml(xml_content)))
            else:
                logger.debug("Response content (XML): suppressed by config/option [logging] response_content_on_debug")
        f = io.BytesIO()
@@ -92,7 +94,7 @@ class ApplicationBase:
        """Generate XML error response."""
        headers = {"Content-Type": "text/xml; charset=%s" % self._encoding}
        content = self._xml_response(xmlutils.webdav_error(human_tag))
-        return status, headers, content
+        return status, headers, content, None


 class Access:
--- a/radicale/app/delete.py
+++ b/radicale/app/delete.py
@@ -24,7 +24,7 @@ from typing import Optional

 from radicale import httputils, storage, types, xmlutils
 from radicale.app.base import Access, ApplicationBase
-from radicale.hook import DeleteHookNotificationItem
+from radicale.hook import HookNotificationItem, HookNotificationItemTypes
 from radicale.log import logger


@@ -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) -> types.WSGIResponse:
+                  path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage DELETE request."""
        access = Access(self._rights, user, path)
        if not access.check("w"):
@@ -82,10 +82,13 @@ class ApplicationPartDelete(ApplicationBase):
                        return httputils.NOT_ALLOWED
                for i in item.get_all():
                    hook_notification_item_list.append(
-                        DeleteHookNotificationItem(
-                            access.path,
-                            i.uid,
-                            old_content=item.serialize()  # type: ignore
+                        HookNotificationItem(
+                            notification_item_type=HookNotificationItemTypes.DELETE,
+                            path=access.path,
+                            content=i.uid,
+                            uid=i.uid,
+                            old_content=i.serialize(),  # type: ignore
+                            new_content=None
                        )
                    )
                xml_answer = xml_delete(base_prefix, path, item)
@@ -93,10 +96,13 @@ class ApplicationPartDelete(ApplicationBase):
                assert item.collection is not None
                assert item.href is not None
                hook_notification_item_list.append(
-                    DeleteHookNotificationItem(
-                        access.path,
-                        item.uid,
-                        old_content=item.serialize()  # type: ignore
+                    HookNotificationItem(
+                        notification_item_type=HookNotificationItemTypes.DELETE,
+                        path=access.path,
+                        content=item.uid,
+                        uid=item.uid,
+                        old_content=item.serialize(),  # type: ignore
+                        new_content=None,
                    )
                )
                xml_answer = xml_delete(
@@ -104,4 +110,4 @@ class ApplicationPartDelete(ApplicationBase):
            for notification_item in hook_notification_item_list:
                self._hook.notify(notification_item)
            headers = {"Content-Type": "text/xml; charset=%s" % self._encoding}
-            return client.OK, headers, self._xml_response(xml_answer)
+            return client.OK, headers, self._xml_response(xml_answer), None
--- a/radicale/app/get.py
+++ b/radicale/app/get.py
@@ -2,7 +2,8 @@
 # Copyright © 2008 Nicolas Kandel
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
-# Copyright © 2017-2018 Unrud <unrud@outlook.com>
+# Copyright © 2017-2023 Unrud <unrud@outlook.com>
+# Copyright © 2025-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -58,7 +59,7 @@ class ApplicationPartGet(ApplicationBase):
        return value

    def do_GET(self, environ: types.WSGIEnviron, base_prefix: str, path: str,
-               user: str) -> types.WSGIResponse:
+               user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage GET request."""
        # Redirect to /.web if the root path is requested
        if not pathutils.strip_path(path):
@@ -108,4 +109,4 @@ class ApplicationPartGet(ApplicationBase):
            if content_disposition:
                headers["Content-Disposition"] = content_disposition
            answer = item.serialize()
-            return client.OK, headers, answer
+            return client.OK, headers, answer, None
--- a/radicale/app/head.py
+++ b/radicale/app/head.py
@@ -2,7 +2,8 @@
 # Copyright © 2008 Nicolas Kandel
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
-# Copyright © 2017-2018 Unrud <unrud@outlook.com>
+# Copyright © 2017-2022 Unrud <unrud@outlook.com>
+# Copyright © 2025-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -25,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) -> types.WSGIResponse:
+                user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage HEAD request."""
        # Body is dropped in `Application.__call__` for HEAD requests
-        return self.do_GET(environ, base_prefix, path, user)
+        return self.do_GET(environ, base_prefix, path, user, remote_host, remote_useragent)
--- a/radicale/app/mkcalendar.py
+++ b/radicale/app/mkcalendar.py
@@ -33,7 +33,7 @@ from radicale.log import logger
 class ApplicationPartMkcalendar(ApplicationBase):

    def do_MKCALENDAR(self, environ: types.WSGIEnviron, base_prefix: str,
-                      path: str, user: str) -> types.WSGIResponse:
+                      path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage MKCALENDAR request."""
        if "w" not in self._rights.authorization(user, path):
            return httputils.NOT_ALLOWED
@@ -89,4 +89,4 @@ class ApplicationPartMkcalendar(ApplicationBase):
                    logger.warning(
                        "Bad MKCALENDAR request on %r: %s", path, e, exc_info=True)
                    return httputils.BAD_REQUEST
-            return client.CREATED, {}, None
+            return client.CREATED, {}, None, xmlutils.pretty_xml(xml_content)
--- a/radicale/app/mkcol.py
+++ b/radicale/app/mkcol.py
@@ -33,7 +33,7 @@ from radicale.log import logger
 class ApplicationPartMkcol(ApplicationBase):

    def do_MKCOL(self, environ: types.WSGIEnviron, base_prefix: str,
-                 path: str, user: str) -> types.WSGIResponse:
+                 path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage MKCOL request."""
        permissions = self._rights.authorization(user, path)
        if not rights.intersect(permissions, "Ww"):
@@ -94,4 +94,4 @@ class ApplicationPartMkcol(ApplicationBase):
                        "Bad MKCOL request on %r (type:%s): %s", path, collection_type, e, exc_info=True)
                    return httputils.BAD_REQUEST
            logger.info("MKCOL request %r (type:%s): %s", path, collection_type, "successful")
-            return client.CREATED, {}, None
+            return client.CREATED, {}, None, xmlutils.pretty_xml(xml_content)
--- a/radicale/app/move.py
+++ b/radicale/app/move.py
@@ -22,7 +22,7 @@ import errno
 import posixpath
 import re
 from http import client
-from urllib.parse import urlparse
+from urllib.parse import unquote, urlparse

 from radicale import httputils, pathutils, storage, types
 from radicale.app.base import Access, ApplicationBase
@@ -34,7 +34,7 @@ def get_server_netloc(environ: types.WSGIEnviron, force_port: bool = False):
        host = environ["HTTP_X_FORWARDED_HOST"]
        proto = environ.get("HTTP_X_FORWARDED_PROTO") or "http"
        port = "443" if proto == "https" else "80"
-        port = environ["HTTP_X_FORWARDED_PORT"] or port
+        port = environ.get("HTTP_X_FORWARDED_PORT") or port
    else:
        host = environ.get("HTTP_HOST") or environ["SERVER_NAME"]
        proto = environ["wsgi.url_scheme"]
@@ -48,18 +48,25 @@ 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) -> types.WSGIResponse:
+                path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage MOVE request."""
        raw_dest = environ.get("HTTP_DESTINATION", "")
-        to_url = urlparse(raw_dest)
-        to_netloc_with_port = to_url.netloc
-        if to_url.port is None:
-            to_netloc_with_port += (":443" if to_url.scheme == "https"
-                                    else ":80")
-        if to_netloc_with_port != get_server_netloc(environ, force_port=True):
-            logger.info("Unsupported destination address: %r", raw_dest)
-            # Remote destination server, not supported
-            return httputils.REMOTE_DESTINATION
+
+        # Decode URL-encoded characters (e.g. %40 -> @) before parsing
+        raw_dest_decoded = unquote(raw_dest)
+        to_url = urlparse(raw_dest_decoded)
+
+        # Only check netloc for absolute URLs
+        if to_url.netloc:
+            to_netloc_with_port = to_url.netloc
+            if to_url.port is None:
+                to_netloc_with_port += (":443" if to_url.scheme == "https"
+                                        else ":80")
+            if to_netloc_with_port != get_server_netloc(environ, force_port=True):
+                logger.info("Unsupported destination address: %r", raw_dest)
+                # Remote destination server, not supported
+                return httputils.REMOTE_DESTINATION
+
        access = Access(self._rights, user, path)
        if not access.check("w"):
            return httputils.NOT_ALLOWED
@@ -127,4 +134,4 @@ class ApplicationPartMove(ApplicationBase):
                    logger.warning(
                        "Bad MOVE request on %r: %s", path, e, exc_info=True)
                    return httputils.BAD_REQUEST
-            return client.NO_CONTENT if to_item else client.CREATED, {}, None
+            return client.NO_CONTENT if to_item else client.CREATED, {}, None, None
--- a/radicale/app/options.py
+++ b/radicale/app/options.py
@@ -2,7 +2,8 @@
 # Copyright © 2008 Nicolas Kandel
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
-# Copyright © 2017-2018 Unrud <unrud@outlook.com>
+# Copyright © 2017-2021 Unrud <unrud@outlook.com>
+# Copyright © 2025-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -26,10 +27,10 @@ from radicale.app.base import ApplicationBase
 class ApplicationPartOptions(ApplicationBase):

    def do_OPTIONS(self, environ: types.WSGIEnviron, base_prefix: str,
-                   path: str, user: str) -> types.WSGIResponse:
+                   path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage OPTIONS request."""
        headers = {
            "Allow": ", ".join(
                name[3:] for name in dir(self) if name.startswith("do_")),
            "DAV": httputils.DAV_HEADERS}
-        return client.OK, headers, None
+        return client.OK, headers, None, None
--- a/radicale/app/post.py
+++ b/radicale/app/post.py
@@ -2,8 +2,9 @@
 # Copyright © 2008 Nicolas Kandel
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
-# Copyright © 2017-2018 Unrud <unrud@outlook.com>
-# Copyright © 2020 Tom Hacohen <tom@stosb.com>
+# Copyright © 2017-2021 Unrud <unrud@outlook.com>
+# Copyright © 2020-2020 Tom Hacohen <tom@stosb.com>
+# Copyright © 2025-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -25,7 +26,7 @@ from radicale.app.base import ApplicationBase
 class ApplicationPartPost(ApplicationBase):

    def do_POST(self, environ: types.WSGIEnviron, base_prefix: str,
-                path: str, user: str) -> types.WSGIResponse:
+                path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage POST request."""
        if path == "/.web" or path.startswith("/.web/"):
            return self._web.post(environ, base_prefix, path, user)
--- a/radicale/app/propfind.py
+++ b/radicale/app/propfind.py
@@ -2,7 +2,8 @@
 # Copyright © 2008 Nicolas Kandel
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
-# Copyright © 2017-2018 Unrud <unrud@outlook.com>
+# Copyright © 2017-2021 Unrud <unrud@outlook.com>
+# Copyright © 2025-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -25,7 +26,8 @@ import xml.etree.ElementTree as ET
 from http import client
 from typing import Dict, Iterable, Iterator, List, Optional, Sequence, Tuple

-from radicale import httputils, pathutils, rights, storage, types, xmlutils
+from radicale import (httputils, pathutils, rights, storage, types, utils,
+                      xmlutils)
 from radicale.app.base import Access, ApplicationBase
 from radicale.log import logger

@@ -33,7 +35,7 @@ from radicale.log import logger
 def xml_propfind(base_prefix: str, path: str,
                 xml_request: Optional[ET.Element],
                 allowed_items: Iterable[Tuple[types.CollectionOrItem, str]],
-                 user: str, encoding: str) -> Optional[ET.Element]:
+                 user: str, encoding: str, max_resource_size: int) -> Optional[ET.Element]:
    """Read and answer PROPFIND requests.

    Read rfc4918-9.1 for info.
@@ -70,14 +72,14 @@ def xml_propfind(base_prefix: str, path: str,
        write = permission == "w"
        multistatus.append(xml_propfind_response(
            base_prefix, path, item, props, user, encoding, write=write,
-            allprop=allprop, propname=propname))
+            allprop=allprop, propname=propname, max_resource_size=max_resource_size))

    return multistatus


 def xml_propfind_response(
        base_prefix: str, path: str, item: types.CollectionOrItem,
-        props: Sequence[str], user: str, encoding: str, write: bool = False,
+        props: Sequence[str], user: str, encoding: str, max_resource_size: int, write: bool = False,
        propname: bool = False, allprop: bool = False) -> ET.Element:
    """Build and return a PROPFIND response."""
    if propname and allprop or (props and (propname or allprop)):
@@ -110,6 +112,9 @@ def xml_propfind_response(
        props.append(xmlutils.make_clark("D:supported-report-set"))
        props.append(xmlutils.make_clark("D:resourcetype"))
        props.append(xmlutils.make_clark("D:owner"))
+        if not allprop:
+            # RFC4791#5.2.5: SHOULD NOT be returned by a PROPFIND DAV:allprop request
+            props.append(xmlutils.make_clark("C:max-resource-size"))

        if is_collection and collection.is_principal:
            props.append(xmlutils.make_clark("C:calendar-user-address-set"))
@@ -131,6 +136,10 @@ def xml_propfind_response(
                props.append(xmlutils.make_clark("CS:getctag"))
                props.append(
                    xmlutils.make_clark("C:supported-calendar-component-set"))
+            if collection.tag == "VADDRESSBOOK":
+                props.append(xmlutils.make_clark("CS:getctag"))
+                props.append(
+                    xmlutils.make_clark("CR:supported-address-data"))

            meta = collection.get_meta()
            for tag in meta:
@@ -184,6 +193,21 @@ def xml_propfind_response(
                    element.append(comp)
            else:
                is404 = True
+        elif tag == xmlutils.make_clark("CR:supported-address-data"):
+            if is_collection and is_leaf and collection.tag == "VADDRESSBOOK":
+                # Advertise supported vCard versions per RFC 6352 section 6.2.2
+                # vCard 4.0 requires vobject >= 1.0.0
+                versions: Sequence[str] = (("4.0", "3.0")
+                                           if utils.vobject_supports_vcard4()
+                                           else ("3.0",))
+                for version in versions:
+                    address_data_type = ET.Element(
+                        xmlutils.make_clark("CR:address-data-type"))
+                    address_data_type.set("content-type", "text/vcard")
+                    address_data_type.set("version", version)
+                    element.append(address_data_type)
+            else:
+                is404 = True
        elif tag == xmlutils.make_clark("D:current-user-principal"):
            if user:
                child_element = ET.Element(xmlutils.make_clark("D:href"))
@@ -238,6 +262,9 @@ def xml_propfind_response(
                child_element.text = xmlutils.make_href(
                    base_prefix, "/%s/" % collection.owner)
                element.append(child_element)
+        elif tag == xmlutils.make_clark("C:max-resource-size"):
+            # RFC4791#5.2.5
+            element.text = str(max_resource_size)
        elif is_collection:
            if tag == xmlutils.make_clark("D:getcontenttype"):
                if is_leaf:
@@ -376,7 +403,7 @@ class ApplicationPartPropfind(ApplicationBase):
                yield item, permission

    def do_PROPFIND(self, environ: types.WSGIEnviron, base_prefix: str,
-                    path: str, user: str) -> types.WSGIResponse:
+                    path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage PROPFIND request."""
        access = Access(self._rights, user, path)
        if not access.check("r"):
@@ -406,7 +433,7 @@ class ApplicationPartPropfind(ApplicationBase):
            headers = {"DAV": httputils.DAV_HEADERS,
                       "Content-Type": "text/xml; charset=%s" % self._encoding}
            xml_answer = xml_propfind(base_prefix, path, xml_content,
-                                      allowed_items, user, self._encoding)
+                                      allowed_items, user, self._encoding, max_resource_size=self._max_resource_size)
            if xml_answer is None:
                return httputils.NOT_ALLOWED
-            return client.MULTI_STATUS, headers, self._xml_response(xml_answer)
+            return client.MULTI_STATUS, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content)
--- a/radicale/app/proppatch.py
+++ b/radicale/app/proppatch.py
@@ -73,7 +73,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) -> types.WSGIResponse:
+                     path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage PROPPATCH request."""
        access = Access(self._rights, user, path)
        if not access.check("w"):
@@ -101,13 +101,17 @@ class ApplicationPartProppatch(ApplicationBase):
                xml_answer = xml_proppatch(base_prefix, path, xml_content,
                                           item)
                if xml_content is not None:
+                    content = DefusedET.tostring(
+                        xml_content,
+                        encoding=self._encoding
+                    ).decode(encoding=self._encoding)
                    hook_notification_item = HookNotificationItem(
-                        HookNotificationItemTypes.CPATCH,
-                        access.path,
-                        DefusedET.tostring(
-                            xml_content,
-                            encoding=self._encoding
-                        ).decode(encoding=self._encoding)
+                        notification_item_type=HookNotificationItemTypes.CPATCH,
+                        path=access.path,
+                        content=content,
+                        uid=None,
+                        old_content=None,
+                        new_content=content
                    )
                    self._hook.notify(hook_notification_item)
            except ValueError as e:
@@ -127,4 +131,4 @@ 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)
+            return client.MULTI_STATUS, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content)
--- a/radicale/app/put.py
+++ b/radicale/app/put.py
@@ -46,7 +46,7 @@ PRODID = u"-//Radicale//NONSGML Version " + utils.package_version("radicale") +


 def prepare(vobject_items: List[vobject.base.Component], path: str,
-            content_type: str, permission: bool, parent_permission: bool,
+            content_type: str, permission: bool, parent_permission: bool, max_resource_size: int,
            tag: Optional[str] = None,
            write_whole_collection: Optional[bool] = None) -> Tuple[
                Iterator[radicale_item.Item],  # items
@@ -93,24 +93,61 @@ def prepare(vobject_items: List[vobject.base.Component], path: str,
                    logger.debug("Prepare item with UID '%s'", item.uid)
                    try:
                        item.prepare()
-                    except ValueError as e:
+                    except (RuntimeError, ValueError, AttributeError) as e:
                        if logger.isEnabledFor(logging.DEBUG):
-                            logger.warning("Problem during prepare item with UID '%s' (content below): %s\n%s", item.uid, e, item._text)
+                            if item._text is None:
+                                content = vobject_item
+                            else:
+                                content = item._text
+                            logger.warning("Problem during prepare item with UID '%s' (content below): %s\n%s", item.uid, e, utils.textwrap_str(content))
                        else:
                            logger.warning("Problem during prepare item with UID '%s' (content suppressed in this loglevel): %s", item.uid, e)
                        raise
+                    size = len(item.serialize())
+                    if (size > max_resource_size):
+                        logger.warning("PUT request contains item with UID %r size %d > limit %d: %r", item.uid, size, max_resource_size, path)
+                        # Use OverflowError as flag for max_resource_size
+                        raise OverflowError
+                    else:
+                        logger.debug("PUT request contains item with UID %r size %d <= limit %d: %r", item.uid, size, max_resource_size, path)
                    items.append(item)
            elif write_whole_collection and tag == "VADDRESSBOOK":
                for vobject_item in vobject_items:
                    item = radicale_item.Item(collection_path=collection_path,
                                              vobject_item=vobject_item)
-                    item.prepare()
+                    logger.debug("Prepare item with UID '%s'", item.uid)
+                    try:
+                        item.prepare()
+                    except (RuntimeError, ValueError, AttributeError) as e:
+                        if logger.isEnabledFor(logging.DEBUG):
+                            if item._text is None:
+                                content = vobject_item
+                            else:
+                                content = item._text
+                            logger.warning("Problem during prepare item with UID '%s' (content below): %s\n%s", item.uid, e, utils.textwrap_str(content))
+                        else:
+                            logger.warning("Problem during prepare item with UID '%s' (content suppressed in this loglevel): %s", item.uid, e)
+                        raise
+                    size = len(item.serialize())
+                    if (size > max_resource_size):
+                        logger.warning("PUT request contains item with UID %r size %d > limit %d: %r", item.uid, size, max_resource_size, path)
+                        # Use OverflowError as flag for max_resource_size
+                        raise OverflowError
+                    else:
+                        logger.debug("PUT request contains item with UID %r size %d <= limit %d: %r", item.uid, size, max_resource_size, path)
                    items.append(item)
            elif not write_whole_collection:
                vobject_item, = vobject_items
                item = radicale_item.Item(collection_path=collection_path,
                                          vobject_item=vobject_item)
                item.prepare()
+                size = len(item.serialize())
+                if (size > max_resource_size):
+                    logger.warning("PUT request contains item with UID %r size %d above limit %d: %r", item.uid, size, max_resource_size, path)
+                    # Use OverflowError as flag for max_resource_size
+                    raise OverflowError
+                else:
+                    logger.debug("PUT request contains item with UID %r size %d below limit %d: %r", item.uid, size, max_resource_size, path)
                items.append(item)

        if write_whole_collection:
@@ -142,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) -> types.WSGIResponse:
+               path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage PUT request."""
        access = Access(self._rights, user, path)
        if not access.check("w"):
@@ -164,7 +201,10 @@ class ApplicationPartPut(ApplicationBase):
            logger.warning(
                "Bad PUT request on %r (read_components): %s", path, e, exc_info=True)
            if self._log_bad_put_request_content:
-                logger.warning("Bad PUT request content of %r:\n%s", path, content)
+                logger.warning("Bad PUT request content of %r:\n%s", path, utils.textwrap_str(content))
+                if logger.isEnabledFor(logging.DEBUG):
+                    logger.debug("Request content (sha256sum): %s", utils.sha256_str(content))
+                    logger.debug("Request content (hexdump/lines):\n%s", utils.hexdump_lines(content))
            else:
                logger.debug("Bad PUT request content: suppressed by config/option [logging] bad_put_request_content")
            return httputils.BAD_REQUEST
@@ -172,7 +212,8 @@ class ApplicationPartPut(ApplicationBase):
         prepared_props, prepared_exc_info) = prepare(
             vobject_items, path, content_type,
             bool(rights.intersect(access.permissions, "Ww")),
-             bool(rights.intersect(access.parent_permissions, "w")))
+             bool(rights.intersect(access.parent_permissions, "w")),
+             self._max_resource_size)

        with self._storage.acquire_lock("w", user, path=path, request="PUT"):
            item = next(iter(self._storage.discover(path)), None)
@@ -207,6 +248,9 @@ class ApplicationPartPut(ApplicationBase):
                return httputils.NOT_ALLOWED

            etag = environ.get("HTTP_IF_MATCH", "")
+            if item and not etag and self._strict_preconditions:
+                logger.warning("Precondition failed for %r: existing item, no If-Match header, strict mode enabled", path)
+                return httputils.PRECONDITION_FAILED
            if not item and etag:
                # Etag asked but no item found: item has been removed
                logger.warning("Precondition failed on PUT request for %r (HTTP_IF_MATCH: %s, item not existing)", path, etag)
@@ -233,24 +277,46 @@ class ApplicationPartPut(ApplicationBase):
                     vobject_items, path, content_type,
                     bool(rights.intersect(access.permissions, "Ww")),
                     bool(rights.intersect(access.parent_permissions, "w")),
+                     self._max_resource_size,
                     tag, write_whole_collection)
            props = prepared_props
            if prepared_exc_info:
-                logger.warning(
-                    "Bad PUT request on %r (prepare): %s", path, prepared_exc_info[1],
-                    exc_info=prepared_exc_info)
-                return httputils.BAD_REQUEST
+                # Use OverflowError as flag for max_resource_size
+                if prepared_exc_info[0] == OverflowError:
+                    return httputils.PRECONDITION_FAILED
+                else:
+                    logger.warning(
+                        "Bad PUT request on %r (prepare): %s", path, prepared_exc_info[1],
+                        exc_info=prepared_exc_info)
+                    return httputils.BAD_REQUEST

            if write_whole_collection:
                try:
-                    etag = self._storage.create_collection(
-                        path, prepared_items, props).etag
+                    col, replaced_items, new_item_hrefs = self._storage.create_collection(
+                        href=path,
+                        items=prepared_items,
+                        props=props)
                    for item in prepared_items:
-                        hook_notification_item = HookNotificationItem(
-                            HookNotificationItemTypes.UPSERT,
-                            access.path,
-                            item.serialize()
-                        )
+                        # Try to grab the previously-existing item by href
+                        existing_item = replaced_items.get(item.href, None)  # type: ignore
+                        if existing_item:
+                            hook_notification_item = HookNotificationItem(
+                                notification_item_type=HookNotificationItemTypes.UPSERT,
+                                path=access.path,
+                                content=existing_item.serialize(),
+                                uid=None,
+                                old_content=existing_item.serialize(),
+                                new_content=item.serialize()
+                            )
+                        else:  # We assume the item is new because it was not in the replaced_items
+                            hook_notification_item = HookNotificationItem(
+                                notification_item_type=HookNotificationItemTypes.UPSERT,
+                                path=access.path,
+                                content=item.serialize(),
+                                uid=None,
+                                old_content=None,
+                                new_content=item.serialize()
+                            )
                        self._hook.notify(hook_notification_item)
                except ValueError as e:
                    logger.warning(
@@ -267,11 +333,15 @@ class ApplicationPartPut(ApplicationBase):

                href = posixpath.basename(pathutils.strip_path(path))
                try:
-                    etag = parent_item.upload(href, prepared_item).etag
+                    uploaded_item, replaced_item = parent_item.upload(href, prepared_item)
+                    etag = uploaded_item.etag
                    hook_notification_item = HookNotificationItem(
-                        HookNotificationItemTypes.UPSERT,
-                        access.path,
-                        prepared_item.serialize()
+                        notification_item_type=HookNotificationItemTypes.UPSERT,
+                        path=access.path,
+                        content=prepared_item.serialize(),
+                        uid=None,
+                        old_content=replaced_item.serialize() if replaced_item else None,
+                        new_content=prepared_item.serialize()
                    )
                    self._hook.notify(hook_notification_item)
                except ValueError as e:
@@ -294,7 +364,7 @@ class ApplicationPartPut(ApplicationBase):
                if (item and item.uid == prepared_item.uid):
                    logger.debug("PUT request updated existing item %r", path)
                    headers = {"ETag": etag}
-                    return client.NO_CONTENT, headers, None
+                    return client.NO_CONTENT, headers, None, None

            headers = {"ETag": etag}
-            return client.CREATED, headers, None
+            return client.CREATED, headers, None, None
--- a/radicale/app/report.py
+++ b/radicale/app/report.py
@@ -149,13 +149,14 @@ 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,
+               max_occurrence: int = 0, user: str = "", remote_addr: str = "", remote_useragent: str = ""
               ) -> Tuple[int, ET.Element]:
    """Read and answer REPORT requests that return XML.

    Read rfc3253-3.6 for info.

    """
+    logger.debug("TRACE/REPORT/xml_report: base_prefix=%r path=%r", base_prefix, path)
    multistatus = ET.Element(xmlutils.make_clark("D:multistatus"))
    if xml_request is None:
        return client.MULTI_STATUS, multistatus
@@ -212,8 +213,8 @@ 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
-            logger.warning("Client provided invalid sync token %r: %s",
-                           old_sync_token, e, exc_info=True)
+            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)
            # client.CONFLICT doesn't work with some clients (e.g. InfCloud)
            return (client.FORBIDDEN,
                    xmlutils.webdav_error("D:valid-sync-token"))
@@ -239,6 +240,7 @@ def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element],
        filter_copy = copy.deepcopy(filter_)

        if expand is not None:
+            logger.debug("TRACE/REPORT/xml_report: expand")
            for comp_filter in filter_copy.findall(".//" + xmlutils.make_clark("C:comp-filter")):
                if comp_filter.get("name", "").upper() == "VCALENDAR":
                    continue
@@ -275,21 +277,15 @@ def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element],

        found_props = []
        not_found_props = []
-        item_etag: str = ""

        for prop in props:
            element = ET.Element(prop.tag)
-            if prop.tag == xmlutils.make_clark("D:getetag"):
-                if expand is not None:
-                    item_etag = item.etag
-                else:
-                    element.text = item.etag
-                    found_props.append(element)
-            elif prop.tag == xmlutils.make_clark("D:getcontenttype"):
+            if prop.tag == xmlutils.make_clark("D:getcontenttype"):
                element.text = xmlutils.get_content_type(item, encoding)
                found_props.append(element)
            elif prop.tag in (
                    xmlutils.make_clark("C:calendar-data"),
+                    xmlutils.make_clark("D:getetag"),
                    xmlutils.make_clark("CR:address-data")):
                element.text = item.serialize()

@@ -326,11 +322,24 @@ def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element],
                        continue

                    n_vevents += n_vev
-                    found_props.append(expanded_element)
+                    if prop.tag == xmlutils.make_clark("D:getetag"):
+                        if n_vev > 0:
+                            logger.debug("TRACE/REPORT/xml_report: getetag/expanded element")
+                            element.text = item.etag
+                            found_props.append(element)
+                        else:
+                            logger.debug("TRACE/REPORT/xml_report: getetag/no expanded element")
+                    else:
+                        logger.debug("TRACE/REPORT/xml_report: default")
+                        found_props.append(expanded_element)
                else:
-                    found_props.append(element)
-                    if hasattr(item.vobject_item, "vevent_list"):
-                        n_vevents += len(item.vobject_item.vevent_list)
+                    if prop.tag == xmlutils.make_clark("D:getetag"):
+                        element.text = item.etag
+                        found_props.append(element)
+                    else:
+                        found_props.append(element)
+                        if hasattr(item.vobject_item, "vevent_list"):
+                            n_vevents += len(item.vobject_item.vevent_list)
                # Avoid DoS with too many events
                if max_occurrence and n_vevents > max_occurrence:
                    raise ValueError("REPORT occurrences limit of {} hit"
@@ -345,7 +354,7 @@ def xml_report(base_prefix: str, path: str, xml_request: Optional[ET.Element],
        if found_props or not_found_props:
            multistatus.append(xml_item_response(
                base_prefix, uri, found_props=found_props,
-                not_found_props=not_found_props, found_item=True, item_etag=item_etag))
+                not_found_props=not_found_props, found_item=True))

    return client.MULTI_STATUS, multistatus

@@ -481,7 +490,7 @@ def _expand(

            if not vevent:
                # Create new instance from recurrence
-                vevent = copy.deepcopy(base_vevent)
+                vevent = base_vevent.duplicate(base_vevent)

                # For all day events, the system timezone may influence the
                # results, so use recurrence_dt
@@ -679,7 +688,7 @@ def _find_overridden(
 def xml_item_response(base_prefix: str, href: str,
                      found_props: Sequence[ET.Element] = (),
                      not_found_props: Sequence[ET.Element] = (),
-                      found_item: bool = True, item_etag: str = "") -> ET.Element:
+                      found_item: bool = True) -> ET.Element:
    response = ET.Element(xmlutils.make_clark("D:response"))

    href_element = ET.Element(xmlutils.make_clark("D:href"))
@@ -693,10 +702,6 @@ def xml_item_response(base_prefix: str, href: str,
                status = ET.Element(xmlutils.make_clark("D:status"))
                status.text = xmlutils.make_response(code)
                prop_element = ET.Element(xmlutils.make_clark("D:prop"))
-                if (item_etag != "") and (code == 200):
-                    prop_etag = ET.Element(xmlutils.make_clark("D:getetag"))
-                    prop_etag.text = item_etag
-                    prop_element.append(prop_etag)
                for prop in props:
                    prop_element.append(prop)
                propstat.append(prop_element)
@@ -750,6 +755,7 @@ def retrieve_items(
        else:
            yield item, False
    if collection_requested:
+        logger.debug("TRACE/REPORT/retrieve_items: get_filtered")
        yield from collection.get_filtered(filters)


@@ -785,7 +791,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) -> types.WSGIResponse:
+                  path: str, user: str, remote_host: str, remote_useragent: str) -> types.WSGIResponse:
        """Manage REPORT request."""
        access = Access(self._rights, user, path)
        if not access.check("r"):
@@ -824,15 +830,15 @@ class ApplicationPartReport(ApplicationBase):
                        "Bad REPORT request on %r: %s", path, e, exc_info=True)
                    return httputils.BAD_REQUEST
                headers = {"Content-Type": "text/calendar; charset=%s" % self._encoding}
-                return status, headers, str(body)
+                return status, headers, str(body), xmlutils.pretty_xml(xml_content)
            else:
                try:
                    status, xml_answer = xml_report(
                        base_prefix, path, xml_content, collection, self._encoding,
-                        lock_stack.close, max_occurrence)
+                        lock_stack.close, max_occurrence, user, remote_host, remote_useragent)
                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)
+                return status, headers, self._xml_response(xml_answer), xmlutils.pretty_xml(xml_content)