From de0e4984404cfce9ad06b1fa94296c1368e5736a Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Fri, 14 Aug 2026 09:47:36 +0200 Subject: [PATCH] locking: warn about clock skew only when there actually is skew, see #9870 The stale-veto path warned unconditionally, but a veto is not by itself evidence of skew: after a suspend, our store "now" estimate lags (monotonic clock stood still), so a genuinely stale foreign lock of a perfectly synced client gets vetoed and produced a bogus "clock skew of ~0s" warning. The per-listing skew check in _get_locks already covers the vetoed lock with a proper magnitude gate, so the veto-path warning (and with it the optional-skew calling convention of _warn_clock_skew) can just go away. Co-Authored-By: Claude Fable 5 --- src/borg/storelocking.py | 15 +++++++-------- src/borg/testsuite/storelocking_test.py | 16 ++++++++++++++++ 2 files changed, 23 insertions(+), 8 deletions(-) diff --git a/src/borg/storelocking.py b/src/borg/storelocking.py index 2d7a33ff1..1f09cad28 100644 --- a/src/borg/storelocking.py +++ b/src/borg/storelocking.py @@ -166,14 +166,12 @@ class Lock: offset_other = lock["dt"].timestamp() - lock["mtime"] return offset_other - offset_self - def _warn_clock_skew(self, lock, skew=None): + def _warn_clock_skew(self, lock, skew): if self.skew_warned: return self.skew_warned = True - skew = skew if skew is not None else self._mutual_skew(lock) - skew_info = f" of ~{abs(skew):.0f}s" if skew is not None else "" logger.warning( - f"Clock skew{skew_info} detected between this machine and the borg client on " + f"Clock skew of ~{abs(skew):.0f}s detected between this machine and the borg client on " f"{lock['hostid']!r} (also using this repository). " f"The clocks of machines sharing a repository should be synchronized (e.g. via NTP)." ) @@ -221,10 +219,11 @@ class Lock: logger.debug(f"LOCK-STALE: lock looks stale, deferring until store time is known. lock: {lock}.") return False if store_now <= lock["mtime"] + self.stale_td.total_seconds(): - # the store saw this lock object being written recently: it is NOT stale, - # its writer's clock is just skewed against ours. never kill it! - self._warn_clock_skew(lock) - logger.debug(f"LOCK-STALE: lock only looks stale due to clock skew. lock: {lock}.") + # the store saw this lock object being written recently: it is NOT stale. + # either its writer's clock is skewed against ours (the skew check in + # _get_locks warns about that) or our store "now" estimate lags behind + # (e.g. time.monotonic() stood still while we were suspended). never kill it! + logger.debug(f"LOCK-STALE: lock looks stale locally, but not to the store. lock: {lock}.") return False # either both clock domains agree that the lock is stale, or the backend can not # provide store-side mtimes (mtime == 0) and the content timestamp has to suffice. diff --git a/src/borg/testsuite/storelocking_test.py b/src/borg/testsuite/storelocking_test.py index 4b1cddab9..b46d7f703 100644 --- a/src/borg/testsuite/storelocking_test.py +++ b/src/borg/testsuite/storelocking_test.py @@ -264,6 +264,22 @@ class TestLock: assert not lock.skew_warned lock.release() + def test_no_skew_warning_when_only_our_store_time_lags(self, lockstore): + # while we are suspended, time.monotonic() stands still, so our store "now" estimate + # lags afterwards. a foreign lock that went genuinely stale meanwhile then gets vetoed + # (the safe direction), but that veto is no evidence of clock skew and must not + # produce a bogus "clock skew of ~0s" warning, see #9870. + lock = Lock(lockstore, exclusive=False, id=ID2) + lock.acquire() + assert lock.my_lock_mtime is not None # store time reference was harvested + lock.my_lock_monotonic += 45 * 60 # simulate a 45 minute suspend after the anchor + dt = datetime.datetime.now(datetime.UTC) - datetime.timedelta(minutes=40) + foreign_key = write_raw_lock(lockstore, ID1, exclusive=False, dt=dt, mtime=dt.timestamp()) + locks = lock._get_locks() + assert foreign_key in locks # genuinely stale, but vetoed: store "now" lags behind + assert not lock.skew_warned # the writer's clock is not skewed - no warning + lock.release() + def test_skew_warning_during_exclusive_acquire(self, lockstore): # an exclusive acquirer must warn about a skewed peer it sees while (unsuccessfully) # waiting for the peer's healthy shared lock to go away: the listing that would satisfy