Measure elapsed time with a clock that cannot step (#568)

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>

Author: alistair3149

AGENTS.md

@@ -6,7 +6,7 @@ Project context for AI coding agents working on this repo. For human users, star
 
 - `src/tools/` — one file per non-extension MCP tool (descriptor + handler + registration).
 - `src/tools/extensions/<id>/` — extension packs: tools gated on a specific MediaWiki extension (SMW / Bucket / Cargo / …), grouped under a per-pack module.
-- `src/runtime/` — context, dispatcher, register, reconcile, logger, constants, request-scoped context, auth-shape classifier.
+- `src/runtime/` — context, dispatcher, register, reconcile, logger, monotonic clock, constants, request-scoped context, auth-shape classifier.
 - `src/wikis/` — wiki registry, selection, mwn provider, discovery, error sanitiser.
 - `src/transport/` — stdio and streamable HTTP entry points, SSRF/upload guards, low-level HTTP helpers.
 - `src/auth/` — OAuth for MediaWiki, in two roles (client to a wiki, and the hosted authorization-server proxy). See [src/auth/README.md](src/auth/README.md).

CHANGELOG.md

@@ -26,6 +26,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/)
 - `delete-page` no longer sends an empty deletion reason when the wiki sets `attributeEdits: false` and the call gave no comment. MediaWiki recorded that empty reason verbatim, leaving a blank deletion log entry; with no reason sent at all it can autogenerate its own `content was: …` reason instead.
 - `update-page` no longer advertises itself as idempotent: in `mode='append'` and `mode='prepend'` it never was, so a client replaying a call whose result never arrived adds the content a second time. A replace resends the same content rather than adding to it.
 - `upload-file-from-url` and `update-file-from-url` no longer leak a connection when they refuse a source URL whose declared size is over `MCP_UPLOAD_MAX_BYTES`. Each refused call held one connection open for as long as the server ran.
+- A host correcting its clock no longer changes what the server does with elapsed time: rate-limit allowances, the shutdown grace window, the readiness and extension-detection caches, and the window a hosted sign-in has to finish. Measured against the wall clock, a backwards NTP step could refuse a caller that had barely touched its rate-limit allowance with a `Retry-After` of up to an hour, and a forwards step could end a graceful shutdown early, aborting the tool calls it was waiting for.
 
 ## [0.16.0] - 2026-07-30
 

src/auth/authorizationServer/cimd.ts

@@ -1,5 +1,6 @@
 import type { ClientRecord } from './proxyStore.ts';
 import { isLoopbackHost } from './redirectPolicy.ts';
