Files
cinny/src/app/utils/clockSkew.test.ts
T
Lotus CIandClaude Opus 5.5 bb569d69a2
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
fix: a stalled server no longer reads as "your clock is ahead"
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
2026-09-28 21:40:02 -04:00

133 lines
5.0 KiB
TypeScript
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
import { test } from 'node:test';
import assert from 'node:assert/strict';
import {
ClockSkewMonitor,
clockFixHint,
describeSkewVsServer,
detectClockFixPlatform,
formatSkew,
} from './clockSkew';
const T = 1_700_000_000_000;
/**
* A live event received `atSec` seconds into the test, when the local clock is
* `skew` ms off the server and the response took `delay` ms to arrive:
* localTimestamp − origin_server_ts = skew + delay.
*/
const feed = (m: ClockSkewMonitor, skew: number, atSec = 0, delay = 0, wallJump = 0) =>
m.sample(T, 500, T + skew + delay, { wall: T + atSec * 1000 + wallJump, mono: atSec * 1000 });
test('behind: reported as soon as there are three samples', () => {
const m = new ClockSkewMonitor();
assert.equal(feed(m, -60_000, 0).skewMs, null);
assert.equal(feed(m, -61_000, 1).skewMs, null);
const s = feed(m, -59_000, 2);
assert.equal(s.skewMs, -61_000);
assert.equal(s.warning, true);
assert.equal(formatSkew(s.skewMs!), '61 seconds behind');
});
test('ahead: only once it has held for a minute', () => {
const m = new ClockSkewMonitor();
feed(m, 60_000, 0);
feed(m, 60_000, 10);
assert.equal(feed(m, 60_000, 20).warning, false);
assert.equal(m.getState().skewMs, 60_000);
assert.equal(feed(m, 60_000, 59).warning, false);
assert.equal(feed(m, 60_000, 61).warning, true);
});
test('server stall (2026-09-29): a burst of late events does not read as a wrong clock', () => {
const m = new ClockSkewMonitor();
// Normal traffic, then the homeserver stalls and one /sync arrives 30 s late
// with a pile of events, then normal traffic again.
feed(m, 200, 0);
feed(m, 150, 5);
feed(m, 300, 10);
[1, 2, 3, 4, 5, 6].forEach(() => feed(m, 0, 130, 31_000));
assert.equal(m.getState().warning, false);
assert.ok(m.getState().skewMs! < 1000);
// Fresh client whose first samples are all from the late burst.
const fresh = new ClockSkewMonitor();
[1, 2, 3, 4, 5, 6].forEach(() => feed(fresh, 0, 0, 31_000));
assert.equal(fresh.getState().warning, false);
// …and the next timely event brings the estimate back down.
feed(fresh, 0, 70, 100);
assert.equal(fresh.getState().warning, false);
assert.equal(fresh.getState().skewMs, 100);
});
test('slow deliveries mixed with fast ones: the fastest one wins', () => {
const m = new ClockSkewMonitor();
[0, 20, 40, 60, 80].forEach((at, i) => feed(m, 45_000, at, i === 2 ? 0 : 20_000));
assert.equal(m.getState().skewMs, 45_000);
assert.equal(m.getState().warning, true);
});
test('hysteresis: once on, clears only under 15 s', () => {
const w = new ClockSkewMonitor();
[0, 1, 2].forEach((at) => feed(w, -40_000, at));
assert.equal(w.getState().warning, true);
// Samples expire after 5 minutes; drifting to -20 s keeps it on (>= 15 s).
[400, 401, 402].forEach((at) => feed(w, -20_000, at));
assert.equal(w.getState().skewMs, -20_000);
assert.equal(w.getState().warning, true);
[800, 801, 802].forEach((at) => feed(w, -10_000, at));
assert.equal(w.getState().warning, false);
});
test('fixing the local clock starts the measurement afresh', () => {
const m = new ClockSkewMonitor();
[0, 1, 2].forEach((at) => feed(m, -14 * 60_000, at));
assert.equal(m.getState().warning, true);
// The user sets the clock forward 14 minutes: wall jumps vs the monotonic clock.
const jump = 14 * 60_000;
feed(m, 0, 10, 0, jump);
assert.equal(m.getState().warning, false);
assert.equal(m.getState().skewMs, null);
feed(m, 0, 11, 0, jump);
feed(m, 0, 12, 0, jump);
assert.equal(m.getState().skewMs, 0);
assert.equal(m.getState().warning, false);
});
test('stale or missing age is ignored (cache replay must not read as skew)', () => {
const m = new ClockSkewMonitor();
m.sample(T, undefined, T + 3_600_000);
m.sample(T, 40 * 24 * 60 * 60 * 1000, T + 3_600_000);
m.sample(T, -5, T);
assert.equal(m.getState().skewMs, null);
});
test('subscribe fires on change only; reset clears', () => {
const m = new ClockSkewMonitor();
const seen: (number | null)[] = [];
m.subscribe((s) => seen.push(s.skewMs));
[0, 1, 2, 3].forEach((at) => feed(m, -120_000, at));
assert.deepEqual(seen, [-120_000]);
assert.equal(formatSkew(-120_000), '2 minutes behind');
m.reset();
assert.deepEqual(seen, [-120_000, null]);
});
test('formatSkew picks a sensible unit', () => {
assert.equal(formatSkew(45_000), '45 seconds ahead');
assert.equal(formatSkew(-14 * 60_000), '14 minutes behind');
assert.equal(formatSkew(3 * 3_600_000), '3 hours ahead');
assert.equal(formatSkew(2 * 86_400_000), '2 days ahead');
assert.equal(describeSkewVsServer(-3 * 3_600_000), '3 hours behind the server');
assert.equal(describeSkewVsServer(14 * 60_000), '14 minutes ahead of the server');
});
test('platform hint', () => {
assert.equal(detectClockFixPlatform('Mozilla/5.0 (Windows NT 10.0; Win64; x64)'), 'windows');
assert.equal(
detectClockFixPlatform('Mozilla/5.0 (iPhone; CPU iPhone OS 17_0 like Mac OS X)'),
'ios',
);
assert.equal(detectClockFixPlatform('Mozilla/5.0 (Macintosh; Intel Mac OS X 14_0)'), 'mac');
assert.match(clockFixHint('windows'), /Sync now/);
});