A stalled server no longer reads as "your clock is ahead" #251

Merged
jared merged 3 commits from clock-skew-lag into lotus 2026-09-28 22:40:14 -04:00
Owner

Tonight (2026-09-29 ~01:18 UTC) everyone was dropped from the call and saw "Your computer's clock is 30 seconds ahead of the server". The clocks were fine: Prometheus shows every host within 0.25 s all evening. What actually happened is that compute-storage-01 ran out of memory (a Tdarr ffmpeg in LXC 170, OOM-killed at 01:19:13). Synapse, LiveKit and Postgres stalled for about 2 minutes, and the first /sync after the stall arrived about 30 s late.

Why that looked like a clock problem

Each sample is (local clock − server clock) + delivery delay, and the estimate was the median of the last 5 samples. One late /sync carrying a few events was enough to trip it.

Fix (utils/clockSkew.ts)

  • Lowest sample: the estimate is the lowest sample from the last 5 min. Delay only ever adds, so the fastest-delivered event is the most accurate.
  • "Behind" (which a delay can't cause) is still reported after 3 samples, as before.
  • "Ahead" must hold across samples received at least a minute apart, so a late burst never trips it.
  • Clock changes: samples are aged on the monotonic clock. A change of the local clock (someone fixing it) resets the measurement, so the warning clears immediately.
  • Own server only: only events stamped by our homeserver are sampled; a federated event's origin_server_ts is the other server's clock.
  • Wording:
    • Banner: "This device's clock is 30 seconds ahead of the server. Voice calls and encrypted messages can fail until it's corrected."
    • Call bar: "Device clock … : calls may fail". It used to say "will fail".

Tests

  • New unit tests: the incident itself (a late burst after normal traffic, and a fresh client whose first samples are all late), mixed slow and fast deliveries, "ahead" only after a minute, "behind" at once, hysteresis, and the clock being fixed.
  • Other checks: the full unit suite has no failures; tsc, eslint and the build are clean.

🤖 Generated with Claude Code

https://claude.ai/code/session_01PPmy3tPq869XDW4njjVaKA

Tonight (2026-09-29 ~01:18 UTC) everyone was dropped from the call and saw *"Your computer's clock is 30 seconds ahead of the server"*. The clocks were fine: Prometheus shows every host within 0.25 s all evening. What actually happened is that **compute-storage-01 ran out of memory** (a Tdarr ffmpeg in LXC 170, OOM-killed at 01:19:13). Synapse, LiveKit and Postgres stalled for about 2 minutes, and the first /sync after the stall arrived about 30 s late. ## Why that looked like a clock problem Each sample is *(local clock − server clock) + delivery delay*, and the estimate was the median of the last 5 samples. One late /sync carrying a few events was enough to trip it. ## Fix (`utils/clockSkew.ts`) - **Lowest sample:** the estimate is the **lowest** sample from the last 5 min. Delay only ever adds, so the fastest-delivered event is the most accurate. - **"Behind"** (which a delay can't cause) is still reported after 3 samples, as before. - **"Ahead"** must hold across samples received **at least a minute apart**, so a late burst never trips it. - **Clock changes:** samples are aged on the monotonic clock. A change of the local clock (someone fixing it) resets the measurement, so the warning clears immediately. - **Own server only:** only events stamped by **our** homeserver are sampled; a federated event's `origin_server_ts` is the other server's clock. - **Wording:** - Banner: *"This device's clock is 30 seconds ahead of the server. Voice calls and encrypted messages can fail until it's corrected."* - Call bar: *"Device clock … : calls may fail"*. It used to say "will fail". ## Tests - **New unit tests:** the incident itself (a late burst after normal traffic, and a fresh client whose first samples are all late), mixed slow and fast deliveries, "ahead" only after a minute, "behind" at once, hysteresis, and the clock being fixed. - **Other checks:** the full unit suite has no failures; tsc, eslint and the build are clean. 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_01PPmy3tPq869XDW4njjVaKA
jared added 1 commit 2026-09-28 21:40:27 -04:00
fix: a stalled server no longer reads as "your clock is ahead"
CI / Build & Quality Checks (pull_request) Successful in 3m1s
CI / Trigger Desktop Build (pull_request) Skipped
CI / Docker image build & smoke test (pull_request) Skipped
CI / Secret scan (gitleaks) (pull_request) Successful in 7s
CI / Playwright smoke (e2e) (pull_request) Failing after 11m28s
bb569d69a2
Incident 2026-09-29: the homeserver's host ran out of memory and stalled for
~2 minutes. The /sync that finally went out carried events whose `age` was
computed ~30 s before it arrived, so every client showed "Your computer's
clock is 30 seconds ahead of the server" while the real problem was the
server (all host clocks were within 0.25 s the whole evening).

The skew estimate was the median of the last 5 samples, and a sample is
local skew + delivery delay, so one late /sync with a handful of events
tripped it.

- Estimate = the LOWEST sample of the last 5 minutes: delay only ever adds,
  so the fastest-delivered event is the truest.
- "Behind" (which a delay can't cause) is reported as soon as there are 3
  samples, like before. "Ahead" must hold across samples received at least
  a minute apart, so a single late burst never trips it.
- Samples are aged on the monotonic clock, and a change of the local clock
  (someone fixing it) resets the measurement, so the warning clears at once.
- Only events stamped by our own homeserver are sampled: a federated event's
  origin_server_ts is the other server's clock.
- Wording: "This device's clock is … Voice calls and encrypted messages can
  fail until it's corrected." / call bar "Device clock … : calls may fail"
  (was "will fail").

Unit tests: the incident (late burst after normal traffic, and a fresh
client whose first samples are all late), mixed slow/fast deliveries,
ahead only after a minute, behind at once, hysteresis, clock fixed.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PPmy3tPq869XDW4njjVaKA
jared added 1 commit 2026-09-28 22:08:23 -04:00
test(e2e): clock-ahead warning needs a minute of samples (#158)
CI / Build & Quality Checks (pull_request) Successful in 2m57s
CI / Trigger Desktop Build (pull_request) Skipped
CI / Docker image build & smoke test (pull_request) Skipped
CI / Secret scan (gitleaks) (pull_request) Successful in 10s
CI / Playwright smoke (e2e) (pull_request) Canceled after 0s
3e5fdd0dab
"Ahead" is now reported only once it has held for a minute of fresh
samples (a stalled server delivers late and reads as ahead). The test sends
its ticks, checks nothing is shown yet, fast-forwards the page clock past a
minute and sends two more.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PPmy3tPq869XDW4njjVaKA
jared added 1 commit 2026-09-28 22:11:35 -04:00
Merge remote-tracking branch 'origin/lotus' into clock-skew-lag
CI / Build & Quality Checks (pull_request) Successful in 3m7s
CI / Trigger Desktop Build (pull_request) Skipped
CI / Docker image build & smoke test (pull_request) Skipped
CI / Secret scan (gitleaks) (pull_request) Successful in 7s
CI / Playwright smoke (e2e) (pull_request) Successful in 10m59s
f0865115a4
jared merged commit 91f82d60e3 into lotus 2026-09-28 22:40:14 -04:00
Sign in to join this conversation.
No Reviewers
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: LotusGuild/cinny#251