diff --git a/cloud/apps/relay-edge/src/host-relay-base.ts b/cloud/apps/relay-edge/src/host-relay-base.ts index f3f34839b10..d550b6ca840 100644 --- a/cloud/apps/relay-edge/src/host-relay-base.ts +++ b/cloud/apps/relay-edge/src/host-relay-base.ts @@ -45,6 +45,9 @@ export type ControlAttachment = { clientKeepalive?: boolean // A keepalive control found silent: one relay ping sent at this time (see probeSilentControls). probeAt?: number + // Upgrade and activation times, for metrics (absent on attachments from before these fields). + openedAt?: number + activeAt?: number } export type Attachment = ControlAttachment export type Conn = { diff --git a/cloud/apps/relay-edge/src/host-relay-control.ts b/cloud/apps/relay-edge/src/host-relay-control.ts index 16697097b1c..2cc2756c22c 100644 --- a/cloud/apps/relay-edge/src/host-relay-control.ts +++ b/cloud/apps/relay-edge/src/host-relay-control.ts @@ -28,8 +28,16 @@ export abstract class HostRelayControl extends HostRelayHandshake { // Where the host is going away anyway (export, erase, drain, a new control of the same host): a // silent control is closed now. Its orphan time is the latest the ping alarm would have found it, // so rebind and the orphan grace are never shorter than before. + // A control closed for silence: value = seconds silent, label = where it was found, reason = + // keepalive | legacy; double2 = seconds since it became active (-1 if unknown). + protected deadControlMetric(a: ControlAttachment, now: number, seen: number, found: 'alarm' | 'on_demand' | 'expired'): void { + const ageS = a.activeAt === undefined ? -1 : Math.round((now - a.activeAt) / 1000) + metric(this.env, 'silence_close', Math.round((now - seen) / 1000), found, [ageS], this.keepalive(a) ? 'keepalive' : 'legacy', a.place) + } + protected async closeSilentControls(now = Date.now()): Promise { - for (const { ws, seen } of this.silentControls(now)) { + for (const { ws, a, seen } of this.silentControls(now)) { + this.deadControlMetric(a, now, seen, 'on_demand') this.close(ws, RELAY_CLOSE_CODE.PEER_DROPPED, 'control silence timeout') await this.onSocketGone(ws, RELAY_CLOSE_CODE.PEER_DROPPED, '', Math.min(now, seen + this.config.silenceTimeoutMs + this.config.pingIntervalMs)) } diff --git a/cloud/apps/relay-edge/src/host-relay-handshake.ts b/cloud/apps/relay-edge/src/host-relay-handshake.ts index 22614a1fe85..1d9995d44bf 100644 --- a/cloud/apps/relay-edge/src/host-relay-handshake.ts +++ b/cloud/apps/relay-edge/src/host-relay-handshake.ts @@ -157,6 +157,7 @@ export abstract class HostRelayHandshake extends HostRelayBase { }) const leaseExpiresAt = now + LEASE_BASE_MS + Math.round((Math.random() * 2 - 1) * LEASE_JITTER_MS) a.phase = 'active' + a.activeAt = now a.generation = generation a.lastPongAt = now a.lastPingAt = now @@ -191,7 +192,7 @@ export abstract class HostRelayHandshake extends HostRelayBase { }) // After the ack, which strict shipped parsers must see unchanged; only hosts that asked get it. if (a.clientKeepalive) { this.send(ws, { type: 'keepalive-offer', v: 1, intervalMs: this.config.pingIntervalMs }) } - metric(this.env, 'control_active', 1, rebind ? 'rebind' : 'new', [], a.clientKeepalive ? 'keepalive' : 'legacy', a.place) + metric(this.env, 'control_active', 1, rebind ? 'rebind' : 'new', [a.openedAt === undefined ? -1 : now - a.openedAt], a.clientKeepalive ? 'keepalive' : 'legacy', a.place) await this.reschedule() } } diff --git a/cloud/apps/relay-edge/src/host-relay.ts b/cloud/apps/relay-edge/src/host-relay.ts index 14f5a0f544f..bc6095bc33a 100644 --- a/cloud/apps/relay-edge/src/host-relay.ts +++ b/cloud/apps/relay-edge/src/host-relay.ts @@ -145,7 +145,8 @@ export class HostRelay extends HostRelayPhones { claims, origin, caps: [...parseRelayHostCapabilities(request.headers.get('x-orca-host-capabilities') ?? '')], - deadline: Date.now() + RELAY_PROTOCOL_LIMITS.firstFrameDeadlineMs + deadline: Date.now() + RELAY_PROTOCOL_LIMITS.firstFrameDeadlineMs, + openedAt: Date.now() }) await this.reschedule() return new Response(null, { status: 101, webSocket: client }) @@ -180,15 +181,25 @@ export class HostRelay extends HostRelayPhones { continue } if (now - seen > this.config.silenceTimeoutMs && (!this.keepalive(a) || now - a.probeAt! >= KEEPALIVE_PROBE_MS - 50)) { + this.deadControlMetric(a, now, seen, 'alarm') this.close(ws, RELAY_CLOSE_CODE.PEER_DROPPED, 'control silence timeout') await this.onSocketGone(ws, RELAY_CLOSE_CODE.PEER_DROPPED, '') continue } // Same order as the cells' heartbeat: expired auth past its grace, then the 6 h lease. if (now > a.claims.exp + CONTROL_CONTINUITY_LIMITS.expiredAuthExistingSpliceGraceMs) { + // A host already silent past the limit is gone (asleep, offline): it closes as one, so + // drop counts stay comparable with the cells, whose pings would have closed it earlier. + // Its probe is cut short: the expired authorization ends the socket either way. + if (now - seen > this.config.silenceTimeoutMs) { + this.deadControlMetric(a, now, seen, 'expired') + this.close(ws, RELAY_CLOSE_CODE.PEER_DROPPED, 'control silence timeout') + await this.onSocketGone(ws, RELAY_CLOSE_CODE.PEER_DROPPED, '', Math.min(now, seen + this.config.silenceTimeoutMs + this.config.pingIntervalMs)) + continue + } const sinceRefreshS = a.lastRefreshAt === undefined ? -1 : Math.round((now - a.lastRefreshAt) / 1000) const seenAgoS = Math.round((now - seen) / 1000) - metric(this.env, 'auth_expired_close', sinceRefreshS, a.lastRefreshAt === undefined ? 'never' : 'refreshed', [seenAgoS], this.keepalive(a) ? 'keepalive' : 'legacy', a.place) + metric(this.env, 'auth_expired_close', sinceRefreshS, a.lastRefreshAt === undefined ? 'never' : 'refreshed', [seenAgoS, a.activeAt === undefined ? -1 : Math.round((now - a.activeAt) / 1000)], this.keepalive(a) ? 'keepalive' : 'legacy', a.place) this.close(ws, RELAY_CLOSE_CODE.BAD_OUTER_CREDENTIAL, 'relay authorization expired') await this.onSocketGone(ws, RELAY_CLOSE_CODE.BAD_OUTER_CREDENTIAL, '') continue diff --git a/cloud/apps/relay-edge/src/metrics.ts b/cloud/apps/relay-edge/src/metrics.ts index febc2bab77c..ea76d7f7f2c 100644 --- a/cloud/apps/relay-edge/src/metrics.ts +++ b/cloud/apps/relay-edge/src/metrics.ts @@ -2,7 +2,8 @@ import type { Env } from './env' export type MetricEvent = - // label 'new' | 'rebind'; reason 'keepalive' | 'legacy' (took the keepalive offer or not). + // label 'new' | 'rebind'; reason 'keepalive' | 'legacy' (took the keepalive offer or not); + // double2 = ms from the upgrade to activation (the desktop gives up a connect after 15 s). | 'control_active' | 'control_close' | 'phone_open' @@ -27,8 +28,11 @@ export type MetricEvent = | 'control_upgrade' // Control closed 4401 for expired authorization: value = seconds since its last extending // refresh, label 'refreshed'; -1 and label 'never' when this socket never extended its token. - // double2 = seconds since the host's last inbound frame or keepalive; reason 'keepalive' | 'legacy'. + // double2 = seconds since the host's last inbound frame or keepalive, double3 = seconds since the + // control became active (-1 if unknown); reason 'keepalive' | 'legacy'. | 'auth_expired_close' + // Control closed for silence (deadControlMetric, host-relay-control.ts). + | 'silence_close' // Pre-auth socket refused by the per-source limiter: label 'phone' | 'data' | 'health'. Unpushed-host phones: 'not_on_edge'. | 'preauth_limited' | 'not_on_edge' diff --git a/cloud/apps/relay-edge/test/harness-mvp-object.ts b/cloud/apps/relay-edge/test/harness-mvp-object.ts index 89ec43b1e7c..69530b07307 100644 --- a/cloud/apps/relay-edge/test/harness-mvp-object.ts +++ b/cloud/apps/relay-edge/test/harness-mvp-object.ts @@ -47,14 +47,14 @@ export function newHost(): Host { } } -export async function mint(key: KeyLike, relayHostId: string, issuer = ISSUER): Promise { +export async function mint(key: KeyLike, relayHostId: string, issuer = ISSUER, expiresIn = '5m'): Promise { return new SignJWT({ purpose: 'host-control', prof: `prof-${USER}`, relayHostId }) .setProtectedHeader({ alg: 'ES256', kid: REMOTE ? 'spike' : 'mvp' }) .setSubject(USER) .setIssuer(issuer) .setAudience('orca-relay') .setIssuedAt() - .setExpirationTime('5m') + .setExpirationTime(expiresIn) .sign(key) } diff --git a/cloud/apps/relay-edge/test/mvp-object-hardening.ts b/cloud/apps/relay-edge/test/mvp-object-hardening.ts index 5bd6553acab..1e86d0058ee 100644 --- a/cloud/apps/relay-edge/test/mvp-object-hardening.ts +++ b/cloud/apps/relay-edge/test/mvp-object-hardening.ts @@ -128,6 +128,32 @@ export async function keepaliveProbeCheck(key: KeyLike): Promise { } } +// K4: a keepalive host gone silent when its authorization expires closes as a dropped host (4408), +// not 4401, so edge drop counts stay comparable with the cells (their pings would have closed it). +export async function keepaliveExpiredSilentCheck(key: KeyLike): Promise { + const host = newHost() + await assign(host.relayHostId, 'edge', EPOCH, []) + const started = Date.now() + // Alive for 50 s, then silent: the silence probe (sent ~9 s later) is still pending when the + // 3 s token passes its 60 s grace at ~63 s, so the expiry check is what closes it. + const c = control(host, await mint(key, host.relayHostId, undefined, '3s'), EPOCH, { + caps: `${SHIPPED_CAPS},client-keepalive-v1`, + drop: () => Date.now() - started > 50_000 + }) + await c.client.connect() + try { + const closed = await waitFor(() => c.events.closes.length > 0, 3_000 + 60_000 + 15_000) + const after = Date.now() - started + record( + 'K4 silent keepalive host at token expiry: closed 4408 (not 4401)', + closed && c.events.closes.includes(4408) && !c.events.closes.includes(4401) && after >= 59_000, + `closedAfter=${after}ms pings=${c.events.pings} closes=${c.events.closes}` + ) + } finally { + c.client.closeNow() + } +} + // F5: POST /__admin/drain sends the host's controls back to the director (drain frame, 4503). export async function drainCheck(key: KeyLike): Promise { const host = newHost() diff --git a/cloud/apps/relay-edge/test/mvp-object.ts b/cloud/apps/relay-edge/test/mvp-object.ts index 5558bb2d179..f9a436c1d37 100644 --- a/cloud/apps/relay-edge/test/mvp-object.ts +++ b/cloud/apps/relay-edge/test/mvp-object.ts @@ -41,7 +41,7 @@ import { waitFor, type Host } from './harness-mvp-object' -import { drainCheck, heartbeatCheck, keepaliveCheck, keepaliveProbeCheck, objectHealthCheck } from './mvp-object-hardening' +import { drainCheck, heartbeatCheck, keepaliveCheck, keepaliveExpiredSilentCheck, keepaliveProbeCheck, objectHealthCheck } from './mvp-object-hardening' import { replayCheck, rotationCheck } from './mvp-object-replay' async function mainRemote(): Promise { @@ -107,7 +107,7 @@ async function main(): Promise { await sleep(500) } await run(host, privateKey, () => jwksHits) - await Promise.all([heartbeatCheck(privateKey), keepaliveCheck(privateKey), keepaliveProbeCheck(privateKey), drainCheck(privateKey), replayCheck(), rotationCheck()]) + await Promise.all([heartbeatCheck(privateKey), keepaliveCheck(privateKey), keepaliveProbeCheck(privateKey), keepaliveExpiredSilentCheck(privateKey), drainCheck(privateKey), replayCheck(), rotationCheck()]) await sweepCheck() await preAuthCheck(stateDir) await objectHealthCheck(stateDir)