From 476dbef7dc9506efcadf8745f8a12807d1b4d662 Mon Sep 17 00:00:00 2001 From: Maurice Date: Thu, 29 Oct 2026 09:13:26 +0100 Subject: [PATCH] fix(server): renew service keys on the next request and stop sending expired ones An expired key is no longer sent; the request goes through the shared pool while a due key, or an expired one within its grace, is renewed in the background. Refusals in one burst count once, a refused renewal counts like a refused search, and a Places request whose key is refused is sent once more without it. --- server/src/nest/maps/trek-places.client.ts | 21 ++- .../nest/service-identity/refusal-streak.ts | 25 ++++ .../service-identity/service-key.service.ts | 125 ++++++++++++------ .../service-identity/refusal-streak.test.ts | 36 +++++ .../service-key.service.test.ts | 73 +++++++++- .../unit/nest/trek-places.client.test.ts | 34 +++++ 6 files changed, 263 insertions(+), 51 deletions(-) create mode 100644 server/src/nest/service-identity/refusal-streak.ts create mode 100644 server/tests/unit/nest/service-identity/refusal-streak.test.ts diff --git a/server/src/nest/maps/trek-places.client.ts b/server/src/nest/maps/trek-places.client.ts index 90f10b7e2..eee8314dc 100644 --- a/server/src/nest/maps/trek-places.client.ts +++ b/server/src/nest/maps/trek-places.client.ts @@ -255,15 +255,24 @@ function noteFailure(err: unknown, breaker: Breaker): void { } } -/** A request carrying who is asking: the instance token, and the installation key where it may go. */ +/** + * A request carrying who is asking: the instance token, and the installation + * key where it may go. A refused key costs no answer: the request goes once + * more without it, through the shared pool, while the identity counts the refusal. + */ async function identifiedFetch(url: URL, headers: Record, signal: AbortSignal): Promise { const identity = serviceIdentitySlot.get(); - const res = await fetch(url, { - signal, - headers: { ...headers, 'X-TREK-Instance': instanceToken(), ...identity.headersFor(url) }, - }); + const own = identity.headersFor(url); + const base = { ...headers, 'X-TREK-Instance': instanceToken() }; + const res = await fetch(url, { signal, headers: { ...base, ...own } }); identity.observe(url, res); - return res; + if (res.status !== 401 || !own.Authorization) return res; + await res.body?.cancel(); + return fetch(url, { signal, headers: { ...base, ...withoutKey(own) } }); +} + +function withoutKey(headers: Record): Record { + return Object.fromEntries(Object.entries(headers).filter(([name]) => name !== 'Authorization')); } function statusError(status: number): Error & { status: number } { diff --git a/server/src/nest/service-identity/refusal-streak.ts b/server/src/nest/service-identity/refusal-streak.ts new file mode 100644 index 000000000..388713613 --- /dev/null +++ b/server/src/nest/service-identity/refusal-streak.ts @@ -0,0 +1,25 @@ +/** Refusals in a row before a key counts as gone, so one broken deploy upstream drops nothing. */ +const STREAK_LIMIT = 3; +/** One page fires several searches at once; refusals closer together than this are one moment. */ +const SPACING_MS = 10 * 60_000; + +/** Counts the refusals of a key at moments apart from each other, until an acceptance clears them. */ +export class RefusalStreak { + private hits = 0; + private lastHitAt: number | null = null; + + /** True when this refusal completes the streak, which then starts over. */ + hit(now = Date.now()): boolean { + if (this.lastHitAt !== null && now - this.lastHitAt < SPACING_MS) return false; + this.lastHitAt = now; + this.hits += 1; + if (this.hits < STREAK_LIMIT) return false; + this.clear(); + return true; + } + + clear(): void { + this.hits = 0; + this.lastHitAt = null; + } +} diff --git a/server/src/nest/service-identity/service-key.service.ts b/server/src/nest/service-identity/service-key.service.ts index 360d7a003..83de1f132 100644 --- a/server/src/nest/service-identity/service-key.service.ts +++ b/server/src/nest/service-identity/service-key.service.ts @@ -5,6 +5,7 @@ import { logInfo, logWarn } from '../audit/audit-log.logger'; import { conflict } from '../common/domain-error'; import { withRequestContext } from '../database/request-context'; import { IssuerClient, IssuerError } from './issuer.client'; +import { RefusalStreak } from './refusal-streak'; import { ServiceClock } from './service-clock'; import { SERVICE_ISSUER_ORIGIN } from './service-identity.constants'; import { isAllowlisted, keyFingerprint, sameServiceUrl } from './service-identity.helpers'; @@ -23,8 +24,6 @@ const DAY_SECONDS = 86_400; const RENEW_AGE_SECONDS = 60 * DAY_SECONDS; /** An expired key can still be renewed for this long; after that it registers anew. */ const RENEW_GRACE_SECONDS = 30 * DAY_SECONDS; -/** Refusals in a row before a key counts as gone, so one broken deploy upstream drops nothing. */ -const INVALID_STREAK_LIMIT = 3; /** Spreads the new registrations of every installation a broken key hit, instead of all at once. */ const REREGISTER_JITTER_MS = 6 * 3_600_000; const FIRST_BACKOFF_MS = 5 * 60_000; @@ -34,14 +33,15 @@ export interface KeySnapshot { state: ServiceIdentityState; key: ServiceKey | null; source: 'env' | 'registered' | null; - /** What a request may carry right now; null while revoked or without a key. */ + /** What a request may carry right now; null while revoked, expired or without a key. */ bearer: string | null; } /** * The installation key: loaded lazily, registered in the background on the - * first call to a liketrek service, renewed from day 60, given up after - * repeated refusals and frozen when the services revoke it. + * first call to a liketrek service, renewed from day 60 on the next call or + * the daily check, given up after repeated refusals and frozen when the + * services revoke it. * * Nothing here ever makes a request wait. Until a key is there, requests go * out as they always did, and the shared legacy pool answers them. @@ -57,7 +57,7 @@ export class ServiceKeyService { private registering = false; private nextAttemptAt = 0; private failures = 0; - private invalidStreak = 0; + private readonly refusals = new RefusalStreak(); constructor( @Inject(servicesConfig.KEY) private readonly config: ConfigType, @@ -79,12 +79,15 @@ export class ServiceKeyService { } } - /** The bearer for a request to an allowlisted host; starts a registration in the background when there is none. */ + /** + * The bearer for a request to an allowlisted host. Starts a registration or a + * due renewal in the background; until it lands, the request goes without a key. + */ bearer(): string | null { if (!this.inUse()) return null; this.settleInBackground(); const token = this.config.key ?? this.key?.token ?? null; - return token && !this.isRevoked(token) ? token : null; + return token && !this.isRevoked(token) && !this.isExpired(token) ? token : null; } /** What the admin card shows. Reads only: a GET must not register. */ @@ -96,57 +99,43 @@ export class ServiceKeyService { const source = this.config.key ? 'env' : 'registered'; const key = parseServiceKey(token); if (this.isRevoked(token)) return { state: 'revoked', key, source, bearer: null }; + if (this.isExpired(token)) return { state: source === 'env' ? 'legacy' : 'registering', key, source, bearer: null }; return { state: 'connected', key, source, bearer: token }; } /** A liketrek service accepted the key. */ noteAccepted(): void { - this.invalidStreak = 0; + this.refusals.clear(); } - /** A liketrek service answered 401 to the key; the third in a row gives it up. */ + /** A liketrek service answered 401 to the key; the third time, at moments apart, gives it up. */ noteInvalid(): void { if (!this.config.key && !this.key) return; - this.invalidStreak += 1; - if (this.invalidStreak < INVALID_STREAK_LIMIT) return; - this.invalidStreak = 0; + if (!this.refusals.hit()) return; if (this.config.key) { logWarn( 'TREK services: the key in TREK_SERVICES_KEY is refused. Place search continues through the shared pool.', ); return; } - this.inBackground(() => this.dropKey()); + void this.inBackground(() => this.dropKey()); } /** A liketrek service answered that the key is revoked. */ noteRevoked(): void { const token = this.config.key ?? this.key?.token; if (!token || this.isRevoked(token)) return; - this.inBackground(() => this.markRevoked(token)); + void this.inBackground(() => this.markRevoked(token)); } /** The daily check: renews the key once it is due. A key past its grace period is already gone on load. */ async renewIfDue(): Promise { - if (!this.inUse() || this.config.key) return; - await this.load(); - const key = this.key; - if (!key || this.isRevoked(key.token)) return; - if (this.clock.nowSeconds() < (this.state.renewAfter ?? key.payload.iat + RENEW_AGE_SECONDS)) return; - const renewal = await this.issuer.renew(key.token).then( - (grant) => ({ grant, error: null }), - (error: unknown) => ({ grant: null, error }), - ); - if (!renewal.grant) { - await this.refused(renewal.error, key.token); - return; - } - this.clock.learn(renewal.grant.serverMs); - const renewed = this.readGrant(renewal.grant.body); - this.state = { ...this.state, renewAfter: renewal.grant.body.renew_after }; - await this.store.replace(renewed, this.state); - this.key = renewed; - logInfo('TREK services: renewed the key of this installation.'); + if (!this.inUse()) return; + await this.inBackground(async () => { + await this.load(); + const key = this.dueForRenewal(); + if (key) await this.renew(key); + }); } /** The admin's way out of a revoked or cloned identity: forget the key and ask for a new one. */ @@ -157,7 +146,7 @@ export class ServiceKeyService { this.adopt({ key: null, unreadable: false, state: EMPTY_KEY_STATE }); this.nextAttemptAt = 0; this.failures = 0; - this.invalidStreak = 0; + this.refusals.clear(); logInfo('TREK services: an admin asked for a new identity for this installation.'); this.settleInBackground(); } @@ -189,28 +178,56 @@ export class ServiceKeyService { ); } + /** A request starts a due renewal, but after a failed one only once the backoff has passed. */ + private keyToRenewNow(): ServiceKey | null { + return Date.now() >= this.nextAttemptAt ? this.dueForRenewal() : null; + } + + private dueForRenewal(): ServiceKey | null { + const key = this.key; + if (this.config.key || !key || this.isRevoked(key.token)) return null; + const dueAt = this.state.renewAfter ?? key.payload.iat + RENEW_AGE_SECONDS; + return this.clock.nowSeconds() >= dueAt ? key : null; + } + private isRevoked(token: string): boolean { return this.state.revoked !== null && this.state.revoked === keyFingerprint(token); } + /** Read on the issuer's clock: the gate refuses an expired key instead of counting it in the shared pool. */ + private isExpired(token: string): boolean { + const key = this.key?.token === token ? this.key : parseServiceKey(token); + return key !== null && this.clock.nowSeconds() >= key.payload.exp; + } + private settleInBackground(): void { - if (this.work || (this.loaded && !this.wantsRegistration())) return; - this.inBackground(async () => { + if (this.work || (this.loaded && !this.wantsRegistration() && !this.keyToRenewNow())) return; + void this.inBackground(async () => { await this.load(); - if (this.wantsRegistration()) await this.register(); + if (this.wantsRegistration()) { + await this.register(); + return; + } + const due = this.keyToRenewNow(); + if (due) await this.renew(due); }); } - /** Runs work outside the request that triggered it, one piece at a time, and never lets it fail a caller. */ - private inBackground(task: () => Promise): void { + /** + * Runs work outside the request that triggered it, one piece at a time. A + * failure is logged and never reaches a request; only a caller that awaits + * the returned promise sees it. + */ + private inBackground(task: () => Promise): Promise { const previous = this.work ?? Promise.resolve(); - const next = previous - .then(() => withRequestContext(this.orm, task)) + const run = previous.then(() => withRequestContext(this.orm, task)); + const next = run .catch((err: unknown) => logWarn(`TREK services: ${err instanceof Error ? err.message : String(err)}`)) .finally(() => { if (this.work === next) this.work = null; }); this.work = next; + return run; } private async load(): Promise { @@ -252,6 +269,27 @@ export class ServiceKeyService { } } + /** Same installation, new expiry; the old key is the proof, so no proof of work. */ + private async renew(key: ServiceKey): Promise { + const renewal = await this.issuer.renew(key.token).then( + (grant) => ({ grant, error: null }), + (error: unknown) => ({ grant: null, error }), + ); + if (!renewal.grant) { + this.backOff(renewal.error); + await this.refused(renewal.error, key.token); + return; + } + this.clock.learn(renewal.grant.serverMs); + const renewed = this.readGrant(renewal.grant.body); + this.state = { ...this.state, renewAfter: renewal.grant.body.renew_after }; + await this.store.replace(renewed, this.state); + this.key = renewed; + this.failures = 0; + this.refusals.clear(); + logInfo('TREK services: renewed the key of this installation.'); + } + private readGrant(grant: ServiceKeyGrant): ServiceKey { const key = parseServiceKey(grant.key); if (!key) throw new Error('the issuer handed out a key TREK cannot read'); @@ -265,10 +303,11 @@ export class ServiceKeyService { this.nextAttemptAt = Date.now() + (asked ?? backoff); } + /** A refused renewal counts like a refused search; anything else is rethrown for the caller to log. */ private async refused(err: unknown, token: string): Promise { if (!(err instanceof IssuerError) || (err.status !== 401 && err.status !== 403)) throw err; if (err.status === 403) await this.markRevoked(token); - else await this.dropKey(); + else if (this.refusals.hit()) await this.dropKey(); } private async dropKey(): Promise { diff --git a/server/tests/unit/nest/service-identity/refusal-streak.test.ts b/server/tests/unit/nest/service-identity/refusal-streak.test.ts new file mode 100644 index 000000000..6fc55aec1 --- /dev/null +++ b/server/tests/unit/nest/service-identity/refusal-streak.test.ts @@ -0,0 +1,36 @@ +/** + * RefusalStreak: when the refusals of a key add up to giving it up. Three at + * moments apart do; a burst counts once, and an acceptance starts over. + */ +import { RefusalStreak } from '../../../../src/nest/service-identity/refusal-streak'; + +import { describe, expect, it } from 'vitest'; + +const MINUTE = 60_000; + +describe('RefusalStreak', () => { + it('SISTREAK-001: completes on the third refusal ten minutes apart, then starts over', () => { + const streak = new RefusalStreak(); + expect(streak.hit(0)).toBe(false); + expect(streak.hit(10 * MINUTE)).toBe(false); + expect(streak.hit(20 * MINUTE)).toBe(true); + expect(streak.hit(30 * MINUTE)).toBe(false); + }); + + it('SISTREAK-002: refusals closer together than ten minutes are one', () => { + const streak = new RefusalStreak(); + for (let i = 0; i < 9; i++) expect(streak.hit(i * MINUTE)).toBe(false); + expect(streak.hit(10 * MINUTE)).toBe(false); + expect(streak.hit(20 * MINUTE)).toBe(true); + }); + + it('SISTREAK-003: an acceptance clears what was counted', () => { + const streak = new RefusalStreak(); + streak.hit(0); + streak.hit(10 * MINUTE); + streak.clear(); + expect(streak.hit(11 * MINUTE)).toBe(false); + expect(streak.hit(21 * MINUTE)).toBe(false); + expect(streak.hit(31 * MINUTE)).toBe(true); + }); +}); diff --git a/server/tests/unit/nest/service-identity/service-key.service.test.ts b/server/tests/unit/nest/service-identity/service-key.service.test.ts index 7a3ce4a4c..8212e5d56 100644 --- a/server/tests/unit/nest/service-identity/service-key.service.test.ts +++ b/server/tests/unit/nest/service-identity/service-key.service.test.ts @@ -252,14 +252,21 @@ describe('refusals', () => { return built; } + const tenMinutesLater = () => vi.setSystemTime(Date.now() + 10 * 60_000); + it('SIKEYS-020: gives the key up only on the third 401 in a row, and asks again within six hours', async () => { + vi.useFakeTimers({ toFake: ['Date'] }); const { keys, store, issuer } = await registered(); keys.noteInvalid(); + tenMinutesLater(); keys.noteInvalid(); keys.noteAccepted(); + tenMinutesLater(); keys.noteInvalid(); + tenMinutesLater(); keys.noteInvalid(); expect(store.dropKey).not.toHaveBeenCalled(); + tenMinutesLater(); const before = Date.now(); keys.noteInvalid(); await settled(keys); @@ -306,6 +313,17 @@ describe('refusals', () => { const off = await build({ config: { mode: 'off' } }); await expect(off.keys.regenerate()).rejects.toMatchObject({ status: 409 }); }); + + it('SIKEYS-024: the refusals of one page full of searches count once', async () => { + vi.useFakeTimers({ toFake: ['Date'] }); + const { keys, store } = await registered(); + for (let i = 0; i < 6; i++) keys.noteInvalid(); + tenMinutesLater(); + for (let i = 0; i < 6; i++) keys.noteInvalid(); + await settled(keys); + expect(store.dropKey).not.toHaveBeenCalled(); + expect(keys.bearer()).toBe(KEY); + }); }); describe('renewal', () => { @@ -345,12 +363,20 @@ describe('renewal', () => { expect(issuer.renew).toHaveBeenCalledTimes(1); }); - it('SIKEYS-033: a refused renewal drops the key, a revoked one freezes it, a network failure changes nothing', async () => { + it('SIKEYS-033: a refused renewal counts like a refused search, a revoked one freezes it, a network failure changes nothing', async () => { + vi.useFakeTimers({ toFake: ['Date'] }); const refused = fakeIssuer(); - refused.renew.mockRejectedValueOnce(new IssuerError(401, null, null)); + refused.renew.mockRejectedValue(new IssuerError(401, null, null)); const first = await build({ store: stored(), issuer: refused }); await first.keys.renewIfDue(); + await first.keys.renewIfDue(); + expect(first.store.dropKey).not.toHaveBeenCalled(); + for (let i = 0; i < 2; i++) { + vi.setSystemTime(Date.now() + 10 * 60_000); + await first.keys.renewIfDue(); + } expect(first.store.dropKey).toHaveBeenCalledTimes(1); + vi.useRealTimers(); await t?.close(); const revoked = fakeIssuer(); @@ -390,4 +416,47 @@ describe('renewal', () => { await keys.renewIfDue(); expect(issuer.renew).not.toHaveBeenCalled(); }); + + it('SIKEYS-036: a due key is renewed on the next request, not only by the daily check', async () => { + const store = stored(); + const { keys, issuer } = await build({ store }); + expect(keys.bearer()).toBe(oldKey); + await settled(keys); + expect(issuer.renew).toHaveBeenCalledWith(oldKey); + expect(keys.bearer()).toBe(RENEWED_KEY); + }); + + it('SIKEYS-037: an expired key within its grace stays home, and the next request renews it', async () => { + const expired = serviceKeyTokenFor({ i: 'installation-a', iat: now() - 95 * DAY, exp: now() - 5 * DAY }); + const store = fakeStore({ + key: { + token: expired, + kid: 'test', + payload: { i: 'installation-a', iat: now() - 95 * DAY, exp: now() - 5 * DAY, q: 'std' }, + }, + }); + const { keys, issuer } = await build({ store }); + expect(keys.bearer()).toBeNull(); + await settled(keys); + expect(issuer.renew).toHaveBeenCalledWith(expired); + expect(issuer.register).not.toHaveBeenCalled(); + expect(keys.bearer()).toBe(RENEWED_KEY); + }); + + it('SIKEYS-038: after a failed renewal the requests wait for the backoff instead of asking again', async () => { + vi.useFakeTimers({ toFake: ['Date'] }); + const issuer = fakeIssuer(); + issuer.renew.mockRejectedValueOnce(new Error('fetch failed')); + const { keys } = await build({ store: stored(), issuer }); + keys.bearer(); + await settled(keys); + keys.bearer(); + await settled(keys); + expect(issuer.renew).toHaveBeenCalledTimes(1); + vi.setSystemTime(Date.now() + 5 * 60_000); + keys.bearer(); + await settled(keys); + expect(issuer.renew).toHaveBeenCalledTimes(2); + expect(keys.bearer()).toBe(RENEWED_KEY); + }); }); diff --git a/server/tests/unit/nest/trek-places.client.test.ts b/server/tests/unit/nest/trek-places.client.test.ts index 160b5614d..eb425d2cf 100644 --- a/server/tests/unit/nest/trek-places.client.test.ts +++ b/server/tests/unit/nest/trek-places.client.test.ts @@ -504,6 +504,40 @@ describe('the installation identity', () => { } }); + it('asks once more through the shared pool when the key is refused, and shows the identity only the refusal', async () => { + const port = { + headersFor: vi.fn(() => ({ 'User-Agent': 'TREK/test', Authorization: 'Bearer installation-key' })), + observe: vi.fn(), + }; + serviceIdentitySlot.install(port); + try { + calls = []; + let answered = 0; + vi.stubGlobal( + 'fetch', + vi.fn(async (url: URL | string, init?: RequestInit) => { + calls.push({ url: String(url), init }); + answered += 1; + const status = answered === 1 ? 401 : 200; + return { + ok: status === 200, + status, + body: null, + text: async () => JSON.stringify({ query: 'x', results: [PLACE] }), + } as unknown as Response; + }), + ); + await expect(trekPlacesSearch('x')).resolves.toHaveLength(1); + expect(calls).toHaveLength(2); + expect(calls[1].init?.headers).not.toHaveProperty('Authorization'); + expect(calls[1].init?.headers).toMatchObject({ 'User-Agent': 'TREK/test' }); + expect(port.observe).toHaveBeenCalledTimes(1); + expect(port.observe.mock.calls[0][1]).toMatchObject({ status: 401 }); + } finally { + serviceIdentitySlot.release(port); + } + }); + it('sends what it always sent while no identity is installed', async () => { stubFetch({ query: 'x', results: [] }); await trekPlacesSearch('x');