+import { monotonicNow } from '../../runtime/clock.ts';
 
 export class CimdValidationError extends Error {
 	public constructor(message: string) {
@@ -219,7 +220,7 @@ export class CimdResolver {
 	public constructor(
 		private isHostAllowed: (host: string) => boolean,
 		private fetcher: (url: string) => Promise<CimdFetchResult>,
-		private now: () => number = Date.now,
+		private now: () => number = monotonicNow,
 		private maxEntries: number = CIMD_CACHE_MAX_ENTRIES,
 	) {}
 

src/auth/authorizationServer/proxyStore.ts

@@ -1,4 +1,5 @@
 import { randomUUID } from 'node:crypto';
+import { monotonicNow } from '../../runtime/clock.ts';
 
 export interface ClientRecord {
 	clientId: string;
@@ -99,12 +100,14 @@ export class InMemoryProxyStore implements ProxyStore {
 	private refreshing = new Set<string>();
 
 	public constructor(
-		private now: () => number = Date.now,
+		private elapsedNow: () => number = monotonicNow,
 		private maxClients: number = DEFAULT_MAX_CLIENTS,
 	) {}
 
 	public putClient(c: Omit<ClientRecord, 'clientId' | 'createdAt'>): ClientRecord {
-		const rec: ClientRecord = { ...c, clientId: `mcp-${randomUUID()}`, createdAt: this.now() };
+		// Not elapsedNow(): register.ts publishes createdAt as client_id_issued_at,
+		// which a client reads as a Unix timestamp.
+		const rec: ClientRecord = { ...c, clientId: `mcp-${randomUUID()}`, createdAt: Date.now() };
 		// FIFO eviction: drop the oldest registration before exceeding the cap.
 		// Map preserves insertion order, so the first key is the oldest.
 		while (this.clients.size >= this.maxClients) {
@@ -127,15 +130,15 @@ export class InMemoryProxyStore implements ProxyStore {
 	}
 
 	public putTransaction(id: string, t: TransactionRecord, ttlMs = TXN_TTL_MS): void {
-		this.txns.set(id, { value: t, expiresAt: this.now() + ttlMs });
+		this.txns.set(id, { value: t, expiresAt: this.elapsedNow() + ttlMs });
 	}
 
 	public getTransaction(id: string): TransactionRecord | undefined {
 		const e = this.txns.get(id);
 		if (!e) {
 			return undefined;
 		}
-		if (e.expiresAt < this.now()) {
+		if (e.expiresAt < this.elapsedNow()) {
 			this.txns.delete(id);
 			return undefined;
 		}
@@ -147,13 +150,13 @@ export class InMemoryProxyStore implements ProxyStore {
 	}
 
 	public putCode(code: string, r: CodeRecord, ttlMs = CODE_TTL_MS): void {
-		this.codes.set(code, { value: r, expiresAt: this.now() + ttlMs });
+		this.codes.set(code, { value: r, expiresAt: this.elapsedNow() + ttlMs });
 	}
 
 	public consumeCode(code: string): CodeRecord | undefined {
 		const e = this.codes.get(code);
 		this.codes.delete(code); // one-time regardless of expiry
-		if (!e || e.expiresAt < this.now()) {
+		if (!e || e.expiresAt < this.elapsedNow()) {
 			return undefined;
 		}
 		return e.value;

src/auth/authorizationServer/proxyStorePersistence.ts

@@ -1,11 +1,11 @@
 import { mkdirSync, readFileSync, renameSync, writeFileSync } from 'node:fs';
 import * as path from 'node:path';
-import { performance } from 'node:perf_hooks';
 import { isErrnoException } from '../../errors/isErrnoException.ts';
 import { recordStoreFlush, recordStoreFlushFailure } from '../../runtime/metrics.ts';
 import { getProxyStorePath } from '../paths.ts';
 import type { ProxyConfig } from './proxyConfig.ts';
 import { deriveKey, decrypt, encrypt } from './proxyStoreCrypto.ts';
+import { monotonicNow } from '../../runtime/clock.ts';
 import {
 	InMemoryProxyStore,
 	type ClientRecord,
@@ -184,7 +184,7 @@ export class PersistentProxyStore implements ProxyStore {
 	}
 
 	private flushSync(): void {
-		const start = performance.now();
+		const start = monotonicNow();
 		try {
 			const json = JSON.stringify(this.inner.snapshotDurable());
 			const blob = encrypt(this.key, Buffer.from(json, 'utf8'));
@@ -193,7 +193,7 @@ export class PersistentProxyStore implements ProxyStore {
 			writeFileSync(tmp, blob, { mode: 0o600 });
 			renameSync(tmp, this.file);
 			this.dirty = false;
-			recordStoreFlush(performance.now() - start);
+			recordStoreFlush(monotonicNow() - start);
 		} catch (err: unknown) {
 			// Best-effort durability: a disk failure must not break the live request. The
 			// record stays valid in memory; persistence is re-attempted by the next

src/auth/browserAuth.ts

@@ -4,6 +4,7 @@ import { randomBytes } from 'node:crypto';
 import type { AddressInfo } from 'node:net';
 import open from 'open';
 import { logger } from '../runtime/logger.ts';
+import { monotonicNow } from '../runtime/clock.ts';
 import { fetchMetadata } from './metadata.ts';
 import type { WikiSlice } from './metadata.ts';
 import { randomVerifier, s256 } from './pkce.ts';
@@ -67,7 +68,7 @@ export function browserAuth(wikiKey: string, ctx: BrowserAuthCtx): Promise<strin
 }
 
 async function doBrowserAuth(wikiKey: string, ctx: BrowserAuthCtx): Promise<string> {
-	const started = Date.now();
+	const started = monotonicNow();
 	const timeoutMs = ctx.timeoutMs ?? DEFAULT_TIMEOUT_MS;
 
 	const metadata = await fetchMetadata(wikiKey, ctx.wiki);
@@ -144,7 +145,7 @@ async function doBrowserAuth(wikiKey: string, ctx: BrowserAuthCtx): Promise<stri
 			event: 'oauth_login_failed',
 			wiki: wikiKey,
 			reason,
-			duration_ms: Date.now() - started,
+			duration_ms: Math.round(monotonicNow() - started),
 		});
 		if (err instanceof OAuthFlowError) {
 			throw new BrowserAuthError(reason, err.message);
@@ -170,7 +171,7 @@ async function doBrowserAuth(wikiKey: string, ctx: BrowserAuthCtx): Promise<stri
 	logger.info('', {
 		event: 'oauth_login_completed',
 		wiki: wikiKey,
-		duration_ms: Date.now() - started,
+		duration_ms: Math.round(monotonicNow() - started),
 	});
 
 	return tok.access_token;

src/auth/metadata.ts

@@ -1,5 +1,6 @@
 // src/auth/metadata.ts
 import { logger } from '../runtime/logger.ts';
+import { monotonicNow } from '../runtime/clock.ts';
 import { mwOauth2AuthorizeEndpoint, mwOauth2TokenEndpoint } from './mwOauth2Endpoints.ts';
 
 // The authorization-server metadata of an upstream wiki, as discovered from its
@@ -56,7 +57,7 @@ export function fetchMetadata(wikiKey: string, wiki: WikiSlice): Promise<Upstrea
 }
 
 async function doFetch(wikiKey: string, wiki: WikiSlice): Promise<UpstreamAsMetadata> {
-	const started = Date.now();
+	const started = monotonicNow();
 	const origin = `${wiki.server}/.well-known/oauth-authorization-server`;
 	const pathed = `${wiki.server}/.well-known/oauth-authorization-server${wiki.scriptpath}/rest.php/oauth2`;
 
@@ -89,7 +90,7 @@ async function doFetch(wikiKey: string, wiki: WikiSlice): Promise<UpstreamAsMeta
 		wiki: wikiKey,
 		outcome: 'success',
 		source: 'synthesized',
-		duration_ms: Date.now() - started,
+		duration_ms: Math.round(monotonicNow() - started),
 	});
 	return synthesized;
 }
@@ -163,7 +164,7 @@ function finalize(
 		wiki: wikiKey,
 		outcome: 'success',
 		source: md.source,
-		duration_ms: Date.now() - started,
+		duration_ms: Math.round(monotonicNow() - started),
 	});
 	return { ...md, issuer };
 }

src/runtime/clock.ts

@@ -0,0 +1,12 @@
+// Elapsed time — a cache TTL, a grace period, a logged duration — is measured
+// with this rather than Date.now, which steps in both directions when a host
+// corrects its clock. It counts milliseconds from process start and only ever
+// moves forwards.
+//
+// Date.now stays correct for a point in time that means something outside this
+// run of the process: a JWT claim, a timestamp that is published, or a token
+// expiry that has to still mean something after a restart.
+export function monotonicNow(): number {
+	// performance.now reads `this`, so it cannot be passed as a bare callback.
+	return performance.now();
+}

src/runtime/dispatcher.ts

@@ -15,6 +15,7 @@ import {
 import { acquireToken } from '../auth/acquireToken.ts';
 import { structuredResult } from '../results/response.ts';
 import { checkWikiCapability } from './wikiCapability.ts';
+import { monotonicNow } from './clock.ts';
 
 // Tools that operate on server-local state (the wiki registry, the OAuth token
 // store) rather than a wiki's API. They must not be blocked by an OAuth gate
@@ -100,7 +101,7 @@ async function runDispatchInner<TSchema extends ZodRawShape, TCtx extends ToolCo
 	args: z.infer<z.ZodObject<TSchema>>,
 	resolvedKey?: string,
 ): Promise<CallToolResult> {
-	const started = performance.now();
+	const started = monotonicNow();
 	let outcome: ToolOutcome = 'success';
 	let errorText: string | undefined;
 	let upstreamStatus: number | undefined;

src/runtime/instrument.ts

@@ -2,6 +2,7 @@ import { createHash } from 'node:crypto';
 import type { CallToolResult } from '@modelcontextprotocol/server';
 import { emitTelemetryEvent } from './logger.ts';
 import { recordToolCall } from './metrics.ts';
+import { monotonicNow } from './clock.ts';
 import type { ErrorCategory } from '../errors/classifyError.ts';
 
 // `cancelled` sits alongside ErrorCategory rather than inside it: the caller
@@ -126,7 +127,7 @@ export function emitToolCall<TArgs>(opts: EmitToolCallOptions<TArgs>): void {
 	const level = levelFor(opts.outcome);
 	const targetValue = safeTarget(opts.target, opts.args);
 	const truncated = opts.outcome === 'success' ? detectTruncation(opts.result) : false;
-	const durationMs = Math.round(performance.now() - opts.started);
+	const durationMs = Math.round(monotonicNow() - opts.started);
 	// Snake-case keys are required by the structured log schema.
 	const data: Record<string, unknown> = {
 		event: 'tool_call',