Compare commits

...
5 Commits
Author SHA1 Message Date
jared 91f82d60e3 Merge pull request 'A stalled server no longer reads as "your clock is ahead"' (#251) from clock-skew-lag into lotus
CI / Build & Quality Checks (push) Successful in 3m4s
CI / Docker image build & smoke test (push) Skipped
CI / Secret scan (gitleaks) (push) Successful in 8s
CI / Trigger Desktop Build (push) Successful in 4s
CI / Playwright smoke (e2e) (push) Successful in 10m32s
Merge pull request #251: a stalled server no longer reads as a wrong clock
2026-09-28 22:40:13 -04:00
Lotus CI f0865115a4 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
2026-09-28 22:11:31 -04:00
jared 899e160aed Merge pull request 'Offline outbox: unsent messages survive reload and retry (#112)' (#250) from offline-outbox into lotus
CI / Build & Quality Checks (push) Successful in 2m58s
CI / Docker image build & smoke test (push) Skipped
CI / Secret scan (gitleaks) (push) Successful in 12s
CI / Trigger Desktop Build (push) Successful in 9s
CI / Playwright smoke (e2e) (push) Successful in 10m52s
Merge pull request #250: Offline outbox (#112)
2026-09-28 22:08:28 -04:00
Lotus CIandClaude Opus 5.5 3e5fdd0dab 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
"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
2026-09-28 22:08:13 -04:00
Lotus CIandClaude Opus 5.5 bb569d69a2 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
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
6 changed files with 156 additions and 49 deletions
+15 -6
View File
@@ -257,12 +257,21 @@ test.describe('local homeserver regression', () => {
await page.clock.install({ time: Date.now() + 14 * 60 * 1000 });
await loginUI(page, alice);
await openRoom(page, room);
for (let i = 0; i < 4; i += 1) {
// eslint-disable-next-line no-await-in-loop
await sendText(bob, room, `tick ${i}`);
// eslint-disable-next-line no-await-in-loop
await page.waitForTimeout(500);
}
const ticks = async (from: number, n: number) => {
for (let i = from; i < from + n; i += 1) {
// eslint-disable-next-line no-await-in-loop
await sendText(bob, room, `tick ${i}`);
// eslint-disable-next-line no-await-in-loop
await page.waitForTimeout(500);
}
};
await ticks(0, 4);
// "Ahead" could be a late delivery (a stalled server), so it is only
// reported once it has held for a minute of fresh samples.
await page.waitForTimeout(2000);
await expect(page.getByText(/clock is .*ahead of the server/)).toHaveCount(0);
await page.clock.fastForward('01:05');
await ticks(4, 2);
await expect(page.getByText(/clock is .*14 minutes ahead of the server/)).toBeVisible();
await page.getByRole('button', { name: 'Dismiss for 24 h' }).click();
await expect(page.getByText(/clock is .*ahead of the server/)).toHaveCount(0);
+2 -2
View File
@@ -72,9 +72,9 @@ export function CallStatus({ callEmbed }: CallStatusProps) {
size="T200"
truncate
style={{ color: color.Warning.Main }}
title="Fix your computer's clock — calls and encryption depend on it"
title="This device's clock is off. Calls and encryption depend on it: turn on automatic time in your system settings."
>
Clock {describeSkewVsServer(clockSkew.skewMs)} — calls will fail
Device clock {describeSkewVsServer(clockSkew.skewMs)}: calls may fail
</Text>
</>
)}
@@ -1072,6 +1072,10 @@ function ClockSkewFeature() {
data,
) => {
if (!data.liveEvent) return;
// Only events our homeserver stamped: a federated event's
// origin_server_ts is the other server's clock.
const senderServer = mEvent.getSender()?.split(':').slice(1).join(':');
if (senderServer !== mx.getDomain()) return;
monitor.sample(mEvent.getTs(), mEvent.getAge(), mEvent.localTimestamp);
};
mx.on(RoomEvent.Timeline, onTimeline);
+3 -3
View File
@@ -19,7 +19,7 @@ const readDismissedUntil = (): number => {
};
/**
* [Gitea #158] "Your computer's clock is 14 minutes ahead of the server."
* [Gitea #158] "This device's clock is 14 minutes ahead of the server."
* Same slot and style as the sync banners. Shown while the skew monitor is
* over its threshold; the direction matters, so it is said. Dismissable for
* 24 h; never auto-corrects anything.
@@ -53,8 +53,8 @@ export function ClockSkewBanner() {
>
<Box alignItems="Center" gap="300" wrap="Wrap" justifyContent="Center">
<Text size="L400" align="Center">
Your computer&apos;s clock is <b>{describeSkewVsServer(skewMs)}</b>. Encrypted messages
and voice calls will fail until it is fixed.
This device&apos;s clock is <b>{describeSkewVsServer(skewMs)}</b>. Voice calls and
encrypted messages can fail until it&apos;s corrected.
</Text>
<Button
size="300"
+76 -27
View File
@@ -8,44 +8,96 @@ import {
formatSkew,
} from './clockSkew';
// A live event received when the local clock is `skew` ms ahead of the server:
// origin_server_ts = T (server clock), age = a, localTimestamp = (T + a + skew) - a.
const feed = (m: ClockSkewMonitor, skew: number, age = 500, t = 1_700_000_000_000) =>
m.sample(t, age, t + skew);
const T = 1_700_000_000_000;
test('needs three samples, then reports the median with direction', () => {
/**
* 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).skewMs, null);
assert.equal(feed(m, 61_000).skewMs, null);
const s = feed(m, 59_000);
assert.equal(s.skewMs, 60_000);
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!), '60 seconds ahead');
assert.equal(formatSkew(s.skewMs!), '61 seconds behind');
});
test('one bad sample cannot trip the warning (median) and hysteresis clears only under 15 s', () => {
test('ahead: only once it has held for a minute', () => {
const m = new ClockSkewMonitor();
feed(m, 1000);
feed(m, 1500);
assert.equal(feed(m, 90_000).warning, false); // outlier
assert.equal(m.getState().skewMs, 1500);
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();
[40_000, 41_000, 39_000, 40_000, 40_000].forEach((s) => feed(w, s));
[0, 1, 2].forEach((at) => feed(w, -40_000, at));
assert.equal(w.getState().warning, true);
// drifting down to 20 s: still >= 15 s → stays on
[20_000, 20_000, 20_000, 20_000, 20_000].forEach((s) => feed(w, s));
// 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);
[10_000, 10_000, 10_000, 10_000, 10_000].forEach((s) => feed(w, s));
[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();
const t = 1_700_000_000_000;
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);
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);
});
@@ -53,10 +105,7 @@ test('subscribe fires on change only; reset clears', () => {
const m = new ClockSkewMonitor();
const seen: (number | null)[] = [];
m.subscribe((s) => seen.push(s.skewMs));
feed(m, -120_000);
feed(m, -120_000);
feed(m, -120_000);
feed(m, -120_000);
[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();
+56 -11
View File
@@ -22,8 +22,23 @@
export const SKEW_WARN_MS = 30_000;
export const SKEW_CLEAR_MS = 15_000;
export const SKEW_SAMPLES = 5;
export const SKEW_MIN_SAMPLES = 3;
/** Samples older than this are forgotten. */
export const SKEW_WINDOW_MS = 5 * 60 * 1000;
export const SKEW_MAX_SAMPLES = 30;
/**
* "Ahead" must hold across samples received at least this far apart.
*
* 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 read "your clock is 30 s
* ahead" — while the real problem was the server. A late delivery can only make
* the local clock look AHEAD (never behind), so the estimate is the LOWEST
* recent sample (the one delivered fastest), and "ahead" has to persist across
* a minute of fresh samples before it is reported. "Behind" can't come from a
* delay and is reported as soon as there are enough samples.
*/
export const SKEW_AHEAD_SPAN_MS = 60_000;
/**
* Sanity cap on `age`. Old events are still valid samples (the server computes
* `age` at response time, so `ts + age` is its clock regardless of the event's
@@ -38,14 +53,21 @@ export type ClockSkewState = {
warning: boolean;
};
const median = (xs: number[]): number => {
const s = [...xs].sort((a, b) => a - b);
const mid = Math.floor(s.length / 2);
return s.length % 2 ? s[mid] : (s[mid - 1] + s[mid]) / 2;
/** A wall-clock change larger than this (vs the monotonic clock) resets the samples. */
export const CLOCK_JUMP_MS = 5_000;
type Sample = { skew: number; at: number };
const currentClock = (): { wall: number; mono: number } => {
const wall = Date.now();
const mono = typeof performance !== 'undefined' ? performance.now() : wall;
return { wall, mono };
};
export class ClockSkewMonitor {
private samples: number[] = [];
private samples: Sample[] = [];
private clockOffset: number | undefined;
private state: ClockSkewState = { skewMs: null, warning: false };
@@ -64,25 +86,47 @@ export class ClockSkewMonitor {
/**
* Feed one live event. `originServerTs` + `age` come from the event;
* `localTimestamp` is the SDK's `Date.now() − age` at construction.
* `localTimestamp` is the SDK's `Date.now() − age` at construction; `clock`
* is when the sample was taken: wall clock and a monotonic clock
* (performance.now()), so samples are aged by real elapsed time and a change
* of the local clock (someone fixing it) starts the measurement afresh.
* Only feed events stamped by OUR homeserver: another server's
* `origin_server_ts` carries that server's clock.
* Returns the new state (unchanged object when nothing moved).
*/
public sample(
originServerTs: number,
age: number | undefined,
localTimestamp: number,
clock: { wall: number; mono: number } = currentClock(),
): ClockSkewState {
if (age === undefined || !Number.isFinite(age) || age < 0 || age > SKEW_MAX_AGE_MS) {
return this.state;
}
if (!Number.isFinite(originServerTs) || !Number.isFinite(localTimestamp)) return this.state;
this.samples.push(localTimestamp - originServerTs);
if (this.samples.length > SKEW_SAMPLES) this.samples.shift();
const now = clock.mono;
const offset = clock.wall - clock.mono;
if (this.clockOffset !== undefined && Math.abs(offset - this.clockOffset) > CLOCK_JUMP_MS) {
// The local clock was changed: earlier samples measured the old clock.
this.reset();
}
this.clockOffset = offset;
this.samples.push({ skew: localTimestamp - originServerTs, at: now });
this.samples = this.samples.filter((s) => now - s.at <= SKEW_WINDOW_MS);
if (this.samples.length > SKEW_MAX_SAMPLES) this.samples.shift();
if (this.samples.length < SKEW_MIN_SAMPLES) return this.state;
const skewMs = median(this.samples);
// Delivery delay only ever adds to a sample: the smallest is the truest.
const skewMs = Math.min(...this.samples.map((s) => s.skew));
const abs = Math.abs(skewMs);
const warning = this.state.warning ? abs >= SKEW_CLEAR_MS : abs > SKEW_WARN_MS;
let warning: boolean;
if (this.state.warning) warning = abs >= SKEW_CLEAR_MS;
else if (skewMs < -SKEW_WARN_MS) warning = true;
else if (skewMs > SKEW_WARN_MS) {
// Ahead: only if the fastest-delivered samples stayed high for a minute.
const span = now - Math.min(...this.samples.map((s) => s.at));
warning = span >= SKEW_AHEAD_SPAN_MS;
} else warning = false;
if (skewMs === this.state.skewMs && warning === this.state.warning) return this.state;
this.state = { skewMs, warning };
this.listeners.forEach((cb) => cb(this.state));
@@ -91,6 +135,7 @@ export class ClockSkewMonitor {
public reset(): void {
this.samples = [];
this.clockOffset = undefined;
if (this.state.skewMs !== null || this.state.warning) {
this.state = { skewMs: null, warning: false };
this.listeners.forEach((cb) => cb(this.state));