diff --git a/cloud/apps/relay/src/cell-phone-path.blackbox.test.ts b/cloud/apps/relay/src/cell-phone-path.blackbox.test.ts index c8526367dde..ad8ee69b66c 100644 --- a/cloud/apps/relay/src/cell-phone-path.blackbox.test.ts +++ b/cloud/apps/relay/src/cell-phone-path.blackbox.test.ts @@ -385,6 +385,22 @@ describe('the memory phone path', () => { await new Promise((resolve) => setTimeout(resolve, 50)) expect(await confirm('confirm-1')).toMatchObject({ type: 'control-error', code: 'confirmation_not_active' }) expect(reserve.phoneStatements()[0]).toBe('BEGIN') + expect(warnings('orca_relay_resume_confirm_failed')).toEqual([ + { + event: 'orca_relay_resume_confirm_failed', + code: 'confirmation_not_active', + phonePath: 'db', + cellId: reserve.config.cellId + } + ]) + }) + + it('does not count a lease release that failed after a committed confirm as a failed confirm', async () => { + const { reserve, confirm } = await splicedPhone('db') + vi.spyOn(reserve.relay.assignments, 'releaseActivity').mockRejectedValueOnce(new Error('connection terminated')) + // As today, the desktop still hears the release failure. + expect(await confirm('confirm-1')).toMatchObject({ type: 'control-error' }) + expect(warnings('orca_relay_resume_confirm_failed')).toEqual([]) }) it('keeps the database confirm statement for statement while phonePath is db', async () => { diff --git a/cloud/apps/relay/src/host-session-client-accept.test.ts b/cloud/apps/relay/src/host-session-client-accept.test.ts index 7806e8d25b3..f66be975704 100644 --- a/cloud/apps/relay/src/host-session-client-accept.test.ts +++ b/cloud/apps/relay/src/host-session-client-accept.test.ts @@ -114,7 +114,9 @@ function harness(options: { random?: () => number; now?: () => number } = {}) { recordSql: vi.fn(), recordClientAcceptAbandoned: vi.fn(), recordClientAcceptCompleted: vi.fn(), - recordControlRtt: vi.fn() + recordControlRtt: vi.fn(), + recordPhoneRejection: vi.fn(), + recordPhoneAttachDeadline: vi.fn() } satisfies RelayRuntimeObserver const registry = new HostSessionRegistry( config, @@ -369,6 +371,40 @@ describe('client accept abandoned mid-DB-phase', () => { } }) + it('logs and counts an attach deadline with what the cell knew of the control', async () => { + let now = 1_700_000_000_000 + const h = harness({ now: () => now }) + await activeHost(h) + const warn = vi.spyOn(console, 'warn').mockImplementation(() => undefined) + const client = new FakeSocket() + await h.registry.acceptClient(client as unknown as WebSocket, identity.relayHostId, 'credential') + now += RELAY_PROTOCOL_LIMITS.hostAttachDeadlineMs + vi.advanceTimersByTime(RELAY_PROTOCOL_LIMITS.hostAttachDeadlineMs) + expect(client.close).toHaveBeenCalledWith(RELAY_CLOSE_CODE.HOST_OFFLINE, expect.any(String)) + expect(h.observer.recordPhoneAttachDeadline).toHaveBeenCalledOnce() + expect(h.observer.recordPhoneRejection).toHaveBeenCalledWith(RELAY_CLOSE_CODE.HOST_OFFLINE) + const lines = warn.mock.calls + .map(([line]) => String(line)) + .filter((line) => line.includes('orca_relay_attach_deadline_offline')) + expect(lines.map((line) => JSON.parse(line))).toEqual([ + { + event: 'orca_relay_attach_deadline_offline', + relayHostIdDigest: expect.any(String), + credentialKind: 'resume', + msSinceLastPong: RELAY_PROTOCOL_LIMITS.hostAttachDeadlineMs, + pingOutstanding: false, + controlAgeMs: RELAY_PROTOCOL_LIMITS.hostAttachDeadlineMs, + controlRttMs: null, + pong: 'fresh', + cellId: config.cellId + } + ]) + expect(lines[0]).not.toContain(identity.relayHostId) + warn.mockRestore() + h.registry.drain(0) + vi.advanceTimersByTime(0) + }) + it('still opens the connection when the phone is holding on', async () => { const h = harness() const control = await activeHost(h) @@ -437,7 +473,8 @@ describe('successful client accept timing', () => { expect(ownerProbe).toHaveBeenCalledOnce() expect(h.observer.recordClientAcceptCompleted).toHaveBeenCalledWith({ totalMs: 49, - stageMs: { assignment: 5, credential: 7, activity: 11, attach: 23, basis: 3 } + stageMs: { assignment: 5, credential: 7, activity: 11, attach: 23, basis: 3 }, + phonePath: 'db' }) const line = log.mock.calls .map((call) => String(call[0])) diff --git a/cloud/apps/relay/src/host-session-registry.ts b/cloud/apps/relay/src/host-session-registry.ts index d33c6e36578..331599be4bf 100644 --- a/cloud/apps/relay/src/host-session-registry.ts +++ b/cloud/apps/relay/src/host-session-registry.ts @@ -37,10 +37,10 @@ import { CellSeatLog, type CellSeatChange, type CellSeatFeedPage } from './cell- import { isRelayDatabaseTransientError } from './database.js' import { printableCloseReason } from './control-close-reason-text.js' import { ControlRenewalBatch } from './control-renewal-batch.js' -import { RelayCredentialStore, type CredentialReservation } from './credential-store.js' +import { RelayCredentialStore, RelayStoreError, type CredentialReservation } from './credential-store.js' import { HostCloseReasonMemory } from './host-close-reason-memory.js' import { MemoryResumeConfirmations } from './memory-resume-confirmations.js' -import { PhoneAcceptLog } from './phone-accept-log.js' +import { PhoneConnectionLog, type PhoneDatabaseCause } from './phone-connection-log.js' import { postProofCloseCause, PostProofCloseLog, @@ -304,7 +304,7 @@ export class HostSessionRegistry { private readonly drainSentHosts = new Set() private readonly seatLog: CellSeatLog private readonly postProofCloses: PostProofCloseLog - private readonly phoneAccepts: PhoneAcceptLog + private readonly phoneConnections: PhoneConnectionLog private readonly memoryConfirmations: MemoryResumeConfirmations // Seat key -> the demoted control socket. Its own set, not drainSentHosts: it ends with // that socket (close, rebind or a new join), so a later booking here is a fresh seat. @@ -450,9 +450,9 @@ export class HostSessionRegistry { ) { this.seatLog = new CellSeatLog(undefined, now) this.postProofCloses = new PostProofCloseLog(observer) - this.phoneAccepts = new PhoneAcceptLog(config.cellId) + this.phoneConnections = new PhoneConnectionLog(config.cellId) this.memoryConfirmations = new MemoryResumeConfirmations(store, now, (error) => - this.phoneAccepts.renewalFailed(isRelayDatabaseTransientError(error) ? 'database_transient' : 'error') + this.recordRenewalFailure(error) ) } @@ -862,9 +862,8 @@ export class HostSessionRegistry { } catch (error) { // Never the invite path: an unread device is not a missing one. capacityReservation?.release() - this.phoneAccepts.databaseError( - isRelayDatabaseTransientError(error) ? 'database_transient' : 'error' - ) + this.observer.recordPhoneAcceptDatabaseError?.() + this.phoneConnections.databaseError(databaseCause(error)) this.rejectClient(socket, RELAY_CLOSE_CODE.DRAINING) return } @@ -981,6 +980,7 @@ export class HostSessionRegistry { capacityReservation?.release() this.failReservationBestEffort(reservation) if (credentialActivityId) this.releaseActivityBestEffort(identity, credentialActivityId) + this.recordAttachDeadline(session, reservation) this.rejectClient(socket, RELAY_CLOSE_CODE.HOST_OFFLINE) }, RELAY_PROTOCOL_LIMITS.hostAttachDeadlineMs) const pending: PendingConnection = { @@ -1075,9 +1075,9 @@ export class HostSessionRegistry { relayHostId: reservation.relayHostId }) elsewhere = row !== null && row.cellId !== this.config.cellId - if (row?.cellId === this.config.cellId) this.phoneAccepts.missRowNamesHere(reservation.relayHostId) + if (row?.cellId === this.config.cellId) this.phoneConnections.missRowNamesHere(reservation.relayHostId) } catch (error) { - this.phoneAccepts.missReadError(isRelayDatabaseTransientError(error) ? 'database_transient' : 'error') + this.phoneConnections.missReadError(databaseCause(error)) elsewhere = true } if (elsewhere) { @@ -1271,13 +1271,14 @@ export class HostSessionRegistry { basis: nonNegativeMs(helloAt - attachedAt) } const totalMs = nonNegativeMs(helloAt - pending.timing.startedAt) - this.observer.recordClientAcceptCompleted?.({ totalMs, stageMs }) + this.observer.recordClientAcceptCompleted?.({ totalMs, stageMs, phonePath: pending.phonePath }) console.log( JSON.stringify({ event: 'orca_relay_client_accept_completed', ...this.logIdentity(), ...this.sessionPlacementLogFields(session), credentialKind: pending.reservation.credentialKind, + phonePath: pending.phonePath, stageMs, totalMs, relayHostIdDigest: relayHostLogDigest(session.relayHostId) @@ -2488,12 +2489,21 @@ export class HostSessionRegistry { if (type === 'device-resume-confirm') { const request = DeviceResumeConfirmSchema.parse(payload(raw, type)) const confirm = { ...identity, ...request, owningControlGeneration: session.generation } - if (this.memoryConfirmations.owns(confirm)) { - send(session.socket, 'device-resume-confirmed', await this.memoryConfirmations.confirm(confirm)) - return + const phonePath = this.memoryConfirmations.owns(confirm) ? 'memory' : 'db' + let result + try { + result = + phonePath === 'memory' + ? await this.memoryConfirmations.confirm(confirm) + : await this.store.confirmResume(confirm) + } catch (error) { + this.recordConfirmFailure(error, phonePath) + throw error + } + // After a committed confirm: a failed release is not a failed confirm. + if (phonePath === 'db') { + await this.assignments.releaseActivity(identity, `confirmation:${request.basisConnId}`) } - const result = await this.store.confirmResume(confirm) - await this.assignments.releaseActivity(identity, `confirmation:${request.basisConnId}`) send(session.socket, 'device-resume-confirmed', result) return } @@ -2519,6 +2529,32 @@ export class HostSessionRegistry { } } + private recordRenewalFailure(error: unknown): void { + this.observer.recordResumeRenewalFailure?.() + this.phoneConnections.renewalFailed(databaseCause(error)) + } + + // Never the raw message as a key: pg errors can carry the database URL. + private recordConfirmFailure(error: unknown, phonePath: 'db' | 'memory'): void { + const code = error instanceof RelayStoreError ? error.code : databaseCause(error) + this.observer.recordResumeConfirmFailure?.(code) + this.phoneConnections.confirmFailed(code, phonePath) + } + + private recordAttachDeadline(session: HostSession, reservation: CredentialReservation): void { + const now = this.now() + const msSinceLastPong = now - session.lastPongAt + this.observer.recordPhoneAttachDeadline?.() + this.phoneConnections.attachDeadline(session.relayHostId, { + credentialKind: reservation.credentialKind, + msSinceLastPong, + pingOutstanding: session.pendingPingAt !== null, + controlAgeMs: now - session.controlWiredAt, + controlRttMs: session.controlRttSamplesMs.at(-1) ?? null, + pong: msSinceLastPong > RELAY_PROTOCOL_LIMITS.controlPingIntervalMs ? 'stale' : 'fresh' + }) + } + private sendControlError(session: HostSession, reqId: string | undefined, code: string): void { if (session.socket) send(session.socket, 'control-error', { ...(reqId ? { reqId } : {}), code }) } @@ -2531,6 +2567,7 @@ export class HostSessionRegistry { code: number, hostCloseReason?: RelayHostCloseReason | null ): void { + this.observer.recordPhoneRejection?.(code) send(socket, 'relay-hello', { ok: false, code }) closeRelayWebSocket(socket, code, hostCloseReason ?? 'relay connection rejected') } @@ -2595,3 +2632,7 @@ export class HostSessionRegistry { } export type RelayIdentityKey = { userId: string; relayHostId: string } + +function databaseCause(error: unknown): PhoneDatabaseCause { + return isRelayDatabaseTransientError(error) ? 'database_transient' : 'error' +} diff --git a/cloud/apps/relay/src/phone-accept-log.ts b/cloud/apps/relay/src/phone-accept-log.ts deleted file mode 100644 index f565ee7b435..00000000000 --- a/cloud/apps/relay/src/phone-accept-log.ts +++ /dev/null @@ -1,61 +0,0 @@ -import { AssignmentRejectionLogWindow } from './assignment-rejection-log-window.js' -import { relayHostLogDigest } from './relay-host-log-digest.js' - -// The memory phone path's two accept anomalies. A stuck database or a lost ledger write repeats -// per phone dial, so per event one line opens the window and one closing line carries the rest. -export const PHONE_ACCEPT_LOG_WINDOW_MS = 60_000 - -export type PhoneAcceptDatabaseCause = 'database_transient' | 'error' - -type PhoneAcceptAnomaly = - | { event: 'orca_relay_client_accept_db_error'; cause: PhoneAcceptDatabaseCause } - | { event: 'orca_relay_client_miss_row_names_here'; relayHostIdDigest: string } - | { event: 'orca_relay_client_miss_read_error'; cause: PhoneAcceptDatabaseCause } - | { event: 'orca_relay_resume_renewal_failed'; cause: PhoneAcceptDatabaseCause } - -export class PhoneAcceptLog { - private readonly window: AssignmentRejectionLogWindow - - constructor( - private readonly cellId: string, - private readonly warn: (line: string) => void = (line) => console.warn(line), - schedule?: (callback: () => void, delayMs: number) => () => void - ) { - this.window = new AssignmentRejectionLogWindow({ - windowMs: PHONE_ACCEPT_LOG_WINDOW_MS, - onWindowClosed: ({ suppressed, sample }) => this.write(sample, suppressed), - schedule - }) - } - - // The one device read failed; the phone was closed 4503 and never took the invite path. - databaseError(cause: PhoneAcceptDatabaseCause): void { - this.record({ event: 'orca_relay_client_accept_db_error', cause }) - } - - // No seat, yet the row names this cell: the 4404 may be stale (a lost reserve ledger write). - missRowNamesHere(relayHostId: string): void { - this.record({ - event: 'orca_relay_client_miss_row_names_here', - relayHostIdDigest: relayHostLogDigest(relayHostId) - }) - } - - // The no-seat assignment read failed; the phone was closed 4409 to re-resolve. - missReadError(cause: PhoneAcceptDatabaseCause): void { - this.record({ event: 'orca_relay_client_miss_read_error', cause }) - } - - // A due renewal write failed; the confirm still answered the stored expiry. - renewalFailed(cause: PhoneAcceptDatabaseCause): void { - this.record({ event: 'orca_relay_resume_renewal_failed', cause }) - } - - private record(anomaly: PhoneAcceptAnomaly): void { - if (this.window.admit(anomaly.event, anomaly)) this.write(anomaly, 0) - } - - private write(anomaly: PhoneAcceptAnomaly, suppressed: number): void { - this.warn(JSON.stringify({ ...anomaly, cellId: this.cellId, ...(suppressed > 0 ? { suppressed } : {}) })) - } -} diff --git a/cloud/apps/relay/src/phone-connection-log.ts b/cloud/apps/relay/src/phone-connection-log.ts new file mode 100644 index 00000000000..52b8c3ace6f --- /dev/null +++ b/cloud/apps/relay/src/phone-connection-log.ts @@ -0,0 +1,86 @@ +import { AssignmentRejectionLogWindow } from './assignment-rejection-log-window.js' +import { relayHostLogDigest } from './relay-host-log-digest.js' + +// Phone-connection anomalies that repeat per dial (a stuck database, a lost ledger write, a +// half-open control): per kind, one line opens the window and one closing line carries the rest. +export const PHONE_CONNECTION_LOG_WINDOW_MS = 60_000 + +export type PhoneDatabaseCause = 'database_transient' | 'error' + +// What the cell knew of the desktop's control when a phone's attach deadline passed: a stale +// pong is a half-open control, a fresh one a slow or failing desktop data dial. +export type AttachDeadlineEvidence = { + credentialKind: 'invite' | 'resume' + msSinceLastPong: number + pingOutstanding: boolean + controlAgeMs: number + controlRttMs: number | null + pong: 'stale' | 'fresh' +} + +type PhoneConnectionAnomaly = + | { event: 'orca_relay_client_accept_db_error'; cause: PhoneDatabaseCause } + | { event: 'orca_relay_client_miss_row_names_here'; relayHostIdDigest: string } + | { event: 'orca_relay_client_miss_read_error'; cause: PhoneDatabaseCause } + | { event: 'orca_relay_resume_renewal_failed'; cause: PhoneDatabaseCause } + | ({ event: 'orca_relay_attach_deadline_offline'; relayHostIdDigest: string } & AttachDeadlineEvidence) + | { event: 'orca_relay_resume_confirm_failed'; code: string; phonePath: 'db' | 'memory' } + +export class PhoneConnectionLog { + private readonly window: AssignmentRejectionLogWindow + + constructor( + private readonly cellId: string, + private readonly warn: (line: string) => void = (line) => console.warn(line), + schedule?: (callback: () => void, delayMs: number) => () => void + ) { + this.window = new AssignmentRejectionLogWindow({ + windowMs: PHONE_CONNECTION_LOG_WINDOW_MS, + onWindowClosed: ({ suppressed, sample }) => this.write(sample, suppressed), + schedule + }) + } + + // The one device read failed; the phone was closed 4503 and never took the invite path. + databaseError(cause: PhoneDatabaseCause): void { + this.record(cause, { event: 'orca_relay_client_accept_db_error', cause }) + } + + // No seat, yet the row names this cell: the 4404 may be stale (a lost reserve ledger write). + missRowNamesHere(relayHostId: string): void { + this.record('', { + event: 'orca_relay_client_miss_row_names_here', + relayHostIdDigest: relayHostLogDigest(relayHostId) + }) + } + + // The no-seat assignment read failed; the phone was closed 4409 to re-resolve. + missReadError(cause: PhoneDatabaseCause): void { + this.record(cause, { event: 'orca_relay_client_miss_read_error', cause }) + } + + // A due renewal write failed; the confirm still answered the stored expiry. + renewalFailed(cause: PhoneDatabaseCause): void { + this.record(cause, { event: 'orca_relay_resume_renewal_failed', cause }) + } + + attachDeadline(relayHostId: string, evidence: AttachDeadlineEvidence): void { + this.record(`${evidence.credentialKind}:${evidence.pong}`, { + event: 'orca_relay_attach_deadline_offline', + relayHostIdDigest: relayHostLogDigest(relayHostId), + ...evidence + }) + } + + confirmFailed(code: string, phonePath: 'db' | 'memory'): void { + this.record(`${code}:${phonePath}`, { event: 'orca_relay_resume_confirm_failed', code, phonePath }) + } + + private record(kind: string, anomaly: PhoneConnectionAnomaly): void { + if (this.window.admit(`${anomaly.event}:${kind}`, anomaly)) this.write(anomaly, 0) + } + + private write(anomaly: PhoneConnectionAnomaly, suppressed: number): void { + this.warn(JSON.stringify({ ...anomaly, cellId: this.cellId, ...(suppressed > 0 ? { suppressed } : {}) })) + } +} diff --git a/cloud/apps/relay/src/relay-observability.test.ts b/cloud/apps/relay/src/relay-observability.test.ts index bb4ae848383..6d73c7871e7 100644 --- a/cloud/apps/relay/src/relay-observability.test.ts +++ b/cloud/apps/relay/src/relay-observability.test.ts @@ -534,6 +534,41 @@ describe('relay observability', () => { }) }) + it('counts the phone path, phone refusals by code and the step-6 failures per window', () => { + const entries: Array> = [] + const observability = new RelayObservability( + { role: 'cell', cellId: 'production-gce-c28', region: 'asia-east2' }, + (entry) => entries.push(entry) + ) + const stageMs = { assignment: 0, credential: 170, activity: 0, attach: 300, basis: 0 } + observability.recordClientAcceptCompleted({ totalMs: 470, stageMs, phonePath: 'memory' }) + observability.recordClientAcceptCompleted({ totalMs: 3_600, stageMs, phonePath: 'db' }) + observability.recordPhoneRejection(4401) + observability.recordPhoneRejection(4404) + observability.recordPhoneRejection(4404) + observability.recordPhoneAttachDeadline() + observability.recordPhoneAcceptDatabaseError() + observability.recordResumeConfirmFailure('reject-revoked') + observability.recordResumeRenewalFailure() + observability.flush({ ...counts, resumeAuditDropped: 3 }) + observability.flush(counts) + expect(entries[0]).toMatchObject({ + clientAcceptsByPhonePathDelta: { memory: 1, db: 1 }, + phoneRejectionsByCodeDelta: { '4401': 1, '4404': 2 }, + phoneAttachDeadlinesDelta: 1, + phoneAcceptDatabaseErrorsDelta: 1, + resumeConfirmFailuresByCodeDelta: { 'reject-revoked': 1 }, + resumeRenewalFailuresDelta: 1, + resumeAuditDropped: 3 + }) + expect(entries[1]).toMatchObject({ + phoneRejectionsByCodeDelta: {}, + phoneAttachDeadlinesDelta: 0, + phoneAcceptDatabaseErrorsDelta: 0, + resumeConfirmFailuresByCodeDelta: {} + }) + }) + it('summarises completed client accepts and control round trips per window', () => { const entries: Array> = [] const observability = new RelayObservability( @@ -576,6 +611,7 @@ describe('relay observability', () => { clientAcceptsAbandonedByStageDelta: {}, clientAcceptAbandonedMsMax: 0 }) + expect(entries[0]).toMatchObject({ clientAcceptsByPhonePathDelta: {} }) // An empty window publishes counts only: a zero percentile point is // indistinguishable from a real zero once Cloud Logging aggregates it. expect(entries[1]).toMatchObject({ clientAcceptCompletedDelta: 0, controlRttSamplesDelta: 0 }) diff --git a/cloud/apps/relay/src/relay-observability.ts b/cloud/apps/relay/src/relay-observability.ts index 2e976a1e694..27ab9178dc8 100644 --- a/cloud/apps/relay/src/relay-observability.ts +++ b/cloud/apps/relay/src/relay-observability.ts @@ -18,6 +18,8 @@ export type RelayRuntimeCounts = { splices: number pendingSplices: number queuedBytes: number + // Step 6: resume audit rows a memory cell dropped since boot; the watcher pages on any. + resumeAuditDropped?: number } export function observedRelayRequests(counts: RelayRuntimeCounts): number { @@ -105,6 +107,12 @@ export interface RelayRuntimeObserver { recordSpliceClose?(trigger: string): void recordClientAcceptAbandoned?(stage: RelayClientAcceptStage, elapsedMs: number): void recordClientAcceptCompleted?(sample: RelayClientAcceptSample): void + // Step 6: every phone refusal by close code, and the phone-path failures the watcher reads. + recordPhoneRejection?(code: number): void + recordPhoneAttachDeadline?(): void + recordPhoneAcceptDatabaseError?(): void + recordResumeConfirmFailure?(code: string): void + recordResumeRenewalFailure?(): void recordControlRtt?(rttMs: number): void recordHostPreAuth?(path: HostPreAuthPath, outcome: HostPreAuthOutcome, durationMs: number): void } @@ -163,6 +171,7 @@ export const RELAY_CLIENT_ACCEPT_TIMED_STAGES = [ export type RelayClientAcceptSample = { totalMs: number stageMs: Record + phonePath?: 'db' | 'memory' } type RelayMetricDeltas = { @@ -207,6 +216,12 @@ type RelayMetricDeltas = { clientAcceptAbandonedMsMax: number clientAcceptTotalsMs: number[] clientAcceptStageSamplesMs: Record + clientAcceptsByPhonePath: Record + phoneRejectionsByCode: Record + phoneAttachDeadlines: number + phoneAcceptDatabaseErrors: number + resumeConfirmFailuresByCode: Record + resumeRenewalFailures: number controlRttSamplesMs: number[] controlRttObserved: number controlRenewalLatenciesMs: number[] @@ -302,6 +317,12 @@ const emptyDeltas = (): RelayMetricDeltas => ({ attach: [], basis: [] }, + clientAcceptsByPhonePath: {}, + phoneRejectionsByCode: {}, + phoneAttachDeadlines: 0, + phoneAcceptDatabaseErrors: 0, + resumeConfirmFailuresByCode: {}, + resumeRenewalFailures: 0, controlRttSamplesMs: [], controlRttObserved: 0, controlRenewalLatenciesMs: [], @@ -550,12 +571,33 @@ export class RelayObservability implements RelayRuntimeObserver { } recordClientAcceptCompleted(sample: RelayClientAcceptSample): void { + if (sample.phonePath) increment(this.deltas.clientAcceptsByPhonePath, sample.phonePath) this.deltas.clientAcceptTotalsMs.push(sample.totalMs) for (const stage of RELAY_CLIENT_ACCEPT_TIMED_STAGES) { this.deltas.clientAcceptStageSamplesMs[stage].push(sample.stageMs[stage]) } } + recordPhoneRejection(code: number): void { + increment(this.deltas.phoneRejectionsByCode, String(code)) + } + + recordPhoneAttachDeadline(): void { + this.deltas.phoneAttachDeadlines += 1 + } + + recordPhoneAcceptDatabaseError(): void { + this.deltas.phoneAcceptDatabaseErrors += 1 + } + + recordResumeConfirmFailure(code: string): void { + increment(this.deltas.resumeConfirmFailuresByCode, code) + } + + recordResumeRenewalFailure(): void { + this.deltas.resumeRenewalFailures += 1 + } + recordControlRtt(rttMs: number): void { const observedBefore = this.deltas.controlRttObserved++ keepInReservoir( @@ -683,6 +725,13 @@ export class RelayObservability implements RelayRuntimeObserver { clientAcceptsAbandonedByStageDelta: deltas.clientAcceptsAbandonedByStage, clientAcceptAbandonedMsMax: roundMs(deltas.clientAcceptAbandonedMsMax), clientAcceptCompletedDelta: deltas.clientAcceptTotalsMs.length, + clientAcceptsByPhonePathDelta: deltas.clientAcceptsByPhonePath, + // Phone refusals by close code; attach deadlines are the 4404s sent with the control still up. + phoneRejectionsByCodeDelta: deltas.phoneRejectionsByCode, + phoneAttachDeadlinesDelta: deltas.phoneAttachDeadlines, + phoneAcceptDatabaseErrorsDelta: deltas.phoneAcceptDatabaseErrors, + resumeConfirmFailuresByCodeDelta: deltas.resumeConfirmFailuresByCode, + resumeRenewalFailuresDelta: deltas.resumeRenewalFailures, // Accepts are sparse: publishing a zero percentile for every empty window // would pin the p50 at 0 forever and collapse the p95 at low accept rates. ...(deltas.clientAcceptTotalsMs.length === 0 diff --git a/cloud/apps/relay/src/relay-server.ts b/cloud/apps/relay/src/relay-server.ts index 6c38c477e31..3824105810a 100644 --- a/cloud/apps/relay/src/relay-server.ts +++ b/cloud/apps/relay/src/relay-server.ts @@ -876,6 +876,10 @@ export function createRelayServer( dataSockets.close() store.resumeAudit.stop() }) + const resumeAuditDropped = (): number => { + const drops = store.resumeAudit.drops() + return drops.overflow + drops.aged + } const runtimeCounts = () => { const ledgerCounts = connectionLedger?.counts() return { @@ -883,6 +887,7 @@ export function createRelayServer( preAuthConnections, ...sessions.runtimeCounts(), queuedBytes: queuedBytes.current(), + ...(config.role === 'cell' ? { resumeAuditDropped: resumeAuditDropped() } : {}), ...(ledgerCounts ? { inFlightConnections: ledgerCounts.inFlightConnections,