From 3d4cd7f034c8f3f9960f18ca3f6692e2571e90a9 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 08:58:42 +0100 Subject: [PATCH 1/6] Add: display mtime_ns precision of storage folder with condition warning if too less --- CHANGELOG.md | 3 + pyproject.toml | 2 +- radicale/storage/multifilesystem/__init__.py | 74 +++++++++++++++++--- setup.py.legacy | 2 +- 4 files changed, 70 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 20b6bda6..94b74d73 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,8 @@ # Changelog +## 3.3.3.dev +* Add: display mtime_ns precision of storage folder with condition warning if too less + ## 3.3.2 * Fix: debug logging in rights/from_file * Add: option [storage] use_cache_subfolder_for_item for storing 'item' cache outside collection-root diff --git a/pyproject.toml b/pyproject.toml index aaeb805c..7c9aa260 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -3,7 +3,7 @@ name = "Radicale" # When the version is updated, a new section in the CHANGELOG.md file must be # added too. readme = "README.md" -version = "3.3.2" +version = "3.3.3.dev" authors = [{name = "Guillaume Ayoub", email = "guillaume.ayoub@kozea.fr"}, {name = "Unrud", email = "unrud@outlook.com"}, {name = "Peter Bieringer", email = "pb@bieringer.de"}] license = {text = "GNU GPL v3"} description = "CalDAV and CardDAV Server" diff --git a/radicale/storage/multifilesystem/__init__.py b/radicale/storage/multifilesystem/__init__.py index 4e5271f5..6aafae8e 100644 --- a/radicale/storage/multifilesystem/__init__.py +++ b/radicale/storage/multifilesystem/__init__.py @@ -47,6 +47,8 @@ from radicale.storage.multifilesystem.upload import CollectionPartUpload from radicale.storage.multifilesystem.verify import StoragePartVerify +# 999 second, 999 ms, 999 us, 999 ns +MTIME_NS_TEST: int = 999999999999 class Collection( CollectionPartDelete, CollectionPartMeta, CollectionPartSync, @@ -91,22 +93,76 @@ class Storage( def __init__(self, configuration: config.Configuration) -> None: super().__init__(configuration) - logger.info("storage location: %r", self._filesystem_folder) + logger.info("Storage location: %r", self._filesystem_folder) self._makedirs_synced(self._filesystem_folder) - logger.info("storage location subfolder: %r", self._get_collection_root_folder()) - logger.info("storage cache subfolder usage for 'item': %s", self._use_cache_subfolder_for_item) - logger.info("storage cache subfolder usage for 'history': %s", self._use_cache_subfolder_for_history) - logger.info("storage cache subfolder usage for 'sync-token': %s", self._use_cache_subfolder_for_synctoken) - logger.info("storage cache use mtime and size for 'item': %s", self._use_mtime_and_size_for_item_cache) - logger.debug("storage cache action logging: %s", self._debug_cache_actions) + logger.info("Storage location subfolder: %r", self._get_collection_root_folder()) + logger.info("Storage cache subfolder usage for 'item': %s", self._use_cache_subfolder_for_item) + logger.info("Storage cache subfolder usage for 'history': %s", self._use_cache_subfolder_for_history) + logger.info("Storage cache subfolder usage for 'sync-token': %s", self._use_cache_subfolder_for_synctoken) + logger.info("Storage cache use mtime and size for 'item': %s", self._use_mtime_and_size_for_item_cache) + if self._use_mtime_and_size_for_item_cache is True: + # calculate and display mtime resolution + path = os.path.join(self._get_collection_root_folder(), ".Radicale.mtime_test") + try: + with open(path, "w") as f: + f.write("mtime_test") + f.close + except Exception: + logger.error("Storage item mtime resolution test not possible") + raise + # set mtime_ns for tests + os.utime(path, times=None, ns=(MTIME_NS_TEST, MTIME_NS_TEST)) + logger.debug("Storage item mtime resoultion test set: %d" % MTIME_NS_TEST) + mtime_ns = os.stat(path).st_mtime_ns + mtime_ns = int(MTIME_NS_TEST / 100000000) * 100000000 + logger.debug("Storage item mtime resoultion test get: %d" % mtime_ns) + # start analysis + precision = 1 + mtime_ns_test = MTIME_NS_TEST + while mtime_ns > 0: + if mtime_ns == mtime_ns_test: + break + factor = 2 + if int(mtime_ns / factor) == int(mtime_ns_test / factor): + precision = precision * factor + break + factor = 5 + if int(mtime_ns / factor) == int(mtime_ns_test / factor): + precision = precision * factor + break + precision = precision * 10 + mtime_ns = int(mtime_ns / 10) + mtime_ns_test = int(mtime_ns_test / 10) + unit = "ns" + precision_log = precision + if precision >= 1000000000: + precision_log = precision / 1000000000 + unit = "s" + elif precision >= 1000000: + precision_log = precision / 1000000 + unit = "ms" + elif precision >= 1000: + precision_log = precision / 1000 + unit = "us" + os.remove(path) + if precision >= 100000000: + # >= 100 ms + logger.warning("Storage item mtime resolution test result: %d %s (VERY RISKY ON PRODUCTION SYSTEMS)" % (precision_log, unit)) + elif precision >= 10000000: + # >= 10 ms + logger.warning("Storage item mtime resolution test result: %d %s (RISKY ON PRODUCTION SYSTEMS)" % (precision_log, unit)) + else: + logger.info("Storage item mtime resolution test result: %d %s" % (precision_log, unit)) + raise + logger.debug("Storage cache action logging: %s", self._debug_cache_actions) if self._use_cache_subfolder_for_item is True or self._use_cache_subfolder_for_history is True or self._use_cache_subfolder_for_synctoken is True: - logger.info("storage cache subfolder: %r", self._get_collection_cache_folder()) + logger.info("Storage cache subfolder: %r", self._get_collection_cache_folder()) self._makedirs_synced(self._get_collection_cache_folder()) if sys.platform != "win32": if not self._folder_umask: # retrieve current umask by setting a dummy umask current_umask = os.umask(0o0022) - logger.info("storage folder umask (from system): '%04o'", current_umask) + logger.info("Storage folder umask (from system): '%04o'", current_umask) # reset to original os.umask(current_umask) else: diff --git a/setup.py.legacy b/setup.py.legacy index ba97b8e0..91bdc16a 100644 --- a/setup.py.legacy +++ b/setup.py.legacy @@ -20,7 +20,7 @@ from setuptools import find_packages, setup # When the version is updated, a new section in the CHANGELOG.md file must be # added too. -VERSION = "3.3.2" +VERSION = "3.3.3.dev" with open("README.md", encoding="utf-8") as f: long_description = f.read() From 836827ac8f4dce83a4de03a0cd7ee98501552472 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 08:59:23 +0100 Subject: [PATCH 2/6] remove test code --- radicale/storage/multifilesystem/__init__.py | 1 - 1 file changed, 1 deletion(-) diff --git a/radicale/storage/multifilesystem/__init__.py b/radicale/storage/multifilesystem/__init__.py index 6aafae8e..c4130dfb 100644 --- a/radicale/storage/multifilesystem/__init__.py +++ b/radicale/storage/multifilesystem/__init__.py @@ -153,7 +153,6 @@ def __init__(self, configuration: config.Configuration) -> None: logger.warning("Storage item mtime resolution test result: %d %s (RISKY ON PRODUCTION SYSTEMS)" % (precision_log, unit)) else: logger.info("Storage item mtime resolution test result: %d %s" % (precision_log, unit)) - raise logger.debug("Storage cache action logging: %s", self._debug_cache_actions) if self._use_cache_subfolder_for_item is True or self._use_cache_subfolder_for_history is True or self._use_cache_subfolder_for_synctoken is True: logger.info("Storage cache subfolder: %r", self._get_collection_cache_folder()) From c1c8ab2887984eab26aebc4927b12612f0f6b6a3 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 09:00:06 +0100 Subject: [PATCH 3/6] remove test code --- radicale/storage/multifilesystem/__init__.py | 1 - 1 file changed, 1 deletion(-) diff --git a/radicale/storage/multifilesystem/__init__.py b/radicale/storage/multifilesystem/__init__.py index c4130dfb..458004ba 100644 --- a/radicale/storage/multifilesystem/__init__.py +++ b/radicale/storage/multifilesystem/__init__.py @@ -114,7 +114,6 @@ def __init__(self, configuration: config.Configuration) -> None: os.utime(path, times=None, ns=(MTIME_NS_TEST, MTIME_NS_TEST)) logger.debug("Storage item mtime resoultion test set: %d" % MTIME_NS_TEST) mtime_ns = os.stat(path).st_mtime_ns - mtime_ns = int(MTIME_NS_TEST / 100000000) * 100000000 logger.debug("Storage item mtime resoultion test get: %d" % mtime_ns) # start analysis precision = 1 From 4b1183ae002956a78bd552b5af924803a3322d43 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 20:34:16 +0100 Subject: [PATCH 4/6] disable fsync during storage verification --- radicale/storage/multifilesystem/verify.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/radicale/storage/multifilesystem/verify.py b/radicale/storage/multifilesystem/verify.py index 776f1bfd..4c644c19 100644 --- a/radicale/storage/multifilesystem/verify.py +++ b/radicale/storage/multifilesystem/verify.py @@ -29,6 +29,8 @@ class StoragePartVerify(StoragePartDiscover, StorageBase): def verify(self) -> bool: item_errors = collection_errors = 0 + logger.info("Disable fsync during storage verification") + self._filesystem_fsync = False @types.contextmanager def exception_cm(sane_path: str, href: Optional[str] From 0f6dcb71923123f44f0177a9294eba3ed188dfc6 Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 20:34:38 +0100 Subject: [PATCH 5/6] disable fsync during storage verification --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 94b74d73..330fa4b3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,7 @@ ## 3.3.3.dev * Add: display mtime_ns precision of storage folder with condition warning if too less +* Improve: disable fsync during storage verification ## 3.3.2 * Fix: debug logging in rights/from_file From 6214111f4fa518120d241b50238d83ca0222138f Mon Sep 17 00:00:00 2001 From: Peter Bieringer Date: Mon, 16 Dec 2024 20:58:59 +0100 Subject: [PATCH 6/6] make tox happy --- radicale/storage/multifilesystem/__init__.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/radicale/storage/multifilesystem/__init__.py b/radicale/storage/multifilesystem/__init__.py index 458004ba..4c4f321a 100644 --- a/radicale/storage/multifilesystem/__init__.py +++ b/radicale/storage/multifilesystem/__init__.py @@ -50,6 +50,7 @@ # 999 second, 999 ms, 999 us, 999 ns MTIME_NS_TEST: int = 999999999999 + class Collection( CollectionPartDelete, CollectionPartMeta, CollectionPartSync, CollectionPartUpload, CollectionPartGet, CollectionPartCache, @@ -102,13 +103,13 @@ def __init__(self, configuration: config.Configuration) -> None: logger.info("Storage cache use mtime and size for 'item': %s", self._use_mtime_and_size_for_item_cache) if self._use_mtime_and_size_for_item_cache is True: # calculate and display mtime resolution - path = os.path.join(self._get_collection_root_folder(), ".Radicale.mtime_test") + path = os.path.join(self._filesystem_folder, ".Radicale.mtime_test") try: with open(path, "w") as f: f.write("mtime_test") f.close - except Exception: - logger.error("Storage item mtime resolution test not possible") + except Exception as e: + logger.error("Storage item mtime resolution test not possible, cannot write file: %r (%s)", path, e) raise # set mtime_ns for tests os.utime(path, times=None, ns=(MTIME_NS_TEST, MTIME_NS_TEST)) @@ -135,13 +136,13 @@ def __init__(self, configuration: config.Configuration) -> None: unit = "ns" precision_log = precision if precision >= 1000000000: - precision_log = precision / 1000000000 + precision_log = int(precision / 1000000000) unit = "s" elif precision >= 1000000: - precision_log = precision / 1000000 + precision_log = int(precision / 1000000) unit = "ms" elif precision >= 1000: - precision_log = precision / 1000 + precision_log = int(precision / 1000) unit = "us" os.remove(path) if precision >= 100000000: