mirror of
https://github.com/stablyai/orca.git
synced 2026-11-13 09:27:29 +00:00
relay edge: silent host at authorization expiry closes 4408; dead-control diagnostics (#40929)
* relay edge: a keepalive host already silent when its authorization expires closes 4408 At token exp + 60 s, a keepalive control that went silent (asleep, offline) had its silence probe pending, so the expiry check closed it 4401. Production showed these as 4401 'never refreshed' closes with the host silent for ~5-6 minutes, inflating the auth-failure count and hiding drops from the 4408 comparison with the cells. Such a host now closes 4408 (orphan time back-dated as for any silence close). Local e2e K4 (fails without the change: 4401). 48/48. * relay edge: handshake time on control_active, control age and silence on dead-control closes At 1%, many new controls went silent at or right after activation and were closed minutes later, with no rebound from a retry. To tell a desktop that gave up the connect (15 s deadline, e.g. a slow first hello on a new object) from one that died later: control_active double2 = ms from the upgrade to activation; new silence_close (seconds silent, where found, keepalive/legacy, age); auth_expired_close double3 = control age.
This commit is contained in:
@@ -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 = {
|
||||
|
||||
@@ -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<void> {
|
||||
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))
|
||||
}
|
||||
|
||||
@@ -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()
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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'
|
||||
|
||||
@@ -47,14 +47,14 @@ export function newHost(): Host {
|
||||
}
|
||||
}
|
||||
|
||||
export async function mint(key: KeyLike, relayHostId: string, issuer = ISSUER): Promise<string> {
|
||||
export async function mint(key: KeyLike, relayHostId: string, issuer = ISSUER, expiresIn = '5m'): Promise<string> {
|
||||
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)
|
||||
}
|
||||
|
||||
|
||||
@@ -128,6 +128,32 @@ export async function keepaliveProbeCheck(key: KeyLike): Promise<void> {
|
||||
}
|
||||
}
|
||||
|
||||
// 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<void> {
|
||||
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<void> {
|
||||
const host = newHost()
|
||||
|
||||
@@ -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<void> {
|
||||
@@ -107,7 +107,7 @@ async function main(): Promise<void> {
|
||||
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)
|
||||
|
||||
Reference in New Issue
Block a user