From 7357cd66d230cbdedbb832c9ec20cba9b920b8ba Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Tue, 1 Sep 2026 17:18:49 +0200 Subject: [PATCH 1/6] feat(cloud-agent-next): add durable control-plane diagnostics --- services/cloud-agent-next/DEBUG.md | 25 + .../src/persistence/SandboxControl.ts | 605 ++++++++++++++---- .../sandbox-control/cloudflare-provider.ts | 31 +- .../src/sandbox-control/diagnostics.ts | 160 +++++ .../src/sandbox-control/lifecycle.test.ts | 90 ++- .../src/sandbox-control/log-routes.test.ts | 234 +++++++ .../src/sandbox-control/log-routes.ts | 164 +++++ .../sandbox-control/log-upload-grant.test.ts | 58 ++ .../src/sandbox-control/log-upload-grant.ts | 48 ++ .../src/sandbox-control/socket.ts | 82 ++- .../src/sandbox-control/vercel-provider.ts | 52 +- .../wrapper-launch-env.test.ts | 57 ++ .../src/sandbox-control/wrapper-launch-env.ts | 37 ++ .../src/sandbox-session/SandboxSession.ts | 158 +++-- services/cloud-agent-next/src/server.test.ts | 66 ++ services/cloud-agent-next/src/server.ts | 6 + .../src/shared/control-diagnostics.ts | 226 +++++++ .../src/shared/runtime-environment.ts | 3 + .../wrapper/src/control/diagnostics.test.ts | 360 +++++++++++ .../wrapper/src/control/diagnostics.ts | 302 +++++++++ .../wrapper/src/control/main.ts | 107 +++- .../src/control/sandbox-control-client.ts | 115 +++- .../control/sandbox-control-handlers.test.ts | 2 +- .../src/control/sandbox-control-handlers.ts | 47 ++ .../src/control/sandbox-control-runtime.ts | 59 +- .../wrapper/src/control/worktree-runtime.ts | 10 + 26 files changed, 2870 insertions(+), 234 deletions(-) create mode 100644 services/cloud-agent-next/src/sandbox-control/diagnostics.ts create mode 100644 services/cloud-agent-next/src/sandbox-control/log-routes.test.ts create mode 100644 services/cloud-agent-next/src/sandbox-control/log-routes.ts create mode 100644 services/cloud-agent-next/src/sandbox-control/log-upload-grant.test.ts create mode 100644 services/cloud-agent-next/src/sandbox-control/log-upload-grant.ts create mode 100644 services/cloud-agent-next/src/shared/control-diagnostics.ts create mode 100644 services/cloud-agent-next/wrapper/src/control/diagnostics.test.ts create mode 100644 services/cloud-agent-next/wrapper/src/control/diagnostics.ts diff --git a/services/cloud-agent-next/DEBUG.md b/services/cloud-agent-next/DEBUG.md index 57fdb2de00..86b5cb3f94 100644 --- a/services/cloud-agent-next/DEBUG.md +++ b/services/cloud-agent-next/DEBUG.md @@ -165,6 +165,31 @@ Wrangler will show the `PUT` requests. The uploaded archive contains: The internal `getWrapperLogs` path also discovers these sandbox-side files directly by scanning `/tmp/kilocode-wrapper-*.log` and the Kilo CLI log directory. +## Control-plane Diagnostics + +Control-plane (`workspace_*`) sessions use verbose structured wrapper diagnostics, not the legacy raw wrapper/Kilo tarball. Records include heartbeat attempts, feed freshness, control socket and request outcomes, event-send metadata, task phases, and retirement causes. They exclude prompts, assistant/tool content, raw errors, credentials, and URLs. + +The wrapper uploads JSON batches to the existing R2 bucket every five seconds and when a batch fills. Shutdown attempts a final flush within the existing shutdown deadline. R2 keys are: + +```text +logs/control////.json +``` + +`sandboxId` is the logical SandboxControl ID, not the `workspace_*` session ID or physical provider allocation name. Use Worker logs to correlate these IDs. Each allocation/wrapper has separate immutable batches; sort them by the batch `sequence` and record `timestamp`, not the random batch ID. Check `droppedRecords` and `droppedTerminalRecords` for buffer overflow or rejected diagnostic records. + +Internal API authentication is required to list or download these archives: + +```text +GET /internal/sandbox-logs/?cursor= +GET /internal/sandbox-logs//// +``` + +Listing returns at most 100 objects and a continuation cursor. Download paths omit the `.json` suffix. These reads use R2 only and work after the container disappears. The legacy `getWrapperLogs` live-file reader and tarball retrieval do not read these JSON archives. + +Worker/DO diagnostics remain in Cloudflare logs/Axiom, not these wrapper archives. Upload result markers on wrapper stderr distinguish HTTP rejection, network failure, timeout, and acceptance. An upload-only grant expires four hours after allocation launch and is not renewed; runtime credential revocation does not revoke it. Grant expiry does not delete archives. R2 retention remains governed by external bucket policy, not the session/report cleanup jobs. + +Uploads are best effort: an abrupt kill or network failure can lose unuploaded records. The buffer holds 512 records and each batch holds up to 128 records or 256 KiB. A recorded WebSocket send is a local handoff, not proof that a session DO applied the event; correlate it with the Worker forwarding and durable message-transition logs. + ## Interpreting Common States - Worker queueing succeeds, but no wrapper logs appear: diff --git a/services/cloud-agent-next/src/persistence/SandboxControl.ts b/services/cloud-agent-next/src/persistence/SandboxControl.ts index c5d2c6475a..47c8ebbbe0 100644 --- a/services/cloud-agent-next/src/persistence/SandboxControl.ts +++ b/services/cloud-agent-next/src/persistence/SandboxControl.ts @@ -20,13 +20,13 @@ import { getSandbox } from '@cloudflare/sandbox'; import { withTimeout } from '@kilocode/worker-utils'; import { z } from 'zod'; import type { Env } from '../types.js'; +import { resolveSecret } from '../auth.js'; import { getSandboxProvider, requiresContainmentSandbox, type SessionMetadata, } from './session-metadata.js'; import { getSandboxSessionStub } from '../sandbox-session/session-stub.js'; -import { logger } from '../logger.js'; import { createSandboxControlSocketHandler, type SandboxControlConnectionIdentity, @@ -125,7 +125,14 @@ import { type SessionCredentialGrant, } from '../sandbox-control/session-credentials.js'; import { parseControlPlaneCredential } from '../sandbox-control/managed-credential.js'; -import { withDORetry } from '../utils/do-retry.js'; +import { + diagnosticCause, + diagnosticConnection, + diagnosticEventType, + logControlDiagnostic, + withControlDORetry as withDORetry, + type ControlDiagnosticFields, +} from '../sandbox-control/diagnostics.js'; import type { ProviderAdapter, ProviderObservation, @@ -247,6 +254,17 @@ export class SandboxControl extends DurableObject { private readyConnectionId: string | null = null; private providerKind: AgentSandboxProvider = 'cloudflare'; private readonly sessionForwardChains = new Map>(); + private readonly forwarding = { + enqueued: 0, + settled: 0, + waiting: 0, + inFlight: 0, + highWater: 0, + dropped: 0, + notApplied: 0, + failed: 0, + }; + private lastAcceptedHeartbeat: { connectionId: string; at: number } | null = null; private credentialUpdates: Promise = Promise.resolve(); private provider: ProviderAdapter; private stopAttemptInFlight: { @@ -338,7 +356,7 @@ export class SandboxControl extends DurableObject { const authorized = await this.authorizeWrapper(request); if (!authorized) { - logger.withFields({ sandboxId: this.sandboxId }).warn('Sandbox control rejected credential'); + this.logDiagnostic('socket_auth', { result: 'rejected' }, 'warn'); return new Response('Unauthorized', { status: 401 }); } @@ -379,6 +397,20 @@ export class SandboxControl extends DurableObject { for (const id of dueDeadlines(deadlines, now)) { const before = await loadDeadlines(this.ctx.storage); if (before[id] === undefined || before[id] > now) continue; + this.logDiagnostic('deadline_fired', { + deadlineId: id, + deadlineAt: before[id], + latenessMs: Math.max(0, now - before[id]), + heartbeatDeadlineAt: before.heartbeatExpiry, + idleDeadlineAt: before.idleStop, + connectionState: this.connectionState(), + lastAcceptedHeartbeatAt: + this.lastAcceptedHeartbeat?.connectionId === this.activeConnection?.connectionId + ? this.lastAcceptedHeartbeat?.at + : undefined, + ...diagnosticConnection(this.activeConnection), + ...this.forwarding, + }); await this.appendLog(deadlineTransition(now, id, 'fired')); await this.handleDeadline(id); await this.ctx.storage.transaction(async () => { @@ -937,9 +969,17 @@ export class SandboxControl extends DurableObject { await this.ctx.storage.put(CREDENTIAL_HASH_KEY, credentialHash); await this.appendLog(credentialTransition(Date.now(), 'issued')); const provider = this.provider; + let phase: 'create' | 'launch' = 'create'; + let startedAt = Date.now(); + let timedOut = false; try { this.assertWorktreeAdmission(worktreeId); if (acquisition) assertAcquisitionDeadline(acquisition); + this.logDiagnostic('allocation_launch', { + allocationId: intent.intentId, + phase, + result: 'started', + }); const created = await withTimeout( provider.create({ ...intent, @@ -947,9 +987,19 @@ export class SandboxControl extends DurableObject { ...(networkPolicy ? { networkPolicy } : {}), }), DEADLINE_MS.startup, - 'Sandbox allocation timed out' + 'Sandbox allocation timed out', + () => { + timedOut = true; + } ); + this.logDiagnostic('allocation_launch', { + allocationId: intent.intentId, + phase, + result: 'providerRef' in created ? 'completed' : 'unresolved', + durationMs: Date.now() - startedAt, + }); if ('providerRef' in created) { + const launchEnv = await this.wrapperLaunchEnv(credential, intent.intentId); const current = await loadPhysicalRecord(this.ctx.storage); if (!sameAllocation(current, physical)) return currentStatus(); if (current.stopTombstone) { @@ -966,16 +1016,39 @@ export class SandboxControl extends DurableObject { } this.assertWorktreeAdmission(worktreeId); if (acquisition) assertAcquisitionDeadline(acquisition); + phase = 'launch'; + startedAt = Date.now(); + this.logDiagnostic('allocation_launch', { + allocationId: intent.intentId, + phase, + result: 'started', + }); await withTimeout( - provider.launch(created.providerRef, this.wrapperLaunchEnv(credential)), + provider.launch(created.providerRef, launchEnv), DEADLINE_MS.startup, - 'Sandbox wrapper launch timed out' + 'Sandbox wrapper launch timed out', + () => { + timedOut = true; + } ); + this.logDiagnostic('allocation_launch', { + allocationId: intent.intentId, + phase, + result: 'completed', + durationMs: Date.now() - startedAt, + }); } } catch { - logger - .withFields({ sandboxId: this.sandboxId }) - .warn('Sandbox allocation or launch failed'); + this.logDiagnostic( + 'allocation_launch', + { + result: timedOut ? 'timed_out' : 'failed', + phase, + durationMs: Date.now() - startedAt, + allocationId: physical.createIntent?.intentId, + }, + 'warn' + ); const current = await loadPhysicalRecord(this.ctx.storage); if ( sameAllocation(current, physical) && @@ -1742,6 +1815,10 @@ export class SandboxControl extends DurableObject { async recordStopAttempt(): Promise { const current = await loadPhysicalRecord(this.ctx.storage); if (this.stopAttemptInFlight && sameAllocation(this.stopAttemptInFlight.physical, current)) { + this.logDiagnostic('stop_coalesced', { + allocationId: current.createIntent?.intentId, + stopAttempts: current.stopTombstone?.attempts, + }); return this.stopAttemptInFlight.promise; } const pending = { physical: current, promise: this.performStopAttempt(current) }; @@ -1787,12 +1864,48 @@ export class SandboxControl extends DurableObject { private async stopCurrentProvider(physical: PhysicalRecord): Promise { let pending = this.providerStopInFlight; if (!pending || !sameAllocation(pending.physical, physical)) { + const startedAt = Date.now(); + const diagnostic = { + allocationId: physical.createIntent?.intentId, + wrapperInstanceId: physical.stopTombstone?.wrapperInstanceId, + stopAttempts: physical.stopTombstone?.attempts, + physicalState: physical.state, + cleanupAgeMs: physical.stopTombstone + ? startedAt - physical.stopTombstone.createdAt + : undefined, + }; + let timedOut = false; + this.logDiagnostic('provider_stop', { ...diagnostic, result: 'started' }); pending = { physical, promise: withTimeout( this.provider.stop(physical.providerRef, physical.createIntent), DEADLINE_MS.stopAttempt, - 'Sandbox stop attempt timed out' + 'Sandbox stop attempt timed out', + () => { + timedOut = true; + } + ).then( + result => { + this.logDiagnostic('provider_stop', { + ...diagnostic, + result, + durationMs: Date.now() - startedAt, + }); + return result; + }, + error => { + this.logDiagnostic( + 'provider_stop', + { + ...diagnostic, + result: timedOut ? 'timed_out' : 'failed', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } ), }; this.providerStopInFlight = pending; @@ -1805,7 +1918,6 @@ export class SandboxControl extends DurableObject { try { return (await pending.promise) === 'terminal'; } catch { - logger.withFields({ sandboxId: this.sandboxId }).warn('Sandbox stop attempt failed'); return false; } } @@ -1848,6 +1960,11 @@ export class SandboxControl extends DurableObject { return current; }); if (!target) return; + this.logDiagnostic('slow_reap', { + allocationId: target.createIntent?.intentId, + stopAttempts: target.stopTombstone?.attempts, + cleanupAgeMs: target.stopTombstone ? Date.now() - target.stopTombstone.createdAt : undefined, + }); const observed = await this.observeCurrentProvider(target); if (!sameAllocation(observed, physical) || !this.shouldSlowReap(observed)) return; const terminal = await this.stopCurrentProvider(observed); @@ -2108,12 +2225,27 @@ export class SandboxControl extends DurableObject { return billing; } - private wrapperLaunchEnv(credential: string): Record { - return buildControlWrapperLaunchEnv({ + private async wrapperLaunchEnv( + credential: string, + allocationId: string + ): Promise> { + const signingSecret = await withTimeout( + resolveSecret(this.env.NEXTAUTH_SECRET), + 1_000, + 'Diagnostic signing secret lookup timed out' + ).catch(() => null); + const launchEnv = buildControlWrapperLaunchEnv({ workerUrl: this.env.WORKER_URL, sandboxId: this.sandboxId, credential, + diagnostics: { allocationId, signingSecret }, + }); + this.logDiagnostic('wrapper_log_upload', { + allocationId, + configured: Boolean(launchEnv.CONTROL_LOG_UPLOAD_GRANT), + wrapperInstanceId: launchEnv.CONTROL_WRAPPER_INSTANCE_ID, }); + return launchEnv; } private matchesProviderReference(physical: PhysicalRecord, providerRef: string): boolean { @@ -2283,6 +2415,7 @@ export class SandboxControl extends DurableObject { this.activeConnection = identity; this.readyConnectionId = null; this.kiloReady = false; + this.logDiagnostic('handshake_committed', diagnosticConnection(identity)); this.socketHandler.closeProvisionalSockets(); } @@ -2318,68 +2451,134 @@ export class SandboxControl extends DurableObject { if (!this.isCurrentConnection(identity)) return; this.readyConnectionId = identity.connectionId; this.kiloReady = true; + this.logDiagnostic('wrapper_ready', { + ...diagnosticConnection(identity), + heartbeatDeadlineAt: now + DEADLINE_MS.heartbeatExpiry, + }); } private async onHeartbeat( payload: SandboxHeartbeatPayload, identity: SandboxControlConnectionIdentity ): Promise { - if (!this.isCurrentConnection(identity)) return; + const diagnostic = { + ...diagnosticConnection(identity), + reportedState: payload.state, + kiloReady: payload.kilo.ready, + reportedSessions: payload.sessions.length, + pendingMessages: payload.pendingMessages, + activeKiloSessions: payload.activeKiloSessions, + ...this.forwarding, + }; + if (!this.isCurrentConnection(identity)) { + this.logDiagnostic('heartbeat', { ...diagnostic, decision: 'stale_connection' }); + return; + } if (!payload.kilo.ready) { - logger - .withFields({ - sandboxId: this.sandboxId, - wrapperInstanceId: identity.wrapperInstanceId, - connectionId: identity.connectionId, + this.logDiagnostic( + 'heartbeat', + { + ...diagnostic, + decision: 'kilo_unhealthy', reason: payload.kilo.reason ?? 'unknown', - }) - .warn('Sandbox control received unhealthy heartbeat'); + }, + 'warn' + ); await this.quarantineConnection(identity, 'kilo_unhealthy'); return; } - if (!this.readyWrapperRuntime()) return; + if (!this.readyWrapperRuntime()) { + this.logDiagnostic('heartbeat', { ...diagnostic, decision: 'runtime_not_ready' }); + return; + } const now = Date.now(); - await this.ctx.storage.transaction(async () => { - const table = await loadRouteTable(this.ctx.storage); - if (!this.isCurrentConnection(identity)) return; - const reported = new Map(payload.sessions.map(session => [session.kiloSessionId, session])); - for (const route of table.values()) { - const report = reported.get(route.kiloSessionId) ?? { - state: 'idle' as const, - idleForMs: 0, - }; - const previousState = route.lastState; - const applied = applyReportedSessionState(table, route.kiloSessionId, report, now); - if (applied.changed) { - await this.appendLog( - sessionStateTransition(now, route.kiloSessionId, previousState, report.state) - ); + const applied = await this.ctx.storage + .transaction(async () => { + const table = await loadRouteTable(this.ctx.storage); + if (!this.isCurrentConnection(identity)) return; + const reported = new Map(payload.sessions.map(session => [session.kiloSessionId, session])); + let missingRoutes = 0; + let activeRoutes = 0; + let finalizingRoutes = 0; + let inputWaitingRoutes = 0; + for (const route of table.values()) { + const report = reported.get(route.kiloSessionId) ?? { + state: 'idle' as const, + idleForMs: 0, + }; + if (!reported.has(route.kiloSessionId)) missingRoutes++; + if (report.state === 'active') activeRoutes++; + if (report.state === 'finalizing') finalizingRoutes++; + if ('waitingOn' in report && report.waitingOn === 'input') inputWaitingRoutes++; + const previousState = route.lastState; + const applied = applyReportedSessionState(table, route.kiloSessionId, report, now); + if (applied.changed) { + await this.appendLog( + sessionStateTransition(now, route.kiloSessionId, previousState, report.state) + ); + } } - } - await saveRouteTable(this.ctx.storage, table); - let deadlines = armDeadline( - await loadDeadlines(this.ctx.storage), - 'heartbeatExpiry', - now + DEADLINE_MS.heartbeatExpiry - ); - if (payload.state !== 'idle' || (payload.pendingMessages ?? 0) > 0 || hasActiveWork(table)) { - deadlines = cancelDeadline(deadlines, 'idleStop'); - } else { - deadlines = armDeadline( - deadlines, - 'idleStop', - deadlines.idleStop ?? now + DEADLINE_MS.idleStop + await saveRouteTable(this.ctx.storage, table); + const previousDeadlines = await loadDeadlines(this.ctx.storage); + let deadlines = armDeadline( + previousDeadlines, + 'heartbeatExpiry', + now + DEADLINE_MS.heartbeatExpiry ); - } - await saveDeadlines(this.ctx.storage, deadlines); - await this.scheduleAlarm(deadlines); + if ( + payload.state !== 'idle' || + (payload.pendingMessages ?? 0) > 0 || + hasActiveWork(table) + ) { + deadlines = cancelDeadline(deadlines, 'idleStop'); + } else { + deadlines = armDeadline( + deadlines, + 'idleStop', + deadlines.idleStop ?? now + DEADLINE_MS.idleStop + ); + } + await saveDeadlines(this.ctx.storage, deadlines); + await this.scheduleAlarm(deadlines); + return { + routeCount: table.size, + missingRoutes, + activeRoutes, + finalizingRoutes, + inputWaitingRoutes, + heartbeatDeadlineAt: deadlines.heartbeatExpiry, + idleDeadlineAt: deadlines.idleStop ?? null, + idleDeadlineAction: + deadlines.idleStop === undefined + ? 'cancelled' + : previousDeadlines.idleStop === undefined + ? 'armed' + : 'retained', + }; + }) + .catch(error => { + this.logDiagnostic('heartbeat', { ...diagnostic, decision: 'apply_failed' }, 'warn'); + throw error; + }); + if (applied) this.lastAcceptedHeartbeat = { connectionId: identity.connectionId, at: now }; + this.logDiagnostic('heartbeat', { + ...diagnostic, + ...applied, + decision: applied ? 'accepted' : 'stale_during_apply', }); await this.renewProviderLease(identity); } private async renewProviderLease(identity: SandboxControlConnectionIdentity): Promise { const physical = await loadPhysicalRecord(this.ctx.storage); + const diagnostic = { + ...diagnosticConnection(identity), + allocationId: physical.createIntent?.intentId, + physicalState: physical.state, + hasTombstone: physical.stopTombstone !== null, + requestedLeaseMs: leaseAtLeastMs(), + }; if ( !this.isCurrentConnection(identity) || !this.readyWrapperRuntime() || @@ -2387,16 +2586,36 @@ export class SandboxControl extends DurableObject { physical.stopTombstone !== null || physical.providerRef === null ) { + this.logDiagnostic('lease', { ...diagnostic, result: 'skipped_authority' }); return; } + const startedAt = Date.now(); + let timedOut = false; + this.logDiagnostic('lease', { ...diagnostic, result: 'started' }); try { await withTimeout( this.provider.ensureLeaseAtLeast(physical.providerRef, leaseAtLeastMs()), DEADLINE_MS.stopAttempt, - 'Sandbox lease renewal timed out' + 'Sandbox lease renewal timed out', + () => { + timedOut = true; + } ); + this.logDiagnostic('lease', { + ...diagnostic, + result: 'completed', + durationMs: Date.now() - startedAt, + }); } catch { - logger.withFields({ sandboxId: this.sandboxId }).warn('Provider lease renewal failed'); + this.logDiagnostic( + 'lease', + { + ...diagnostic, + result: timedOut ? 'timed_out' : 'failed', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); } } @@ -2405,15 +2624,26 @@ export class SandboxControl extends DurableObject { payload: SessionEventPayload, connection: SandboxControlConnectionIdentity ): Promise { - if (!this.isCurrentConnection(connection)) return; + const diagnostic = { + ...diagnosticConnection(connection), + eventType: diagnosticEventType(payload.type), + }; + if (!this.isCurrentConnection(connection)) { + this.recordForwardDrop('stale_before_enqueue', diagnostic); + return; + } if (!identity) { - logger - .withFields({ sandboxId: this.sandboxId, eventType: payload.type }) - .warn('session.event missing identity'); + this.recordForwardDrop('missing_identity', diagnostic); return; } - await this.forwardRoutedSessionFrame(identity, payload.type, connection, route => - this.forwardSessionEvent(route, identity, payload, connection) + await this.forwardRoutedSessionFrame(identity, payload.type, connection, (route, fields) => + this.forwardSessionFrame(route, connection, fields, 'receiveSandboxControlEvent', stub => + stub.receiveSandboxControlEvent({ + identity, + payload, + wrapperInstanceId: connection.wrapperInstanceId, + }) + ) ); } @@ -2422,15 +2652,35 @@ export class SandboxControl extends DurableObject { payload: SessionPreparingPayload, connection: SandboxControlConnectionIdentity ): Promise { - if (!this.isCurrentConnection(connection)) return; + const diagnostic = { + ...diagnosticConnection(connection), + eventType: 'session.preparing', + }; + if (!this.isCurrentConnection(connection)) { + this.recordForwardDrop('stale_before_enqueue', diagnostic); + return; + } if (!identity) { - logger - .withFields({ sandboxId: this.sandboxId, eventType: 'session.preparing' }) - .warn('session.event missing identity'); + this.recordForwardDrop('missing_identity', diagnostic); return; } - await this.forwardRoutedSessionFrame(identity, 'session.preparing', connection, route => - this.forwardSessionPreparing(route, identity, payload, connection) + await this.forwardRoutedSessionFrame( + identity, + 'session.preparing', + connection, + (route, fields) => + this.forwardSessionFrame( + route, + connection, + fields, + 'receiveSandboxControlPreparing', + stub => + stub.receiveSandboxControlPreparing({ + identity, + payload, + wrapperInstanceId: connection.wrapperInstanceId, + }) + ) ); } @@ -2438,86 +2688,136 @@ export class SandboxControl extends DurableObject { identity: SessionEventIdentity, eventType: string, connection: SandboxControlConnectionIdentity, - forward: (route: SessionRoute) => Promise + forward: (route: SessionRoute, diagnostic: ControlDiagnosticFields) => Promise ): Promise { + const diagnostic = { + ...diagnosticConnection(connection), + eventType: diagnosticEventType(eventType), + }; const table = await loadRouteTable(this.ctx.storage); - if (!this.isCurrentConnection(connection)) return; + if (!this.isCurrentConnection(connection)) { + this.recordForwardDrop('stale_before_enqueue', diagnostic); + return; + } const route = resolveSessionEventRoute(table, identity); if (!route) { - logger - .withFields({ - sandboxId: this.sandboxId, - eventType, - directory: identity.directory, - kiloSessionId: identity.kiloSessionId, - rootKiloSessionId: identity.rootKiloSessionId, - }) - .warn('session.event unroutable'); + this.recordForwardDrop('unroutable', { ...diagnostic, routeCount: table.size }); return; } + const queuedAt = Date.now(); + this.forwarding.enqueued++; + this.forwarding.waiting++; + this.forwarding.highWater = Math.max( + this.forwarding.highWater, + this.forwarding.waiting + this.forwarding.inFlight + ); + const fields = { + ...diagnostic, + sessionId: route.sessionId, + forwardSequence: this.forwarding.enqueued, + queuedAt, + }; + this.logDiagnostic('forward_enqueued', { ...fields, ...this.forwarding }); const previous = this.sessionForwardChains.get(route.sessionId) ?? Promise.resolve(); const next = previous .catch(() => undefined) - .then(() => (this.isCurrentConnection(connection) ? forward(route) : undefined)); + .then(async () => { + this.forwarding.waiting--; + this.forwarding.inFlight++; + this.logDiagnostic('forward_started', { + ...fields, + queueWaitMs: Date.now() - queuedAt, + ...this.forwarding, + }); + try { + if (this.isCurrentConnection(connection)) await forward(route, fields); + else this.recordForwardDrop('stale_before_send', fields); + } finally { + this.forwarding.inFlight--; + this.forwarding.settled++; + this.logDiagnostic('forward_settled', { + ...fields, + totalForwardMs: Date.now() - queuedAt, + ...this.forwarding, + }); + } + }); this.sessionForwardChains.set(route.sessionId, next); this.ctx.waitUntil(next); } - private async forwardSessionEvent( - route: SessionRoute, - identity: SessionEventIdentity, - payload: SessionEventPayload, - connection: SandboxControlConnectionIdentity - ): Promise { - if (!this.isCurrentConnection(connection)) return; - const delivered = await withTimeout( - withDORetry( - () => getSandboxSessionStub(this.env, route.ownerId, route.sessionId), - stub => - this.isCurrentConnection(connection) - ? stub.receiveSandboxControlEvent({ - identity, - payload, - wrapperInstanceId: connection.wrapperInstanceId, - }) - : Promise.resolve({ applied: true }), - 'receiveSandboxControlEvent' - ), - DEADLINE_MS.stopAttempt, - 'Sandbox event forwarding timed out' - ).then( - () => true, - () => false - ); - if (!delivered) await this.quarantineForwardingFailure(route, connection); + private recordForwardDrop(reason: string, fields: ControlDiagnosticFields): void { + this.forwarding.dropped++; + this.logDiagnostic('forward_dropped', { ...fields, reason, ...this.forwarding }); } - private async forwardSessionPreparing( + private async forwardSessionFrame( route: SessionRoute, - identity: SessionEventIdentity, - payload: SessionPreparingPayload, - connection: SandboxControlConnectionIdentity + connection: SandboxControlConnectionIdentity, + diagnostic: ControlDiagnosticFields, + operation: 'receiveSandboxControlEvent' | 'receiveSandboxControlPreparing', + send: (stub: ReturnType) => Promise<{ applied: boolean }> ): Promise { - if (!this.isCurrentConnection(connection)) return; + if (!this.isCurrentConnection(connection)) { + this.recordForwardDrop('stale_before_send', diagnostic); + return; + } + const startedAt = Date.now(); + let timedOut = false; + let skipped = false; + let attempts = 0; const delivered = await withTimeout( withDORetry( () => getSandboxSessionStub(this.env, route.ownerId, route.sessionId), - stub => - this.isCurrentConnection(connection) - ? stub.receiveSandboxControlPreparing({ - identity, - payload, - wrapperInstanceId: connection.wrapperInstanceId, - }) - : Promise.resolve({ applied: true }), - 'receiveSandboxControlPreparing' + stub => { + skipped = !this.isCurrentConnection(connection); + if (skipped) { + this.recordForwardDrop('stale_retry', diagnostic); + return Promise.resolve({ applied: true }); + } + attempts++; + return send(stub); + }, + operation ), DEADLINE_MS.stopAttempt, - 'Sandbox preparation forwarding timed out' + operation === 'receiveSandboxControlEvent' + ? 'Sandbox event forwarding timed out' + : 'Sandbox preparation forwarding timed out', + () => { + timedOut = true; + } ).then( - () => true, - () => false + result => { + if (!skipped && result?.applied === false) this.forwarding.notApplied++; + this.logDiagnostic('forward_result', { + ...diagnostic, + operation, + attempts, + result: skipped ? 'skipped' : 'delivered', + applied: skipped ? undefined : result?.applied, + rpcWaitMs: Date.now() - startedAt, + ...this.forwarding, + }); + return true; + }, + () => { + this.forwarding.failed++; + this.logDiagnostic( + 'forward_result', + { + ...diagnostic, + operation, + attempts, + result: timedOut ? 'timed_out' : 'failed', + rpcWaitMs: Date.now() - startedAt, + ...this.forwarding, + }, + 'warn' + ); + return false; + } ); if (!delivered) await this.quarantineForwardingFailure(route, connection); } @@ -2534,8 +2834,13 @@ export class SandboxControl extends DurableObject { current.ownerId !== route.ownerId || current.directory !== route.directory || current.kiloSessionId !== route.kiloSessionId - ) + ) { + this.logDiagnostic('forward_quarantine_skipped', { + sessionId: route.sessionId, + ...diagnosticConnection(connection), + }); return; + } await this.quarantineConnection(connection, 'session_delivery_failed'); } @@ -2559,6 +2864,12 @@ export class SandboxControl extends DurableObject { physical.state === 'stopped' || physical.stopTombstone ) { + this.logDiagnostic('quarantine_skipped', { + ...diagnosticConnection(identity), + cause: diagnosticCause(reason), + physicalState: physical.state, + hasTombstone: physical.stopTombstone !== null, + }); return; } const next = beginStop(physical, reason, Date.now(), identity.wrapperInstanceId); @@ -2575,18 +2886,34 @@ export class SandboxControl extends DurableObject { if (shouldRearmReconciliation(physical.state)) { await this.rearmReconciliation(physical); } + const startedAt = Date.now(); + let timedOut = false; + let failed = false; let result: ProviderObservation; try { result = await withTimeout( this.provider.observe(physical.providerRef, physical.createIntent), DEADLINE_MS.stopAttempt, - 'Sandbox observation timed out' + 'Sandbox observation timed out', + () => { + timedOut = true; + } ); } catch { + failed = true; result = { status: 'unknown' }; } const current = await loadPhysicalRecord(this.ctx.storage); - if (!sameAllocation(current, physical) || current.state === 'stopped') return current; + const stale = !sameAllocation(current, physical) || current.state === 'stopped'; + this.logDiagnostic('provider_observation', { + allocationId: physical.createIntent?.intentId, + physicalState: physical.state, + observation: result.status, + result: timedOut ? 'timed_out' : failed ? 'failed' : 'completed', + stale, + durationMs: Date.now() - startedAt, + }); + if (stale) return current; if (result.providerRef && current.providerRef === null) { await savePhysicalRecord(this.ctx.storage, { ...current, providerRef: result.providerRef }); } @@ -2804,6 +3131,18 @@ export class SandboxControl extends DurableObject { const unavailable = to.stopTombstone !== null || (to.state !== 'creating' && to.state !== 'running'); await this.ctx.storage.transaction(() => this.persistPhysicalState(from, to, cause)); + this.logDiagnostic('physical_committed', { + allocationId: to.createIntent?.intentId ?? from.createIntent?.intentId, + wrapperInstanceId, + fromState: from.state, + toState: to.state, + cause: diagnosticCause(cause), + stopCause: to.stopTombstone ? diagnosticCause(to.stopTombstone.reason) : undefined, + stopAttempts: to.stopTombstone?.attempts ?? from.stopTombstone?.attempts, + cleanupAgeMs: from.stopTombstone ? Date.now() - from.stopTombstone.createdAt : undefined, + hasTombstone: to.stopTombstone !== null, + ...this.forwarding, + }); if (!unavailable) return; this.activeConnection = null; this.readyConnectionId = null; @@ -2991,6 +3330,18 @@ export class SandboxControl extends DurableObject { await saveTransitionLog(this.ctx.storage, appendTransition(log, row)); } + private logDiagnostic( + event: string, + fields: ControlDiagnosticFields, + level: 'info' | 'warn' = 'info' + ): void { + logControlDiagnostic( + event, + { sandboxId: this.sandboxId, provider: this.providerKind, ...fields }, + level + ); + } + private async requireOwner(): Promise { const ownerId = await this.readOwner(); if (ownerId === null) throw new Error('Sandbox owner is not initialized'); diff --git a/services/cloud-agent-next/src/sandbox-control/cloudflare-provider.ts b/services/cloud-agent-next/src/sandbox-control/cloudflare-provider.ts index 8cb21a4e7c..8bf6d8a604 100644 --- a/services/cloud-agent-next/src/sandbox-control/cloudflare-provider.ts +++ b/services/cloud-agent-next/src/sandbox-control/cloudflare-provider.ts @@ -10,6 +10,7 @@ import { AgentSandboxUnavailableError } from '../agent-sandbox/protocol.js'; import { MANAGED_SCM_OUTBOUND_HANDLER } from '../sandbox-id.js'; import type { SandboxInstance } from '../types.js'; import { DEADLINE_MS } from './deadlines.js'; +import { logControlDiagnostic } from './diagnostics.js'; import type { CreateIntent } from './physical-lifecycle.js'; import type { ProviderAdapter, ProviderCreateIntent } from './provider.js'; @@ -142,16 +143,42 @@ export function createCloudflareProviderAdapter(deps: { }, async stop(ref, intent) { const parsed = decodeOwnedProviderRef(resolveProviderRef(ref, intent)); - if (!parsed) return 'retryable'; + const diagnostic = { provider: 'cloudflare', allocationName: deps.sandboxId }; + if (!parsed) { + logControlDiagnostic('native_stop', { ...diagnostic, result: 'invalid_reference' }); + return 'retryable'; + } + const startedAt = Date.now(); + logControlDiagnostic('native_stop', { ...diagnostic, result: 'started' }); try { await deps.destroy(parsed.sandboxId, { containment: parsed.containment }); + logControlDiagnostic('native_stop', { + ...diagnostic, + result: 'terminal', + durationMs: Date.now() - startedAt, + }); return 'terminal'; } catch { + logControlDiagnostic( + 'native_stop', + { + ...diagnostic, + result: 'retryable', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); return 'retryable'; } }, - async ensureLeaseAtLeast(ref, _ms) { + async ensureLeaseAtLeast(ref, ms) { const parsed = decodeOwnedProviderRef(ref); + logControlDiagnostic('native_lease', { + provider: 'cloudflare', + allocationName: deps.sandboxId, + requestedLeaseMs: ms, + action: parsed === null ? 'invalid_reference' : 'activity_timeout_renewal', + }); if (parsed === null) return; return deps .getSandbox(parsed.sandboxId, { containment: parsed.containment }) diff --git a/services/cloud-agent-next/src/sandbox-control/diagnostics.ts b/services/cloud-agent-next/src/sandbox-control/diagnostics.ts new file mode 100644 index 0000000000..b411ccb409 --- /dev/null +++ b/services/cloud-agent-next/src/sandbox-control/diagnostics.ts @@ -0,0 +1,160 @@ +import { withDORetry } from '@kilocode/worker-utils'; +import { logger } from '../logger.js'; + +export type ControlDiagnosticFields = Record; + +const EVENT_TYPES = new Set([ + 'sandbox.ready', + 'sandbox.heartbeat', + 'session.event', + 'session.preparing', + 'session.message.outcome', + 'session.status', + 'session.updated', + 'session.created', + 'session.deleted', + 'session.error', + 'session.idle', + 'session.turn.close', + 'message.updated', + 'message.removed', + 'message.part.updated', + 'message.part.delta', + 'message.part.removed', + 'question.asked', + 'question.replied', + 'question.rejected', + 'permission.asked', + 'permission.replied', +]); + +const CAUSES = new Set([ + 'idle', + 'heartbeat_expired', + 'kilo_unhealthy', + 'control_replaced', + 'control_disconnected', + 'session_delivery_failed', + 'environment_failed', + 'environment_stopped', + 'provider_unknown', + 'runtime_unhealthy', + 'preparation_interrupted', + 'preparation_timeout', + 'attach_exhausted', + 'prompt_exhausted', + 'credential_containment_unavailable', + 'demand', + 'terminal', + 'failed', + 'recovered', + 'hello', + 'instance confirmed', + 'stop attempt', + 'stop retries exhausted', + 'observe:active', + 'observe:terminal', + 'observe:unknown', +]); + +export function diagnosticEventType(value: string): string { + return EVENT_TYPES.has(value) ? value : 'other'; +} + +export function diagnosticCause(value: string): string { + return CAUSES.has(value) ? value.replaceAll(' ', '_') : 'other'; +} + +export function logControlDiagnostic( + event: string, + fields: ControlDiagnosticFields, + level: 'info' | 'warn' = 'info' +): void { + try { + const bounded: ControlDiagnosticFields = {}; + for (const [key, value] of Object.entries(fields).slice(0, 48)) { + if (!/^[a-zA-Z][a-zA-Z0-9]{0,63}$/.test(key)) continue; + if (typeof value === 'string') { + bounded[key] = /^[a-zA-Z0-9_.:-]{1,128}$/.test(value) ? value : 'redacted'; + } else if (typeof value === 'number') { + bounded[key] = Number.isFinite(value) + ? Math.max(-Number.MAX_SAFE_INTEGER, Math.min(Number.MAX_SAFE_INTEGER, value)) + : null; + } else if (typeof value === 'boolean' || value === null) { + bounded[key] = value; + } + } + const scoped = logger.withFields({ + ...bounded, + logTag: 'sandbox_control', + diagnosticEvent: /^[a-z_]{1,64}$/.test(event) ? event : 'unknown', + }); + scoped[level]('Sandbox control diagnostic'); + } catch { + return; + } +} + +export function diagnosticConnection( + identity?: { + connectionId: string; + wrapperInstanceId?: string; + } | null +): ControlDiagnosticFields { + return { + connectionId: identity?.connectionId, + wrapperInstanceId: identity?.wrapperInstanceId, + }; +} + +export function withControlDORetry( + getStub: () => TStub, + operation: (stub: TStub) => Promise, + operationName: string +): Promise { + const logRetry = (_message: unknown, fields: unknown) => { + try { + logControlDiagnostic( + 'rpc_retry', + { + operation: operationName, + attempt: + typeof fields === 'object' && + fields !== null && + 'attempt' in fields && + typeof fields.attempt === 'number' + ? fields.attempt + : undefined, + attempts: + typeof fields === 'object' && + fields !== null && + 'attempts' in fields && + typeof fields.attempts === 'number' + ? fields.attempts + : undefined, + backoffMs: + typeof fields === 'object' && + fields !== null && + 'backoffMs' in fields && + typeof fields.backoffMs === 'number' + ? fields.backoffMs + : undefined, + retryable: + typeof fields === 'object' && + fields !== null && + 'retryable' in fields && + typeof fields.retryable === 'boolean' + ? fields.retryable + : undefined, + }, + 'warn' + ); + } catch { + return; + } + }; + return withDORetry(getStub, operation, operationName, undefined, { + warn: logRetry, + error: logRetry, + }); +} diff --git a/services/cloud-agent-next/src/sandbox-control/lifecycle.test.ts b/services/cloud-agent-next/src/sandbox-control/lifecycle.test.ts index 5bf5ac83ee..a9e86607e6 100644 --- a/services/cloud-agent-next/src/sandbox-control/lifecycle.test.ts +++ b/services/cloud-agent-next/src/sandbox-control/lifecycle.test.ts @@ -23,6 +23,7 @@ import { decodeCloudflareProviderRef } from './cloudflare-provider.js'; import { WORKTREE_CREDENTIAL_CONTAINMENT } from './physical-lifecycle.js'; import { parseSessionMetadata } from '../persistence/session-metadata.js'; import { logger } from '../logger.js'; +import { validateControlLogUploadGrant } from './log-upload-grant.js'; const mocks = vi.hoisted(() => ({ getSandbox: vi.fn(), @@ -688,6 +689,76 @@ describe('SandboxControl lifecycle boundaries', () => { } ); + it('launches the wrapper with an upload-only grant scoped to its physical allocation', async () => { + const secret = 'test-log-upload-signing-secret'; + let launchEnv: Record | undefined; + const h = await harness({ + env: { NEXTAUTH_SECRET: { get: async () => secret } }, + configureAllocation: runtime => { + runtime.startProcess.mockImplementation( + async (_command: string, options: { env: Record }) => { + launchEnv = options.env; + return { id: 'proc_1' }; + } + ); + }, + }); + await h.create(); + const physical = await h.control.getPhysicalRecord(); + expect(launchEnv).toBeDefined(); + if (!launchEnv) throw new Error('Wrapper was not launched'); + expect( + validateControlLogUploadGrant(`Bearer ${launchEnv.CONTROL_LOG_UPLOAD_GRANT}`, secret) + ).toMatchObject({ + sandboxId: SANDBOX_ID, + allocationId: physical.createIntent?.intentId, + wrapperInstanceId: launchEnv.CONTROL_WRAPPER_INSTANCE_ID, + }); + expect(launchEnv.CONTROL_LOG_UPLOAD_URL).toBe( + `https://example.test/sandbox-logs/${SANDBOX_ID}/${physical.createIntent?.intentId}/${launchEnv.CONTROL_WRAPPER_INSTANCE_ID}` + ); + expect(Object.values(launchEnv)).not.toContain(secret); + }); + + it('launches without diagnostic credentials when the signing secret lookup stalls', async () => { + const lookup = deferred(); + const entered = deferred(); + const launches: Record[] = []; + const h = await harness({ + env: { + NEXTAUTH_SECRET: { + get: () => { + entered.resolve(); + return lookup.promise; + }, + }, + }, + configureAllocation: runtime => { + runtime.startProcess.mockImplementation( + async (_command: string, options: { env: Record }) => { + launches.push(options.env); + return { id: 'proc_1' }; + } + ); + }, + }); + const creating = h.create(); + await entered.promise; + try { + await vi.advanceTimersByTimeAsync(1_000); + expect(launches).toHaveLength(1); + expect(launches[0]).toMatchObject({ SANDBOX_CONTROL_CREDENTIAL: expect.any(String) }); + expect(launches[0]).not.toHaveProperty('CONTROL_LOG_UPLOAD_GRANT'); + expect(launches[0]).not.toHaveProperty('CONTROL_LOG_UPLOAD_URL'); + await expect(creating).resolves.toMatchObject({ physical: 'running' }); + } finally { + lookup.resolve('late-test-signing-secret'); + await creating; + } + expect(launches).toHaveLength(1); + expect(launches[0]).not.toHaveProperty('CONTROL_LOG_UPLOAD_GRANT'); + }); + it('binds concurrent acquisition replays to one allocation before provider I/O', async () => { const acquisition = { id: 'attempt_a', deadlineAt: Date.now() + SESSION_DELIVERY_TIMEOUT_MS }; const h = await harness({ @@ -1805,15 +1876,18 @@ describe('SandboxControl lifecycle boundaries', () => { }); expect(warn).not.toHaveBeenCalled(); await h.hooks.onHeartbeat?.(payload, identity); - expect(fields).toHaveBeenCalledExactlyOnceWith({ - sandboxId: SANDBOX_ID, - wrapperInstanceId: identity.wrapperInstanceId, - connectionId: identity.connectionId, - reason: reason ?? 'unknown', - }); - expect(warn).toHaveBeenCalledExactlyOnceWith( - 'Sandbox control received unhealthy heartbeat' + expect(fields).toHaveBeenCalledWith( + expect.objectContaining({ + sandboxId: SANDBOX_ID, + wrapperInstanceId: identity.wrapperInstanceId, + connectionId: identity.connectionId, + reason: reason ?? 'unknown', + logTag: 'sandbox_control', + diagnosticEvent: 'heartbeat', + decision: 'kilo_unhealthy', + }) ); + expect(warn).toHaveBeenCalledExactlyOnceWith('Sandbox control diagnostic'); await h.flush(); expect(runtime?.state.running).toBe(false); expect(h.session.failWaitingMessages).toHaveBeenCalledWith( diff --git a/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts b/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts new file mode 100644 index 0000000000..d062781e83 --- /dev/null +++ b/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts @@ -0,0 +1,234 @@ +import { describe, expect, it, vi } from 'vitest'; +import { Hono } from 'hono'; +import type { HonoContext } from '../hono-context.js'; +import type { Env } from '../types.js'; +import { CONTROL_LOG_MAX_BATCH_BYTES } from '../shared/control-diagnostics.js'; +import { mintControlLogUploadGrant } from './log-upload-grant.js'; +import { registerControlLogRoutes } from './log-routes.js'; + +const secret = 'test-log-signing-secret'; +const identity = { + sandboxId: 'sandbox_test', + allocationId: 'allocation_test', + wrapperInstanceId: '0fce125c-54a3-4143-b503-b7775c4d2135', +}; +const batchId = '5886f962-cc33-43f7-bd94-a31c0ed6c13b'; +const suffix = `${identity.sandboxId}/${identity.allocationId}/${identity.wrapperInstanceId}/${batchId}`; +const batch = { + version: 1, + sequence: 0, + droppedRecords: 0, + records: [{ timestamp: 100, event: 'wrapper.lifecycle', fields: { phase: 'starting' } }], +}; + +function fixture() { + const objects = new Map(); + const put = vi.fn(async (key: string, body: string, options: R2PutOptions) => { + expect(options.onlyIf).toEqual({ etagDoesNotMatch: '*' }); + if (objects.has(key)) return null; + objects.set(key, { body, sequence: options.customMetadata?.sequence ?? '' }); + return { key }; + }); + const get = vi.fn(async (key: string) => { + const object = objects.get(key); + return object ? { body: new Response(object.body).body } : null; + }); + const list = vi.fn(async (options: R2ListOptions) => ({ + objects: [...objects] + .filter(([key]) => key.startsWith(options.prefix ?? '')) + .map(([key, value]) => ({ + key, + size: value.body.length, + uploaded: new Date(1000), + customMetadata: { sequence: value.sequence }, + })), + truncated: false, + })); + const env = { NEXTAUTH_SECRET: secret, R2_BUCKET: { put, get, list } } as unknown as Env; + const app = new Hono(); + registerControlLogRoutes(app, c => + c.req.header('x-internal-api-key') === 'internal-secret' + ? null + : new Response('Unauthorized', { status: 401 }) + ); + const request = (path: string, init?: RequestInit) => + app.request(`http://worker.test${path}`, init, env); + const upload = ( + body: unknown = batch, + path = suffix, + token = mintControlLogUploadGrant(identity, secret) + ) => + request(`/sandbox-logs/${path}`, { + method: 'PUT', + headers: { Authorization: `Bearer ${token}`, 'Content-Type': 'application/json' }, + body: JSON.stringify(body), + }); + return { request, upload, objects, put, get, list }; +} + +describe('control log routes', () => { + it('stores validated immutable batches and retrieves them without any provider or DO binding', async () => { + const f = fixture(); + expect((await f.upload()).status).toBe(204); + const key = `logs/control/${suffix}.json`; + expect(JSON.parse(f.objects.get(key)!.body)).toEqual(batch); + expect((await f.upload({ ...batch, sequence: 42 })).status).toBe(204); + expect(JSON.parse(f.objects.get(key)!.body).sequence).toBe(0); + const response = await f.request(`/internal/sandbox-logs/${suffix}`, { + headers: { 'x-internal-api-key': 'internal-secret' }, + }); + expect(response.status).toBe(200); + expect(response.headers.get('Cache-Control')).toBe('no-store'); + expect(await response.json()).toEqual(batch); + const listing = await f.request(`/internal/sandbox-logs/${identity.sandboxId}`, { + headers: { 'x-internal-api-key': 'internal-secret' }, + }); + expect(await listing.json()).toMatchObject({ objects: [{ key, sequence: '0' }], cursor: null }); + }); + + it('rejects cross-allocation, cross-wrapper and cross-sandbox writes', async () => { + const f = fixture(); + for (const path of [ + suffix.replace('sandbox_test', 'sandbox_other'), + suffix.replace('allocation_test', 'allocation_other'), + suffix.replace(identity.wrapperInstanceId, '2b6e33c0-20f8-4676-ad18-eedc478b161d'), + ]) + expect((await f.upload(batch, path)).status).toBe(403); + expect(f.put).not.toHaveBeenCalled(); + }); + + it('rejects raw control credentials and unauthenticated retrieval', async () => { + const f = fixture(); + expect((await f.upload(batch, suffix, 'raw-control-credential')).status).toBe(401); + expect((await f.request(`/internal/sandbox-logs/${suffix}`)).status).toBe(401); + expect((await f.request(`/internal/sandbox-logs/${identity.sandboxId}`)).status).toBe(401); + expect(f.put).not.toHaveBeenCalled(); + expect(f.get).not.toHaveBeenCalled(); + expect(f.list).not.toHaveBeenCalled(); + }); + + it.each([ + { ...batch, secret: 'private' }, + { ...batch, records: [{ timestamp: 100, event: 'raw.error', fields: { phase: 'failed' } }] }, + { + ...batch, + records: [ + { + timestamp: 100, + event: 'wrapper.lifecycle', + fields: { phase: 'failed', message: 'secret' }, + }, + ], + }, + { + ...batch, + records: [ + { + timestamp: 100, + event: 'session.task', + fields: { phase: 'started', sessionId: '/private/path' }, + }, + ], + }, + { ...batch, records: [] }, + ])('rejects non-allowlisted bodies before R2: %j', async body => { + const f = fixture(); + expect((await f.upload(body)).status).toBe(400); + expect(f.put).not.toHaveBeenCalled(); + }); + + it('enforces actual streamed bytes with missing or misleading Content-Length', async () => { + const f = fixture(); + for (const length of [undefined, '1']) { + let cancelled = false; + const body = new ReadableStream({ + pull(controller) { + controller.enqueue(new Uint8Array(64 * 1024)); + }, + cancel() { + cancelled = true; + }, + }); + const headers = new Headers({ + Authorization: `Bearer ${mintControlLogUploadGrant(identity, secret)}`, + 'Content-Type': 'application/json', + }); + if (length) headers.set('Content-Length', length); + const init: RequestInit & { duplex: string } = { + method: 'PUT', + headers, + body, + duplex: 'half', + }; + expect((await f.request(`/sandbox-logs/${suffix}`, init)).status).toBe(413); + expect(cancelled).toBe(true); + } + expect(f.put).not.toHaveBeenCalled(); + }); + + it('rejects an oversized declared body before reading or writing it', async () => { + const f = fixture(); + const response = await f.request(`/sandbox-logs/${suffix}`, { + method: 'PUT', + headers: { + Authorization: `Bearer ${mintControlLogUploadGrant(identity, secret)}`, + 'Content-Type': 'application/json', + 'Content-Length': String(CONTROL_LOG_MAX_BATCH_BYTES + 1), + }, + }); + expect(response.status).toBe(413); + expect(f.put).not.toHaveBeenCalled(); + }); + + it('preserves earlier wrapper archives and forwards bounded pagination', async () => { + const f = fixture(); + await f.upload(); + const nextIdentity = { ...identity, wrapperInstanceId: '2b6e33c0-20f8-4676-ad18-eedc478b161d' }; + const nextPath = suffix.replace(identity.wrapperInstanceId, nextIdentity.wrapperInstanceId); + expect( + (await f.upload(batch, nextPath, mintControlLogUploadGrant(nextIdentity, secret))).status + ).toBe(204); + expect(f.objects.size).toBe(2); + await f.request(`/internal/sandbox-logs/${identity.sandboxId}?cursor=next-page`, { + headers: { 'x-internal-api-key': 'internal-secret' }, + }); + expect(f.list).toHaveBeenCalledWith( + expect.objectContaining({ limit: 100, cursor: 'next-page' }) + ); + }); + + it('rejects archives, malformed JSON and path injection', async () => { + const f = fixture(); + const headers = { + Authorization: `Bearer ${mintControlLogUploadGrant(identity, secret)}`, + 'Content-Type': 'application/gzip', + }; + expect( + (await f.request(`/sandbox-logs/${suffix}`, { method: 'PUT', headers, body: 'raw archive' })) + .status + ).toBe(415); + headers['Content-Type'] = 'application/json'; + expect( + (await f.request(`/sandbox-logs/${suffix}`, { method: 'PUT', headers, body: '{' })).status + ).toBe(400); + expect( + (await f.upload(batch, suffix.replace('allocation_test', 'allocation%2Fother'))).status + ).toBe(400); + expect(f.put).not.toHaveBeenCalled(); + }); + + it('returns safe storage failures without including exception details', async () => { + const f = fixture(); + f.put.mockRejectedValueOnce(new Error('Authorization: private-secret')); + const response = await f.upload(); + expect(response.status).toBe(503); + expect(await response.text()).not.toContain('private-secret'); + expect( + ( + await f.request(`/internal/sandbox-logs/${suffix}`, { + headers: { 'x-internal-api-key': 'internal-secret' }, + }) + ).status + ).toBe(404); + }); +}); diff --git a/services/cloud-agent-next/src/sandbox-control/log-routes.ts b/services/cloud-agent-next/src/sandbox-control/log-routes.ts new file mode 100644 index 0000000000..0363fb596d --- /dev/null +++ b/services/cloud-agent-next/src/sandbox-control/log-routes.ts @@ -0,0 +1,164 @@ +import type { Hono, Context } from 'hono'; +import type { HonoContext } from '../hono-context.js'; +import { resolveSecret } from '../auth.js'; +import { + CONTROL_LOG_MAX_BATCH_BYTES, + controlLogBatchSchema, + controlLogIdentitySchema, + controlLogSandboxIdSchema, + controlLogWrapperIdSchema, + type ControlLogIdentity, +} from '../shared/control-diagnostics.js'; +import { validateControlLogUploadGrant } from './log-upload-grant.js'; + +function archivePrefix(identity: ControlLogIdentity): string { + return `logs/control/${[identity.sandboxId, identity.allocationId, identity.wrapperInstanceId] + .map(encodeURIComponent) + .join('/')}/`; +} + +async function readBoundedBody(request: Request): Promise { + const stream: ReadableStream | null = request.body; + if (!stream) return ''; + const reader = stream.getReader(); + const chunks: Uint8Array[] = []; + let length = 0; + try { + while (true) { + const { value, done } = await reader.read(); + if (done) break; + length += value.byteLength; + if (length > CONTROL_LOG_MAX_BATCH_BYTES) return undefined; + chunks.push(value); + } + } finally { + void reader.cancel().catch(() => undefined); + } + const bytes = new Uint8Array(length); + let offset = 0; + for (const chunk of chunks) { + bytes.set(chunk, offset); + offset += chunk.byteLength; + } + return new TextDecoder('utf-8', { fatal: true, ignoreBOM: false }).decode(bytes); +} + +function routeIdentity(c: Context) { + return controlLogIdentitySchema.safeParse({ + sandboxId: c.req.param('sandboxId'), + allocationId: c.req.param('allocationId'), + wrapperInstanceId: c.req.param('wrapperInstanceId'), + }); +} + +export function registerControlLogRoutes( + app: Hono, + requireInternalApi: (c: Context) => Response | null +): void { + app.put('/sandbox-logs/:sandboxId/:allocationId/:wrapperInstanceId/:batchId', async c => { + const identity = routeIdentity(c); + const batchId = controlLogWrapperIdSchema.safeParse(c.req.param('batchId')); + if (!identity.success || !batchId.success) return c.text('Invalid log identity', 400); + const grant = validateControlLogUploadGrant( + c.req.header('Authorization') ?? null, + await resolveSecret(c.env.NEXTAUTH_SECRET) + ); + if (!grant) return c.text('Unauthorized', 401); + if ( + grant.sandboxId !== identity.data.sandboxId || + grant.allocationId !== identity.data.allocationId || + grant.wrapperInstanceId !== identity.data.wrapperInstanceId + ) + return c.text('Log scope mismatch', 403); + + if (c.req.header('Content-Type')?.split(';')[0].trim() !== 'application/json') { + return c.text('Expected application/json', 415); + } + const encoding = c.req.header('Content-Encoding'); + if (encoding && encoding !== 'identity') return c.text('Unsupported encoding', 415); + const declaredLength = c.req.header('Content-Length'); + if (declaredLength && !/^\d+$/.test(declaredLength)) return c.text('Invalid length', 400); + if (Number(declaredLength) > CONTROL_LOG_MAX_BATCH_BYTES) return c.text('Body too large', 413); + + let body: unknown; + try { + const text = await readBoundedBody(c.req.raw); + if (text === undefined) return c.text('Body too large', 413); + body = JSON.parse(text); + } catch { + return c.text('Invalid log batch', 400); + } + const batch = controlLogBatchSchema.safeParse(body); + if (!batch.success) return c.text('Invalid log batch', 400); + try { + await c.env.R2_BUCKET.put( + `${archivePrefix(identity.data)}${batchId.data}.json`, + JSON.stringify(batch.data), + { + onlyIf: { etagDoesNotMatch: '*' }, + httpMetadata: { contentType: 'application/json' }, + customMetadata: { sequence: String(batch.data.sequence) }, + } + ); + } catch { + return c.text('Log storage unavailable', 503); + } + return c.body(null, 204); + }); + + app.get('/internal/sandbox-logs/:sandboxId', async c => { + const unauthorized = requireInternalApi(c); + if (unauthorized) return unauthorized; + const sandboxId = controlLogSandboxIdSchema.safeParse(c.req.param('sandboxId')); + const cursor = c.req.query('cursor'); + if (!sandboxId.success || (cursor && cursor.length > 4096)) { + return c.text('Invalid log query', 400); + } + try { + const listed = await c.env.R2_BUCKET.list({ + prefix: `logs/control/${encodeURIComponent(sandboxId.data)}/`, + limit: 100, + ...(cursor ? { cursor } : {}), + include: ['customMetadata'], + }); + c.header('Cache-Control', 'no-store'); + return c.json({ + objects: listed.objects.map(object => ({ + key: object.key, + size: object.size, + uploaded: object.uploaded.toISOString(), + sequence: object.customMetadata?.sequence, + })), + cursor: listed.truncated ? listed.cursor : null, + }); + } catch { + return c.text('Log storage unavailable', 503); + } + }); + + app.get( + '/internal/sandbox-logs/:sandboxId/:allocationId/:wrapperInstanceId/:batchId', + async c => { + const unauthorized = requireInternalApi(c); + if (unauthorized) return unauthorized; + const identity = routeIdentity(c); + const batchId = controlLogWrapperIdSchema.safeParse(c.req.param('batchId')); + if (!identity.success || !batchId.success) return c.text('Invalid log identity', 400); + try { + const object = await c.env.R2_BUCKET.get( + `${archivePrefix(identity.data)}${batchId.data}.json` + ); + if (!object) return c.text('Not found', 404); + return new Response(object.body, { + headers: { + 'Content-Type': 'application/json', + 'Cache-Control': 'no-store', + 'X-Content-Type-Options': 'nosniff', + }, + }); + } catch { + return c.text('Log storage unavailable', 503); + } + } + ); +} diff --git a/services/cloud-agent-next/src/sandbox-control/log-upload-grant.test.ts b/services/cloud-agent-next/src/sandbox-control/log-upload-grant.test.ts new file mode 100644 index 0000000000..a34e90e821 --- /dev/null +++ b/services/cloud-agent-next/src/sandbox-control/log-upload-grant.test.ts @@ -0,0 +1,58 @@ +import { describe, expect, it } from 'vitest'; +import jwt from 'jsonwebtoken'; +import { + validateWrapperDispatchTicket, + validateStreamTicket, + STREAM_TICKET_AUDIENCE, +} from '../auth.js'; +import { CONTROL_LOG_GRANT_SECONDS } from '../shared/control-diagnostics.js'; +import { mintControlLogUploadGrant, validateControlLogUploadGrant } from './log-upload-grant.js'; + +const identity = { + sandboxId: 'sandbox_test', + allocationId: 'allocation_test', + wrapperInstanceId: '0fce125c-54a3-4143-b503-b7775c4d2135', +}; +const secret = 'test-signing-secret'; + +describe('control log upload grant', () => { + it('confers no legacy wrapper or stream authority', async () => { + const token = mintControlLogUploadGrant(identity, secret); + expect((await validateWrapperDispatchTicket(`Bearer ${token}`, secret)).success).toBe(false); + expect(validateStreamTicket(token, secret, STREAM_TICKET_AUDIENCE).success).toBe(false); + }); + + it('carries only its fixed log scope and bounded expiry', () => { + const token = mintControlLogUploadGrant(identity, secret); + expect(validateControlLogUploadGrant(`Bearer ${token}`, secret)).toEqual(identity); + const decoded = jwt.decode(token); + if (!decoded || typeof decoded === 'string') throw new Error('Missing claims'); + expect(decoded.exp! - decoded.iat!).toBe(CONTROL_LOG_GRANT_SECONDS); + expect(decoded.type).toBe('control_log_upload'); + expect(decoded.aud).toBe('cloud-agent-control-log-upload'); + expect(validateControlLogUploadGrant(`Bearer ${token}`, 'wrong-secret')).toBeUndefined(); + }); + + it.each([ + { type: 'wrapper_dispatch_ticket', aud: 'cloud-agent-control-log-upload', expiresIn: 60 }, + { type: 'control_log_upload', aud: 'cloud-agent-stream', expiresIn: 60 }, + { type: 'control_log_upload', aud: 'cloud-agent-control-log-upload', expiresIn: -1 }, + { + type: 'control_log_upload', + aud: 'cloud-agent-control-log-upload', + expiresIn: CONTROL_LOG_GRANT_SECONDS + 1, + }, + ])('rejects wrong purpose, audience and expiry: %j', ({ type, aud, expiresIn }) => { + const token = jwt.sign({ type, identity }, secret, { audience: aud, expiresIn }); + expect(validateControlLogUploadGrant(`Bearer ${token}`, secret)).toBeUndefined(); + }); + + it('rejects missing, oversized and malformed credentials', () => { + for (const auth of [null, '', 'Bearer control-credential', `Bearer ${'x'.repeat(4096)}`]) { + expect(validateControlLogUploadGrant(auth, secret)).toBeUndefined(); + } + expect( + validateControlLogUploadGrant(`Bearer ${mintControlLogUploadGrant(identity, secret)}`, null) + ).toBeUndefined(); + }); +}); diff --git a/services/cloud-agent-next/src/sandbox-control/log-upload-grant.ts b/services/cloud-agent-next/src/sandbox-control/log-upload-grant.ts new file mode 100644 index 0000000000..45433a911b --- /dev/null +++ b/services/cloud-agent-next/src/sandbox-control/log-upload-grant.ts @@ -0,0 +1,48 @@ +import jwt from 'jsonwebtoken'; +import { z } from 'zod'; +import { + CONTROL_LOG_GRANT_SECONDS, + controlLogIdentitySchema, + type ControlLogIdentity, +} from '../shared/control-diagnostics.js'; + +const audience = 'cloud-agent-control-log-upload'; +const grantSchema = z + .object({ + type: z.literal('control_log_upload'), + aud: z.literal(audience), + identity: controlLogIdentitySchema, + iat: z.number().int().nonnegative(), + exp: z.number().int().nonnegative(), + }) + .strict(); + +export function mintControlLogUploadGrant(identity: ControlLogIdentity, secret: string): string { + return jwt.sign( + { type: 'control_log_upload', identity: controlLogIdentitySchema.parse(identity) }, + secret, + { algorithm: 'HS256', audience, expiresIn: CONTROL_LOG_GRANT_SECONDS } + ); +} + +export function validateControlLogUploadGrant( + authorization: string | null, + secret: string | null +): ControlLogIdentity | undefined { + if (!secret || !authorization || authorization.length > 4096) return undefined; + const match = /^Bearer (\S+)$/.exec(authorization); + if (!match) return undefined; + try { + const parsed = grantSchema.safeParse( + jwt.verify(match[1], secret, { algorithms: ['HS256'], audience }) + ); + if (!parsed.success) return undefined; + const { iat, exp, identity } = parsed.data; + if (exp <= iat || exp - iat > CONTROL_LOG_GRANT_SECONDS || iat > Date.now() / 1000 + 30) { + return undefined; + } + return identity; + } catch { + return undefined; + } +} diff --git a/services/cloud-agent-next/src/sandbox-control/socket.ts b/services/cloud-agent-next/src/sandbox-control/socket.ts index f6d8a7dfc0..179b2ed794 100644 --- a/services/cloud-agent-next/src/sandbox-control/socket.ts +++ b/services/cloud-agent-next/src/sandbox-control/socket.ts @@ -1,4 +1,9 @@ -import { logger } from '../logger.js'; +import { + diagnosticConnection, + diagnosticEventType, + logControlDiagnostic, + type ControlDiagnosticFields, +} from './diagnostics.js'; import { SANDBOX_CONTROL_PROTOCOL_VERSION, SANDBOX_CONTROL_WS_TAG, @@ -213,6 +218,8 @@ export function createSandboxControlSocketHandler( hooks: SandboxControlSocketHooks = {} ): SandboxControlSocketHandler { const activatingConnections = new Set(); + const log = (event: string, fields: ControlDiagnosticFields) => + logControlDiagnostic(event, { sandboxId, ...fields }); return { hasHandshakenSocket(): boolean { @@ -253,25 +260,35 @@ export function createSandboxControlSocketHandler( }; state.acceptWebSocket(server, [SANDBOX_CONTROL_WS_TAG]); server.serializeAttachment(attachment); - logger.withFields({ sandboxId }).info('Sandbox control socket accepted'); + log('socket_accepted', { connectionId: attachment.connectionId }); return new Response(null, { status: 101, webSocket: client }); }, async handleMessage(ws: WebSocket, message: string | ArrayBuffer): Promise { - if (ws.readyState !== 1) return; + if (ws.readyState !== 1) { + log('socket_frame_rejected', { reason: 'socket_not_open' }); + return; + } const attachment = readAttachment(ws); + const diagnostic = { + connectionId: attachment?.connectionId, + wrapperInstanceId: attachment?.wrapperInstanceId, + handshakeComplete: attachment?.handshakeComplete ?? false, + }; if ( attachment && !attachment.handshakeComplete && Date.now() - attachment.acceptedAt > SANDBOX_HELLO_DEADLINE_MS ) { + log('socket_frame_rejected', { ...diagnostic, reason: 'handshake_expired' }); closeSocket(ws, 1008, 'handshake_required'); return; } const parsed = parseControlFrame(message); if (!parsed.ok) { + log('socket_frame_rejected', { ...diagnostic, reason: parsed.error.code }); if (parsed.error.code === 'payload_too_large') { closeSocket(ws, 1009, 'payload_too_large'); return; @@ -281,8 +298,21 @@ export function createSandboxControlSocketHandler( } const frame = parsed.frame; + const frameDiagnostic = { + ...diagnostic, + frameType: frame.type, + frameBytes: parsed.bytes, + eventType: frame.type === 'event' ? diagnosticEventType(frame.event) : undefined, + operation: + frame.type === 'request' && isControlOperation(frame.operation) + ? frame.operation + : undefined, + requestId: frame.type !== 'event' ? frame.requestId : undefined, + }; + log('socket_frame_received', frameDiagnostic); if (frame.type === 'request' && frame.operation === 'sandbox.hello') { if (!isProvisionalSocket(state, ws, attachment)) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'invalid_provisional' }); sendJson( ws, errorResponse( @@ -299,6 +329,7 @@ export function createSandboxControlSocketHandler( const payload = parseSandboxHelloPayload(frame.payload); if (!payload) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'invalid_hello' }); sendJson( ws, errorResponse(frame.requestId, 'protocol_error', 'Invalid sandbox.hello payload') @@ -316,6 +347,10 @@ export function createSandboxControlSocketHandler( return; } if (!valid) { + log('socket_frame_rejected', { + ...frameDiagnostic, + reason: 'invalid_provider_instance', + }); sendJson( ws, errorResponse(frame.requestId, 'unauthorized', 'Invalid sandbox provider instance') @@ -384,11 +419,12 @@ export function createSandboxControlSocketHandler( operation: 'sandbox.status', payload: {}, }); - logger.withFields({ sandboxId }).info('Sandbox control handshake complete'); + log('socket_handshake_complete', { ...diagnosticConnection(identity), replaced }); return; } if (!attachment?.handshakeComplete) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'handshake_required' }); if (frame.type === 'request') { sendJson( ws, @@ -408,27 +444,29 @@ export function createSandboxControlSocketHandler( !identity || current.identity.connectionId !== identity.connectionId ) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'stale_connection' }); closeSocket(ws, 1008, 'stale_connection'); return; } - if (activatingConnections.has(identity.connectionId)) return; + if (activatingConnections.has(identity.connectionId)) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'activation_pending' }); + return; + } if (frame.type === 'response') { + log('socket_response', { ...frameDiagnostic, ok: frame.ok }); waiters.settle(frame); return; } if (frame.type === 'event') { - if (!isControlEvent(frame.event)) return; + if (!isControlEvent(frame.event)) { + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'unknown_event' }); + return; + } const eventPayload = parseEventPayload(frame.event, frame.payload); if (!eventPayload.ok) { - logger - .withFields({ - sandboxId, - event: frame.event, - error: eventPayload.error.message, - }) - .warn('Control event payload rejected'); + log('socket_frame_rejected', { ...frameDiagnostic, reason: 'invalid_event_payload' }); return; } if (frame.event === 'sandbox.ready') { @@ -479,12 +517,11 @@ export function createSandboxControlSocketHandler( async handleClose(ws: WebSocket): Promise { const attachment = readAttachment(ws); const handshakeComplete = attachment?.handshakeComplete === true; - logger - .withFields({ - sandboxId, - handshakeComplete, - }) - .info('Sandbox control socket closed'); + log('socket_closed', { + connectionId: attachment?.connectionId, + wrapperInstanceId: attachment?.wrapperInstanceId, + handshakeComplete, + }); if (!handshakeComplete) return; const current = currentHandshakenSocket(state); @@ -538,6 +575,13 @@ export function createSandboxControlSocketHandler( ...(input.session ? { session: input.session } : {}), }; const pending = waiters.wait(requestId, input.timeoutMs); + log('socket_request_sent', { + ...diagnosticConnection(current.identity), + requestId, + operation: input.operation, + sessionId: input.session?.sessionId, + timeoutMs: input.timeoutMs, + }); sendJson(current.socket, frame); return pending; }, diff --git a/services/cloud-agent-next/src/sandbox-control/vercel-provider.ts b/services/cloud-agent-next/src/sandbox-control/vercel-provider.ts index 3dc7803ed2..6cf2f1909e 100644 --- a/services/cloud-agent-next/src/sandbox-control/vercel-provider.ts +++ b/services/cloud-agent-next/src/sandbox-control/vercel-provider.ts @@ -10,6 +10,7 @@ import { } from '../agent-sandbox/vercel/vercel-sandbox-rest-client.js'; import type { VercelSandboxRuntimeConfig } from '../agent-sandbox/vercel/vercel-runtime-config.js'; import { DEADLINE_MS } from './deadlines.js'; +import { logControlDiagnostic } from './diagnostics.js'; import type { ObserveResult } from './physical-lifecycle.js'; import type { ProviderAdapter, ProviderCreateIntent } from './provider.js'; @@ -193,22 +194,61 @@ export function createVercelProviderAdapter(deps: { }, async stop(ref) { const parsed = decodeOwnedProviderRef(ref); - if (parsed === null) return 'retryable'; + const diagnostic = { + provider: 'vercel', + allocationName: deps.sandboxName, + providerSessionId: parsed?.sessionId, + }; + if (parsed === null) { + logControlDiagnostic('native_stop', { ...diagnostic, result: 'invalid_reference' }); + return 'retryable'; + } + const startedAt = now(); + logControlDiagnostic('native_stop', { ...diagnostic, result: 'started' }); try { const session = await restClient.stopSession(parsed.sessionId, parsed.sandboxName); - return TERMINAL_STATUSES.has(session.status) ? 'terminal' : 'retryable'; + const result = TERMINAL_STATUSES.has(session.status) ? 'terminal' : 'retryable'; + logControlDiagnostic('native_stop', { + ...diagnostic, + result, + durationMs: now() - startedAt, + }); + return result; } catch (error) { - if (isNotFound(error)) return 'terminal'; - return 'retryable'; + const result = isNotFound(error) ? 'terminal' : 'retryable'; + logControlDiagnostic('native_stop', { + ...diagnostic, + result, + durationMs: now() - startedAt, + }); + return result; } }, async ensureLeaseAtLeast(ref, ms) { const parsed = decodeOwnedProviderRef(ref); - if (parsed === null) return; + const diagnostic = { + provider: 'vercel', + allocationName: deps.sandboxName, + providerSessionId: parsed?.sessionId, + requestedLeaseMs: ms, + }; + if (parsed === null) { + logControlDiagnostic('native_lease', { ...diagnostic, action: 'invalid_reference' }); + return; + } const { session } = await restClient.getSession(parsed.sessionId, parsed.sandboxName); - if (session.status !== 'running') return; + if (session.status !== 'running') { + logControlDiagnostic('native_lease', { ...diagnostic, action: 'not_running' }); + return; + } const startedAt = session.startedAt ?? session.requestedAt; const remaining = startedAt + session.timeout - now(); + logControlDiagnostic('native_lease', { + ...diagnostic, + remainingMs: remaining, + action: remaining > ms ? 'sufficient_remaining' : 'extension', + extensionMs: remaining > ms ? undefined : Math.max(ms, config.extendDurationMs), + }); if (remaining > ms) return; await restClient.extendSessionTimeout( parsed.sessionId, diff --git a/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.test.ts b/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.test.ts index a308264bd6..f86f432c26 100644 --- a/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.test.ts +++ b/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.test.ts @@ -1,7 +1,64 @@ import { describe, expect, it } from 'vitest'; import { buildControlWrapperLaunchEnv } from './wrapper-launch-env.js'; +import { validateControlLogUploadGrant } from './log-upload-grant.js'; +import { CONTROL_RUNTIME_RESERVED_ENV_VARS } from '../shared/runtime-environment.js'; describe('buildControlWrapperLaunchEnv', () => { + it('issues a separate log-only grant and archive identity for each launch', () => { + const input = { + workerUrl: 'https://worker.example.com', + sandboxId: 'sandbox_test', + credential: 'control-credential', + diagnostics: { allocationId: 'allocation_test', signingSecret: 'test-secret' }, + }; + const first = buildControlWrapperLaunchEnv(input); + const second = buildControlWrapperLaunchEnv(input); + const identity = validateControlLogUploadGrant( + `Bearer ${first.CONTROL_LOG_UPLOAD_GRANT}`, + 'test-secret' + ); + expect(identity).toEqual({ + sandboxId: input.sandboxId, + allocationId: input.diagnostics.allocationId, + wrapperInstanceId: first.CONTROL_WRAPPER_INSTANCE_ID, + }); + expect(first.CONTROL_LOG_UPLOAD_URL).toBe( + `https://worker.example.com/sandbox-logs/sandbox_test/allocation_test/${first.CONTROL_WRAPPER_INSTANCE_ID}` + ); + expect(first.CONTROL_WRAPPER_INSTANCE_ID).not.toBe(second.CONTROL_WRAPPER_INSTANCE_ID); + expect(first.CONTROL_LOG_UPLOAD_GRANT).not.toContain(input.credential); + expect(first.CONTROL_LOG_UPLOAD_URL).not.toContain(first.CONTROL_LOG_UPLOAD_GRANT); + for (const key of [ + 'CONTROL_LOG_UPLOAD_URL', + 'CONTROL_LOG_UPLOAD_GRANT', + 'CONTROL_WRAPPER_INSTANCE_ID', + ]) { + expect(CONTROL_RUNTIME_RESERVED_ENV_VARS).toContain(key); + } + }); + + it.each([null, ''])('does not break startup without a signing secret: %s', signingSecret => { + const env = buildControlWrapperLaunchEnv({ + workerUrl: 'https://worker.example.com', + sandboxId: 'sandbox_test', + credential: 'control', + diagnostics: { allocationId: 'allocation_test', signingSecret }, + }); + expect(env.CONTROL_LOG_UPLOAD_GRANT).toBeUndefined(); + expect(env.SANDBOX_CONTROL_CREDENTIAL).toBe('control'); + }); + + it('does not put credentials into an invalid upload URL', () => { + const env = buildControlWrapperLaunchEnv({ + workerUrl: 'https://worker.example.com?token=private', + sandboxId: 'sandbox_test', + credential: 'control', + diagnostics: { allocationId: 'allocation_test', signingSecret: 'test-secret' }, + }); + expect(env.CONTROL_LOG_UPLOAD_GRANT).toBeUndefined(); + expect(env.CONTROL_LOG_UPLOAD_URL).toBeUndefined(); + }); + it('keeps Kilo and SCM credentials out of the wrapper bootstrap environment', () => { const input = { workerUrl: 'https://worker.example.com/', diff --git a/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.ts b/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.ts index 0be6c7ab69..2fb343b341 100644 --- a/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.ts +++ b/services/cloud-agent-next/src/sandbox-control/wrapper-launch-env.ts @@ -1,16 +1,53 @@ import { sandboxControlWebSocketUrl } from './control-url.js'; +import { mintControlLogUploadGrant } from './log-upload-grant.js'; export type ControlWrapperLaunchEnvInput = { workerUrl?: string; sandboxId: string; credential: string; + diagnostics?: { + allocationId: string; + signingSecret: string | null; + }; }; export function buildControlWrapperLaunchEnv( input: ControlWrapperLaunchEnvInput ): Record { const workerUrl = input.workerUrl?.replace(/\/$/, '') ?? ''; + let diagnosticEnv: Record = {}; + if (input.diagnostics?.signingSecret && workerUrl) { + try { + const base = new URL(workerUrl); + if ( + !['http:', 'https:'].includes(base.protocol) || + base.username || + base.password || + base.search || + base.hash + ) { + throw new Error('Invalid diagnostic upload origin'); + } + const identity = { + sandboxId: input.sandboxId, + allocationId: input.diagnostics.allocationId, + wrapperInstanceId: crypto.randomUUID(), + }; + const grant = mintControlLogUploadGrant(identity, input.diagnostics.signingSecret); + const path = [identity.sandboxId, identity.allocationId, identity.wrapperInstanceId] + .map(encodeURIComponent) + .join('/'); + diagnosticEnv = { + CONTROL_LOG_UPLOAD_URL: `${workerUrl}/sandbox-logs/${path}`, + CONTROL_LOG_UPLOAD_GRANT: grant, + CONTROL_WRAPPER_INSTANCE_ID: identity.wrapperInstanceId, + }; + } catch { + diagnosticEnv = {}; + } + } return { + ...diagnosticEnv, SANDBOX_CONTROL_URL: sandboxControlWebSocketUrl(workerUrl, input.sandboxId), SANDBOX_CONTROL_CREDENTIAL: input.credential, PROVIDER_INSTANCE_ID: input.sandboxId, diff --git a/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts b/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts index dd930f4a71..76fd437a96 100644 --- a/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts +++ b/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts @@ -16,7 +16,13 @@ import { import { and, eq, inArray, isNotNull, sql } from 'drizzle-orm'; import { buildSandboxBillingInput } from '../container-usage-context.js'; import { isCloudAgentContainerBillingEnabled } from '../container-billing-rollout.js'; -import { withDORetry } from '../utils/do-retry.js'; +import { + diagnosticCause, + diagnosticEventType, + logControlDiagnostic, + withControlDORetry as withDORetry, + type ControlDiagnosticFields, +} from '../sandbox-control/diagnostics.js'; import { drizzle } from 'drizzle-orm/durable-sqlite'; import { migrate } from 'drizzle-orm/durable-sqlite/migrator'; import migrations from '../../drizzle/migrations'; @@ -273,19 +279,30 @@ export class SandboxSession extends DurableObject { private async applySandboxControlEvent( input: SandboxControlEventInput & { wrapperInstanceId?: string } ): Promise<{ applied: boolean }> { + const startedAt = Date.now(); const metadata = await this.getMetadata(); const epoch = this.terminalLifecycle.captureEpoch(); - if (!metadata || epoch === null) { - logger - .withFields({ - sessionId: this.sessionId, - eventType: input.payload.type, - }) - .warn('receiveSandboxControlEvent rejected; session metadata missing'); - return { applied: false }; - } + const result = ( + applied: boolean, + disposition: string, + fields: ControlDiagnosticFields = {} + ) => { + logControlDiagnostic('session_event_result', { + sessionId: this.sessionId, + sandboxId: metadata?.workspace?.sandboxId, + wrapperInstanceId: input.wrapperInstanceId, + eventType: diagnosticEventType(input.payload.type), + applied, + disposition, + durationMs: Date.now() - startedAt, + ...fields, + }); + return { applied }; + }; + if (!metadata || epoch === null) return result(false, 'session_unavailable'); const root = metadata.auth.kiloSessionId; - if (input.identity.directory !== this.directory(metadata)) return { applied: false }; + if (input.identity.directory !== this.directory(metadata)) + return result(false, 'directory_mismatch'); const payloadKiloSessionId = ingestKiloSessionId(input.payload.type, input.payload.properties); const identityKiloSessionId = input.identity.kiloSessionId; const eventKiloSessionId = identityKiloSessionId ?? payloadKiloSessionId; @@ -302,15 +319,7 @@ export class SandboxSession extends DurableObject { identityKiloSessionId !== root && payloadKiloSessionId !== root) ) { - logger - .withFields({ - sessionId: this.sessionId, - eventType: input.payload.type, - rootKiloSessionId: input.identity.rootKiloSessionId, - expectedRootKiloSessionId: root, - }) - .warn('receiveSandboxControlEvent rejected; kilo session mismatch'); - return { applied: false }; + return result(false, 'root_mismatch'); } if (input.payload.type === 'session.created' || input.payload.type === 'session.updated') { const info = input.payload.properties.info; @@ -331,48 +340,66 @@ export class SandboxSession extends DurableObject { const sessionId = this.requireSessionId(); if (input.payload.type === 'session.message.outcome') { const outcome = sessionMessageOutcomeSchema.safeParse(input.payload.properties); - if ( - !outcome.success || - !input.wrapperInstanceId || - (eventKiloSessionId !== undefined && root !== undefined && eventKiloSessionId !== root) - ) { - return { applied: false }; + if (!outcome.success) return result(false, 'invalid_outcome'); + if (!input.wrapperInstanceId) return result(false, 'missing_wrapper_identity'); + if (eventKiloSessionId !== undefined && root !== undefined && eventKiloSessionId !== root) { + return result(false, 'root_mismatch'); } const messages = this.loadMessages(); const existing = messages.find(message => message.messageId === outcome.data.messageId); + const diagnostic = { + messageId: existing?.messageId, + fromState: existing?.state, + outcome: outcome.data.status, + }; if ( existing?.wrapperInstanceId === input.wrapperInstanceId && existing.state === outcome.data.status ) - return { applied: true }; + return result(true, 'duplicate', diagnostic); const settled = applyMessageOutcome( messages, outcome.data, input.wrapperInstanceId, Date.now() ); - if (!settled || !this.saveMessages(settled, epoch)) return { applied: false }; + if (!settled) { + return result( + false, + !existing + ? 'message_missing' + : existing.state !== 'queued' && existing.state !== 'accepted' + ? 'already_terminal' + : existing.wrapperInstanceId !== input.wrapperInstanceId + ? 'runtime_mismatch' + : 'not_queue_head', + diagnostic + ); + } + if (!this.saveMessages(settled, epoch, 'wrapper_outcome')) + return result(false, 'epoch_changed', diagnostic); await this.armQueueRetry(); const nextId = nextQueuedMessageId(this.loadMessages()); if (nextId && this.terminalLifecycle.isCurrent(epoch)) { this.ctx.waitUntil(this.dispatchQueued(nextId)); } - return { applied: true }; + return result(true, 'outcome_applied', diagnostic); } - if (!this.isCurrentEventRuntime(input.wrapperInstanceId)) return { applied: false }; + if (!this.isCurrentEventRuntime(input.wrapperInstanceId)) + return result(false, 'runtime_mismatch'); if ( eventKiloSessionId !== undefined && eventKiloSessionId !== root && (root === undefined || input.identity.rootKiloSessionId !== root) ) - return { applied: false }; + return result(false, 'root_mismatch'); if ( (input.payload.type === 'question.asked' || input.payload.type === 'permission.asked') && !this.loadMessages().some( message => message.state === 'accepted' || message.state === 'queued' ) ) - return { applied: false }; + return result(false, 'no_pending_work'); this.recordPendingInteraction(input.payload); persistSandboxControlSessionEvent({ sessionId, @@ -394,7 +421,7 @@ export class SandboxSession extends DurableObject { } catch { internalSecret = undefined; } - if (!this.terminalLifecycle.isCurrent(epoch)) return { applied: false }; + if (!this.terminalLifecycle.isCurrent(epoch)) return result(false, 'epoch_changed'); if (!internalSecret) { logger .withFields({ @@ -428,7 +455,8 @@ export class SandboxSession extends DurableObject { this.ctx.waitUntil(publication); } } - return { applied: this.terminalLifecycle.isCurrent(epoch) }; + const applied = this.terminalLifecycle.isCurrent(epoch); + return result(applied, applied ? 'applied' : 'epoch_changed'); } async receiveSandboxControlPreparing(input: { @@ -438,15 +466,26 @@ export class SandboxSession extends DurableObject { }): Promise<{ applied: boolean }> { const metadata = await this.getMetadata(); const epoch = this.terminalLifecycle.captureEpoch(); - if (!metadata || epoch === null) return { applied: false }; + const result = (applied: boolean, disposition: string) => { + logControlDiagnostic('session_preparing_result', { + sessionId: this.sessionId, + sandboxId: metadata?.workspace?.sandboxId, + wrapperInstanceId: input.wrapperInstanceId, + applied, + disposition, + }); + return { applied }; + }; + if (!metadata || epoch === null) return result(false, 'session_unavailable'); const root = metadata.auth.kiloSessionId; - if (input.identity.directory !== this.directory(metadata)) return { applied: false }; + if (input.identity.directory !== this.directory(metadata)) + return result(false, 'directory_mismatch'); if ( input.identity.rootKiloSessionId !== undefined && root !== undefined && input.identity.rootKiloSessionId !== root ) { - return { applied: false }; + return result(false, 'root_mismatch'); } const message = this.loadMessages().find( item => item.messageId === input.payload.triggerMessageId @@ -458,9 +497,18 @@ export class SandboxSession extends DurableObject { (input.wrapperInstanceId !== undefined && message.wrapperInstanceId !== input.wrapperInstanceId) ) { - return { applied: false }; + return result( + false, + !this.terminalLifecycle.isCurrent(epoch) + ? 'epoch_changed' + : !message + ? 'message_missing' + : message.preparationAttemptId !== input.payload.attemptId + ? 'attempt_mismatch' + : 'runtime_mismatch' + ); } - if (message.state !== 'queued') return { applied: true }; + if (message.state !== 'queued') return result(true, 'already_settled'); const sessionId = this.requireSessionId(); applyControlPlanePreparingEvent({ sessionId, @@ -468,7 +516,7 @@ export class SandboxSession extends DurableObject { eventQueries: this.eventQueries, broadcast: event => this.broadcastStoredEvent(event), }); - return { applied: true }; + return result(true, 'processed'); } async closeOrgStreams(organizationId: string): Promise { @@ -2046,7 +2094,11 @@ export class SandboxSession extends DurableObject { return this.ctx.storage.kv.get(MESSAGES_KEY) ?? []; } - private saveMessages(messages: MessageRecord[], epoch?: number): boolean { + private saveMessages( + messages: MessageRecord[], + epoch?: number, + source: 'coordinator' | 'wrapper_outcome' = 'coordinator' + ): boolean { const currentEpoch = epoch ?? this.terminalLifecycle.captureEpoch(); if ( this.deletedWorktreeId || @@ -2055,6 +2107,7 @@ export class SandboxSession extends DurableObject { ) return false; const events: StoredEvent[] = []; + const committed: ControlDiagnosticFields[] = []; this.ctx.storage.transactionSync(() => { const before = this.loadMessages(); const previousById = new Map(before.map(message => [message.messageId, message])); @@ -2069,6 +2122,13 @@ export class SandboxSession extends DurableObject { if (previous?.state !== 'accepted') { const event = this.persistMessageLifecycleEvent(message); if (event) events.push(event); + committed.push({ + messageId: message.messageId, + wrapperInstanceId: message.wrapperInstanceId, + fromState: previous?.state, + toState: message.state, + lifecycleEventInserted: event !== undefined, + }); } return message; } @@ -2083,6 +2143,15 @@ export class SandboxSession extends DurableObject { } const event = this.persistMessageLifecycleEvent(terminal); if (event) events.push(event); + committed.push({ + messageId: terminal.messageId, + wrapperInstanceId: terminal.wrapperInstanceId, + fromState: previous?.state, + toState: terminal.state, + terminalAt: terminal.terminalAt, + lifecycleEventInserted: event !== undefined, + cause: terminal.failedReason ? diagnosticCause(terminal.failedReason) : undefined, + }); if (terminal.preparationAttemptId) { events.push( ...finalizePreparationAttempt( @@ -2105,6 +2174,13 @@ export class SandboxSession extends DurableObject { }); this.ctx.storage.kv.put(MESSAGES_KEY, next); }); + for (const fields of committed) { + logControlDiagnostic('session_message_committed', { + sessionId: this.sessionId, + source, + ...fields, + }); + } for (const event of events) this.broadcastStoredEvent(event); return true; } diff --git a/services/cloud-agent-next/src/server.test.ts b/services/cloud-agent-next/src/server.test.ts index 82db0702d4..a95897f7d7 100644 --- a/services/cloud-agent-next/src/server.test.ts +++ b/services/cloud-agent-next/src/server.test.ts @@ -3,6 +3,7 @@ import jwt from 'jsonwebtoken'; import { VERCEL_SANDBOX_UNAVAILABLE_MESSAGE } from './agent-sandbox/vercel/vercel-agent-sandbox.js'; import type { Env } from './types.js'; import { mintWrapperDispatchTicket, type WrapperDispatchTicketClaims } from './auth.js'; +import { mintControlLogUploadGrant } from './sandbox-control/log-upload-grant.js'; const { getRunningTerminalClientMock, @@ -1046,6 +1047,20 @@ describe('server wrapper ingest route', () => { }); describe('server wrapper log upload route', () => { + it('does not accept legacy raw archives for control-plane sessions', async () => { + const env = Object.assign(createEnv(), { R2_BUCKET: { put: vi.fn() } }); + const response = await fetchWorker( + new Request('http://worker.test/sessions/usr_feed/workspace_test/logs/session/logs.tar.gz', { + method: 'PUT', + headers: { Authorization: `Bearer ${signKiloToken('usr_feed')}` }, + body: 'raw archive', + }), + env + ); + expect(response.status).toBe(404); + expect(env.R2_BUCKET.put).not.toHaveBeenCalled(); + }); + function createLogEnv() { const env = createEnv(); return Object.assign(env, { @@ -1489,6 +1504,57 @@ describe('server /sandbox-terminal', () => { }); }); +describe('server control log routes', () => { + it('accepts a log-only grant without touching sandbox liveness', async () => { + const env = Object.assign(createEnv(), { R2_BUCKET: { put: vi.fn().mockResolvedValue(null) } }); + const identity = { + sandboxId: 'sandbox_test', + allocationId: 'allocation_test', + wrapperInstanceId: '0fce125c-54a3-4143-b503-b7775c4d2135', + }; + const response = await fetchWorker( + new Request( + `http://worker.test/sandbox-logs/${identity.sandboxId}/${identity.allocationId}/${identity.wrapperInstanceId}/5886f962-cc33-43f7-bd94-a31c0ed6c13b`, + { + method: 'PUT', + headers: { + Authorization: `Bearer ${mintControlLogUploadGrant(identity, secret)}`, + 'Content-Type': 'application/json', + }, + body: JSON.stringify({ + version: 1, + sequence: 0, + droppedRecords: 0, + records: [ + { timestamp: 100, event: 'wrapper.lifecycle', fields: { phase: 'starting' } }, + ], + }), + } + ), + env + ); + expect(response.status).toBe(204); + expect(env.R2_BUCKET.put).toHaveBeenCalledOnce(); + expect(env.SANDBOX_CONTROL.getByName).not.toHaveBeenCalled(); + expect(requireCurrentSessionAccessMock).not.toHaveBeenCalled(); + }); + + it('protects durable retrieval with the internal API secret', async () => { + const env = Object.assign(createEnv(), { + R2_BUCKET: { list: vi.fn().mockResolvedValue({ objects: [], truncated: false }) }, + }); + const url = 'http://worker.test/internal/sandbox-logs/sandbox_test'; + expect((await fetchWorker(new Request(url), env)).status).toBe(401); + expect(env.R2_BUCKET.list).not.toHaveBeenCalled(); + const response = await fetchWorker( + new Request(url, { headers: { 'x-internal-api-key': 'test-internal-secret' } }), + env + ); + expect(response.status).toBe(200); + expect(env.SANDBOX_CONTROL.getByName).not.toHaveBeenCalled(); + }); +}); + describe('server /sandbox-control', () => { it('rejects non-websocket requests', async () => { const env = createEnv(); diff --git a/services/cloud-agent-next/src/server.ts b/services/cloud-agent-next/src/server.ts index e7540e99ee..1bb504cd6b 100644 --- a/services/cloud-agent-next/src/server.ts +++ b/services/cloud-agent-next/src/server.ts @@ -47,6 +47,7 @@ import { parseBearerCredential, } from './sandbox-control/credential.js'; import { PtyIdSchema, sessionIdSchema } from './router/schemas.js'; +import { registerControlLogRoutes } from './sandbox-control/log-routes.js'; const app = new Hono(); @@ -224,6 +225,8 @@ function requireInternalApi(c: Context): Response | null { return null; } +registerControlLogRoutes(app, requireInternalApi); + app.post('/internal/sandbox-control/seed', async (c: Context) => { const unauthorized = requireInternalApi(c); if (unauthorized) return unauthorized; @@ -660,6 +663,9 @@ app.put( if (!rawUserId || !filename || !sessionId || !executionId) { return c.text('Missing route params', 400); } + if (sessionPlaneFromId(sessionId) === 'control') { + return c.text('Not found', 404); + } let userId: string; try { diff --git a/services/cloud-agent-next/src/shared/control-diagnostics.ts b/services/cloud-agent-next/src/shared/control-diagnostics.ts new file mode 100644 index 0000000000..7911a9d768 --- /dev/null +++ b/services/cloud-agent-next/src/shared/control-diagnostics.ts @@ -0,0 +1,226 @@ +import { z } from 'zod'; +import { CONTROL_OPERATIONS, controlErrorCodes } from './sandbox-control-protocol.js'; + +export const CONTROL_LOG_MAX_BATCH_BYTES = 256 * 1024; +export const CONTROL_LOG_MAX_BATCH_RECORDS = 128; +export const CONTROL_LOG_MAX_BUFFER_RECORDS = 512; +export const CONTROL_LOG_MAX_RECORD_BYTES = 4096; +export const CONTROL_LOG_GRANT_SECONDS = 4 * 60 * 60; +export const controlLogUploadResults = [ + 'accepted', + 'http_rejection', + 'network_failure', + 'timeout', + 'cancelled', +] as const; +export type ControlLogUploadResult = (typeof controlLogUploadResults)[number]; + +export type ControlDiagnosticFields = Record; +export type ControlDiagnosticReporter = (event: string, fields: ControlDiagnosticFields) => void; + +export const controlLogSandboxIdSchema = z.string().regex(/^[A-Za-z0-9._:-]{1,256}$/); +export const controlLogAllocationIdSchema = z.string().regex(/^[A-Za-z0-9_-]{1,128}$/); +export const controlLogWrapperIdSchema = z.string().uuid(); +const identifier = z.string().regex(/^[A-Za-z0-9_:-]{1,128}$/); +const count = z.number().int().min(0).max(Number.MAX_SAFE_INTEGER); +const milliseconds = z.number().min(0).max(Number.MAX_SAFE_INTEGER); + +export const controlDiagnosticFieldsSchema = z + .object({ + phase: z.enum([ + 'starting', + 'ready', + 'stopping', + 'start_failed', + 'started', + 'deadline_expired', + 'finished', + 'failed', + 'prompt_started', + 'prompt_completed', + 'command_started', + 'command_completed', + 'compact_started', + 'compact_completed', + 'finalization_started', + 'autocommit_started', + 'autocommit_completed', + 'condense_started', + 'condense_completed', + 'execution_failed', + 'abort_started', + 'abort_completed', + 'abort_failed', + 'outcome_sending', + 'outcome_sent', + 'outcome_failed', + 'sending', + 'sent', + 'send_failed', + 'send_threw', + 'stopped', + 'opening', + 'stale', + 'reconnected', + 'ended', + 'freshness', + 'opened', + 'hello_sent', + 'hello_accepted', + 'closed', + 'retired', + 'connect_attempt', + 'retry_scheduled', + 'keepalive_sent', + 'keepalive_failed', + 'received', + 'completed', + 'response_sent', + 'response_failed', + 'response_skipped', + 'skipped', + ]), + kind: z.enum(['preparation', 'execution', 'finalizing']).optional(), + status: z.enum(['completed', 'failed', 'cancelled']).optional(), + category: z + .enum([ + 'outcome', + 'preparing', + 'session_event', + 'heartbeat', + 'ready', + 'other', + ...controlLogUploadResults, + ]) + .optional(), + operation: z.enum([...CONTROL_OPERATIONS, 'other']).optional(), + retirementCause: z + .enum([ + 'event_feed_unhealthy', + 'control_disconnected', + 'preparation_delivery_failed', + 'requested_shutdown', + 'sigterm', + 'sigint', + 'uncaught_exception', + 'unhandled_rejection', + 'cancellation_failed', + 'outcome_delivery_failed', + 'execution_deadline', + 'preparation_deadline', + 'unknown', + ]) + .optional(), + errorCode: z.enum([...controlErrorCodes, 'other']).optional(), + retryable: z.boolean().optional(), + scopeId: identifier.optional(), + sessionId: identifier.optional(), + kiloSessionId: identifier.optional(), + messageId: identifier.optional(), + requestId: identifier.optional(), + connectionId: identifier.optional(), + incarnation: identifier.optional(), + elapsedMs: milliseconds.optional(), + lastSentAt: milliseconds.optional(), + sinceLastSentMs: milliseconds.optional(), + lastEventAt: milliseconds.optional(), + ageMs: milliseconds.optional(), + delayMs: milliseconds.optional(), + sequence: count.optional(), + eventsReceived: count.optional(), + bufferedBytes: count.optional(), + bytes: count.optional(), + attempt: count.optional(), + failureCount: count.optional(), + statusCode: z.number().int().min(100).max(599).optional(), + readyState: z.number().int().min(0).max(3).optional(), + closeCode: z.number().int().min(0).max(65535).optional(), + exitCode: z.number().int().min(0).max(255).optional(), + wasClean: z.boolean().optional(), + ok: z.boolean().optional(), + aborted: z.boolean().optional(), + }) + .strict(); + +export const controlDiagnosticRecordSchema = z + .object({ + timestamp: milliseconds, + event: z.enum([ + 'wrapper.lifecycle', + 'session.task', + 'session.execution', + 'control.heartbeat', + 'control.feed', + 'control.socket', + 'control.request', + 'control.event', + 'control.upload', + ]), + fields: controlDiagnosticFieldsSchema, + }) + .strict(); + +export type ControlDiagnosticRecord = z.infer; + +export const controlLogIdentitySchema = z + .object({ + sandboxId: controlLogSandboxIdSchema, + allocationId: controlLogAllocationIdSchema, + wrapperInstanceId: controlLogWrapperIdSchema, + }) + .strict(); + +export type ControlLogIdentity = z.infer; + +export const controlLogBatchSchema = z + .object({ + version: z.literal(1), + sequence: count, + droppedRecords: count, + droppedTerminalRecords: count.optional(), + records: z.array(controlDiagnosticRecordSchema).min(1).max(CONTROL_LOG_MAX_BATCH_RECORDS), + }) + .strict(); + +export type ControlLogBatch = z.infer; + +export function emitControlDiagnostic( + callback: ControlDiagnosticReporter | undefined, + event: string, + fields: ControlDiagnosticFields +): void { + try { + callback?.(event, fields); + } catch { + return; + } +} + +export function createControlDiagnosticRecord( + event: string, + fields: ControlDiagnosticFields, + timestamp: number +): ControlDiagnosticRecord | undefined { + try { + const allowedFields: ControlDiagnosticFields = {}; + for (const key of Object.keys(controlDiagnosticFieldsSchema.shape)) { + const value = fields[key]; + if (value !== undefined) allowedFields[key] = value; + } + const parsed = controlDiagnosticRecordSchema.safeParse({ + timestamp, + event, + fields: allowedFields, + }); + if (!parsed.success) return undefined; + if ( + new TextEncoder().encode(JSON.stringify(parsed.data)).byteLength > + CONTROL_LOG_MAX_RECORD_BYTES + ) { + return undefined; + } + return parsed.data; + } catch { + return undefined; + } +} diff --git a/services/cloud-agent-next/src/shared/runtime-environment.ts b/services/cloud-agent-next/src/shared/runtime-environment.ts index 91eae15c8c..f9c9d06b0c 100644 --- a/services/cloud-agent-next/src/shared/runtime-environment.ts +++ b/services/cloud-agent-next/src/shared/runtime-environment.ts @@ -43,4 +43,7 @@ export const CONTROL_RUNTIME_RESERVED_ENV_VARS = [ 'SANDBOX_CONTROL_CREDENTIAL', 'SANDBOX_CONTROL_URL', 'PROVIDER_INSTANCE_ID', + 'CONTROL_LOG_UPLOAD_URL', + 'CONTROL_LOG_UPLOAD_GRANT', + 'CONTROL_WRAPPER_INSTANCE_ID', ] as const; diff --git a/services/cloud-agent-next/wrapper/src/control/diagnostics.test.ts b/services/cloud-agent-next/wrapper/src/control/diagnostics.test.ts new file mode 100644 index 0000000000..6c9be2bdf3 --- /dev/null +++ b/services/cloud-agent-next/wrapper/src/control/diagnostics.test.ts @@ -0,0 +1,360 @@ +import { describe, expect, it, spyOn } from 'bun:test'; +import { + CONTROL_LOG_MAX_BATCH_BYTES, + CONTROL_LOG_MAX_BATCH_RECORDS, + CONTROL_LOG_MAX_BUFFER_RECORDS, + controlLogBatchSchema, +} from '../../../src/shared/control-diagnostics.js'; +import { createControlDiagnostics } from './diagnostics'; +import { buildWorktreeKiloEnvironment } from './worktree-runtime'; + +const uploadUrl = 'http://worker.test/sandbox-logs/sandbox/allocation/wrapper'; +const uploadGrant = 'test-upload-only-grant'; + +function requestBody(init: RequestInit): string { + if (typeof init.body !== 'string') throw new Error('Expected JSON body'); + return init.body; +} + +function record(diagnostics: ReturnType, phase = 'started') { + diagnostics.onDiagnostic('session.task', { + phase, + kind: 'execution', + sessionId: 'workspace_test', + }); +} + +describe('control diagnostics', () => { + it('strips log upload secrets and configuration from both inherited and supplied child env', () => { + const privateEnv = { + CONTROL_LOG_UPLOAD_URL: uploadUrl, + CONTROL_LOG_UPLOAD_GRANT: uploadGrant, + CONTROL_WRAPPER_INSTANCE_ID: 'private-wrapper-identity', + }; + const child = buildWorktreeKiloEnvironment( + '/workspace/test', + '/home/test', + { + scopeId: 'worktree_test', + token: 'worktree-token', + targets: { + backendBaseUrl: 'https://backend.test', + providerBaseUrl: 'https://provider.test', + sessionIngestBaseUrl: 'https://ingest.test', + }, + }, + privateEnv, + privateEnv + ); + for (const name of Object.keys(privateEnv)) expect(child[name]).toBeUndefined(); + expect(JSON.stringify(child)).not.toContain(uploadGrant); + }); + + it('retries a timed-out upload with the same immutable identity and ignores its late result', async () => { + const late = Promise.withResolvers(); + const requests: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + uploadTimeoutMs: 10, + fetch: async url => { + requests.push(url); + return requests.length === 1 ? late.promise : new Response(null, { status: 204 }); + }, + }); + record(diagnostics); + await diagnostics.flush(); + await diagnostics.flush(); + late.resolve(new Response(null, { status: 204 })); + record(diagnostics, 'finished'); + await diagnostics.finalize(); + expect(requests).toHaveLength(3); + expect(requests[0]).toBe(requests[1]); + expect(requests[2]).not.toBe(requests[0]); + }); + + it('uploads startup immediately, then periodically, with structured records only', async () => { + const uploads: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + intervalMs: 5, + fetch: async (_url, init) => { + expect(new Headers(init.headers).get('Authorization')).toBe(`Bearer ${uploadGrant}`); + expect(init.redirect).toBe('error'); + uploads.push(requestBody(init)); + return new Response(null, { status: 204 }); + }, + }); + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'starting', error: 'secret' }); + diagnostics.start(); + await diagnostics.flush(); + expect(uploads).toHaveLength(1); + record(diagnostics); + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sending', sequence: 1 }); + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sent', sequence: 1 }); + await Bun.sleep(20); + await diagnostics.finalize(); + expect(uploads).toHaveLength(2); + const periodicBatch = controlLogBatchSchema.parse(JSON.parse(uploads[1])); + expect(periodicBatch.records).toHaveLength(3); + expect(periodicBatch.droppedRecords).toBe(0); + expect(uploads.join('')).not.toContain('secret'); + expect(uploads.join('')).not.toContain(uploadGrant); + expect(uploads.every(body => controlLogBatchSchema.safeParse(JSON.parse(body)).success)).toBe( + true + ); + }); + + it('serializes uploads and retries the same immutable batch before newer records', async () => { + const uploads: Array<{ url: string; body: string }> = []; + const response = Promise.withResolvers(); + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (url, init) => { + uploads.push({ url, body: requestBody(init) }); + return uploads.length === 1 ? response.promise : new Response(null, { status: 204 }); + }, + }); + record(diagnostics); + const first = diagnostics.flush(); + expect(diagnostics.flush()).toBe(first); + record(diagnostics, 'finished'); + expect(uploads).toHaveLength(1); + response.resolve(new Response('private-response-body', { status: 503 })); + await first; + await diagnostics.flush(); + await diagnostics.finalize(); + expect(uploads).toHaveLength(3); + expect(uploads[1]).toEqual(uploads[0]); + expect(uploads[2].url).not.toBe(uploads[0].url); + const recovered = controlLogBatchSchema.parse(JSON.parse(uploads[2].body)); + expect(recovered.sequence).toBe(1); + expect(recovered.records).toContainEqual( + expect.objectContaining({ + event: 'control.upload', + fields: expect.objectContaining({ + category: 'http_rejection', + statusCode: 503, + failureCount: 1, + }), + }) + ); + expect(uploads.map(upload => upload.body).join('')).not.toContain('private-response-body'); + }); + + it.each([401, 403])('stops uploads after authentication is rejected with %s', async status => { + let uploads = 0; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + intervalMs: 5, + fetch: async () => { + uploads++; + return new Response(null, { status }); + }, + }); + record(diagnostics); + diagnostics.start(); + await diagnostics.flush(); + try { + record(diagnostics, 'finished'); + await Bun.sleep(20); + diagnostics.start(); + await diagnostics.flush(); + } finally { + await diagnostics.finalize(); + } + expect(uploads).toBe(1); + }); + + it('keeps failed-batch retries on the timer instead of retrying for every new record', async () => { + let uploads = 0; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + intervalMs: 60_000, + fetch: async () => { + uploads++; + return new Response(null, { status: 503 }); + }, + }); + record(diagnostics); + diagnostics.start(); + await diagnostics.flush(); + try { + for (let i = 0; i < CONTROL_LOG_MAX_BATCH_RECORDS + 10; i++) { + record(diagnostics); + await Promise.resolve(); + } + expect(uploads).toBe(1); + } finally { + await diagnostics.finalize(); + } + }); + + it('bounds queued records and batch bytes and reports dropped records', async () => { + const bodies: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (_url, init) => { + bodies.push(requestBody(init)); + return new Response(null, { status: 204 }); + }, + }); + for (let i = 0; i < CONTROL_LOG_MAX_BUFFER_RECORDS + 50; i++) record(diagnostics); + await diagnostics.finalize(); + const batches = bodies.map(body => controlLogBatchSchema.parse(JSON.parse(body))); + expect(batches.flatMap(batch => batch.records)).toHaveLength(CONTROL_LOG_MAX_BUFFER_RECORDS); + expect(batches[0].droppedRecords).toBe(50); + expect(bodies.every(body => Buffer.byteLength(body) <= CONTROL_LOG_MAX_BATCH_BYTES)).toBe(true); + }); + + it.each(['ordinary', 'heartbeat'])( + 'retains startup, latest heartbeat and terminal evidence under %s buffer pressure', + async distribution => { + const bodies: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (_url, init) => { + bodies.push(requestBody(init)); + return new Response(null, { status: 204 }); + }, + }); + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'starting' }); + for (let i = 0; i < CONTROL_LOG_MAX_BUFFER_RECORDS; i++) { + if (distribution === 'heartbeat') { + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sent', sequence: i }); + } else { + record(diagnostics); + } + } + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sent', sequence: 1 }); + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sent', sequence: 2 }); + diagnostics.onDiagnostic('session.execution', { + phase: 'outcome_sent', + messageId: 'msg_terminal', + }); + await diagnostics.finalize(); + const batches = bodies.map(body => controlLogBatchSchema.parse(JSON.parse(body))); + const retained = batches.flatMap(batch => batch.records); + expect(retained).toHaveLength(CONTROL_LOG_MAX_BUFFER_RECORDS); + expect(retained.some(record => record.event === 'wrapper.lifecycle')).toBe(true); + expect( + retained + .filter(record => record.event === 'control.heartbeat') + .map(record => record.fields.sequence) + ).toContain(2); + expect(retained.some(record => record.fields.messageId === 'msg_terminal')).toBe(true); + expect(batches[0].droppedRecords).toBe(4); + expect(batches[0].droppedTerminalRecords).toBe(0); + } + ); + + it('accounts explicitly for terminal loss when even priority records exceed the buffer bound', async () => { + const bodies: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (_url, init) => { + bodies.push(requestBody(init)); + return new Response(null, { status: 204 }); + }, + }); + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'starting' }); + diagnostics.onDiagnostic('control.heartbeat', { phase: 'sent', sequence: 1 }); + for (let i = 0; i < CONTROL_LOG_MAX_BUFFER_RECORDS; i++) { + diagnostics.onDiagnostic('session.execution', { + phase: 'outcome_sent', + messageId: `msg_${i}`, + }); + } + await diagnostics.finalize(); + const batches = bodies.map(body => controlLogBatchSchema.parse(JSON.parse(body))); + const retained = batches.flatMap(batch => batch.records); + expect(retained).toHaveLength(CONTROL_LOG_MAX_BUFFER_RECORDS); + expect(retained.some(record => record.event === 'wrapper.lifecycle')).toBe(true); + expect(retained.some(record => record.event === 'control.heartbeat')).toBe(true); + expect( + retained.some( + record => record.fields.messageId === `msg_${CONTROL_LOG_MAX_BUFFER_RECORDS - 1}` + ) + ).toBe(true); + expect(batches[0].droppedRecords).toBe(2); + expect(batches[0].droppedTerminalRecords).toBe(2); + }); + + it('bounds finalization even when fetch ignores abort and makes finalization idempotent', async () => { + let signal: AbortSignal | null | undefined; + let uploads = 0; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (_url, init) => { + uploads++; + signal = init.signal; + return new Promise(() => {}); + }, + }); + record(diagnostics); + void diagnostics.flush(); + const started = Date.now(); + const final = diagnostics.finalize(25); + expect(diagnostics.finalize()).toBe(final); + await final; + expect(Date.now() - started).toBeLessThan(500); + expect(signal?.aborted).toBe(true); + await diagnostics.flush(); + expect(uploads).toBe(1); + }); + + it('flushes shutdown records after the active upload completes', async () => { + const pending = Promise.withResolvers(); + const bodies: string[] = []; + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async (_url, init) => { + bodies.push(requestBody(init)); + return bodies.length === 1 ? pending.promise : new Response(null, { status: 204 }); + }, + }); + record(diagnostics); + void diagnostics.flush(); + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'stopping', exitCode: 1 }); + const final = diagnostics.finalize(); + pending.resolve(new Response(null, { status: 204 })); + await final; + expect(bodies).toHaveLength(2); + const lastBatch = controlLogBatchSchema.parse(JSON.parse(bodies[1])); + expect(lastBatch.sequence).toBe(1); + expect(lastBatch.records).toHaveLength(1); + }); + + it('degrades without configuration and swallows upload errors', async () => { + const disabled = createControlDiagnostics({}); + disabled.start(); + record(disabled); + await disabled.finalize(); + const stderr = spyOn(console, 'error').mockImplementation(() => { + throw new Error('stderr unavailable'); + }); + try { + const diagnostics = createControlDiagnostics({ + uploadUrl, + uploadGrant, + fetch: async () => { + throw new Error('Authorization: secret'); + }, + }); + record(diagnostics); + await diagnostics.flush(); + await diagnostics.finalize(); + } finally { + stderr.mockRestore(); + } + }); +}); diff --git a/services/cloud-agent-next/wrapper/src/control/diagnostics.ts b/services/cloud-agent-next/wrapper/src/control/diagnostics.ts new file mode 100644 index 0000000000..fa583433f0 --- /dev/null +++ b/services/cloud-agent-next/wrapper/src/control/diagnostics.ts @@ -0,0 +1,302 @@ +import { + CONTROL_LOG_MAX_BATCH_BYTES, + CONTROL_LOG_MAX_BATCH_RECORDS, + CONTROL_LOG_MAX_BUFFER_RECORDS, + createControlDiagnosticRecord, + type ControlDiagnosticReporter, + type ControlDiagnosticRecord, + type ControlLogBatch, + type ControlLogUploadResult, +} from '../../../src/shared/control-diagnostics.js'; + +export type ControlDiagnostics = { + onDiagnostic: ControlDiagnosticReporter; + start(): void; + flush(): Promise; + finalize(timeoutMs?: number): Promise; +}; + +type Options = { + uploadUrl?: string; + uploadGrant?: string; + fetch?: (url: string, init: RequestInit) => Promise; + now?: () => number; + intervalMs?: number; + uploadTimeoutMs?: number; +}; + +type PendingBatch = { id: string; body: string; sequence: number; attempts: number }; + +function isTerminalRecord(record: ControlDiagnosticRecord): boolean { + const { event, fields } = record; + if (event === 'wrapper.lifecycle') + return ( + fields.phase === 'stopping' || fields.phase === 'start_failed' || fields.phase === 'failed' + ); + if (event === 'session.task') { + return ( + fields.phase === 'finished' || + fields.phase === 'failed' || + fields.phase === 'deadline_expired' + ); + } + return ( + event === 'session.execution' && + (fields.status !== undefined || + fields.phase === 'execution_failed' || + fields.phase === 'outcome_sending' || + fields.phase === 'outcome_sent' || + fields.phase === 'outcome_failed' || + fields.phase === 'abort_completed' || + fields.phase === 'abort_failed') + ); +} + +function retentionPriority(record: ControlDiagnosticRecord): number { + if ( + record.event === 'control.heartbeat' || + (record.event === 'wrapper.lifecycle' && record.fields.phase === 'starting') + ) + return 2; + return isTerminalRecord(record) || record.event === 'control.upload' ? 1 : 0; +} + +export function createControlDiagnostics(options: Options): ControlDiagnostics { + const records: ControlDiagnosticRecord[] = []; + const now = options.now ?? Date.now; + const upload = options.fetch ?? fetch; + let droppedRecords = 0; + let droppedTerminalRecords = 0; + let uploadFailures = 0; + let lastUploadFailure: ControlDiagnosticRecord | undefined; + let sequence = 0; + let pending: PendingBatch | undefined; + let active: Promise | undefined; + let finalizing: Promise | undefined; + let timer: ReturnType | undefined; + let stopped = false; + let accepting = true; + const stop = new AbortController(); + + function accountDrop(record?: ControlDiagnosticRecord): void { + droppedRecords = Math.min(Number.MAX_SAFE_INTEGER, droppedRecords + 1); + if (record && isTerminalRecord(record)) { + droppedTerminalRecords = Math.min(Number.MAX_SAFE_INTEGER, droppedTerminalRecords + 1); + } + } + + function bufferRecord(record: ControlDiagnosticRecord): void { + if (records.length >= CONTROL_LOG_MAX_BUFFER_RECORDS) { + const priority = retentionPriority(record); + const latestHeartbeat = records.findLastIndex(queued => queued.event === 'control.heartbeat'); + const queuedPriority = (queued: ControlDiagnosticRecord, index: number): number => { + if ( + queued.event === 'control.heartbeat' && + (record.event === 'control.heartbeat' || index !== latestHeartbeat) + ) + return 0; + return retentionPriority(queued); + }; + let replace = + priority > 0 + ? records.findIndex((queued, index) => queuedPriority(queued, index) === 0) + : -1; + if (replace === -1 && priority > 0) { + replace = records.findIndex((queued, index) => queuedPriority(queued, index) === 1); + } + if (replace === -1) { + accountDrop(record); + return; + } + accountDrop(records.splice(replace, 1)[0]); + } + records.push(record); + } + + const onDiagnostic: ControlDiagnosticReporter = (event, fields) => { + try { + if (!accepting) return; + const record = createControlDiagnosticRecord(event, fields, now()); + if (!record) { + accountDrop(); + return; + } + bufferRecord(record); + if (timer && !pending && records.length >= CONTROL_LOG_MAX_BATCH_RECORDS) void flush(); + } catch { + return; + } + }; + + function reportUploadResult( + batch: PendingBatch, + category: ControlLogUploadResult, + statusCode?: number + ): void { + try { + const accepted = category === 'accepted'; + if (!accepted) uploadFailures = Math.min(Number.MAX_SAFE_INTEGER, uploadFailures + 1); + const record = createControlDiagnosticRecord( + 'control.upload', + { + phase: accepted ? 'completed' : 'failed', + category, + statusCode: + statusCode !== undefined && statusCode >= 100 && statusCode <= 599 + ? statusCode + : undefined, + sequence: batch.sequence, + attempt: batch.attempts, + failureCount: uploadFailures, + }, + now() + ); + if (!record) return; + if (!accepted) { + lastUploadFailure = record; + } else { + if (lastUploadFailure) bufferRecord(lastUploadFailure); + lastUploadFailure = undefined; + uploadFailures = 0; + } + console.error(JSON.stringify(record)); + } catch { + return; + } + } + + function nextBatch(): PendingBatch | undefined { + if (pending) return pending; + if (records.length === 0) return undefined; + const batch: ControlLogBatch = { + version: 1, + sequence, + droppedRecords, + droppedTerminalRecords, + records: [], + }; + let bytes = 256; + while ( + batch.records.length < records.length && + batch.records.length < CONTROL_LOG_MAX_BATCH_RECORDS + ) { + const record = records[batch.records.length]; + const recordBytes = new TextEncoder().encode(JSON.stringify(record)).byteLength + 1; + if (bytes + recordBytes > CONTROL_LOG_MAX_BATCH_BYTES) break; + bytes += recordBytes; + batch.records.push(record); + } + pending = { id: crypto.randomUUID(), body: JSON.stringify(batch), sequence, attempts: 0 }; + records.splice(0, batch.records.length); + sequence++; + droppedRecords = 0; + droppedTerminalRecords = 0; + return pending; + } + + async function performFlush(): Promise { + const batch = nextBatch(); + if (!batch || !options.uploadUrl || !options.uploadGrant || stopped) return; + const timeout = new AbortController(); + const signal = AbortSignal.any([timeout.signal, stop.signal]); + let timeoutId: ReturnType | undefined; + let onAbort: (() => void) | undefined; + let result: ControlLogUploadResult = 'network_failure'; + let statusCode: number | undefined; + batch.attempts = Math.min(Number.MAX_SAFE_INTEGER, batch.attempts + 1); + try { + const interrupted = new Promise((_resolve, reject) => { + onAbort = () => reject(new Error('Diagnostic upload interrupted')); + signal.addEventListener('abort', onAbort, { once: true }); + if (signal.aborted) onAbort(); + }); + timeoutId = setTimeout(() => timeout.abort(), options.uploadTimeoutMs ?? 3000); + const response = await Promise.race([ + upload(`${options.uploadUrl}/${batch.id}`, { + method: 'PUT', + headers: { + Authorization: `Bearer ${options.uploadGrant}`, + 'Content-Type': 'application/json', + }, + body: batch.body, + redirect: 'error', + signal, + }), + interrupted, + ]); + statusCode = response.status; + result = statusCode === 204 ? 'accepted' : 'http_rejection'; + if (statusCode === 204 && pending === batch) pending = undefined; + if (statusCode === 401 || statusCode === 403) { + stopped = true; + accepting = false; + if (timer) clearInterval(timer); + pending = undefined; + records.length = 0; + } + void response.body?.cancel().catch(() => undefined); + } catch { + result = stop.signal.aborted + ? 'cancelled' + : timeout.signal.aborted + ? 'timeout' + : 'network_failure'; + } finally { + if (timeoutId !== undefined) clearTimeout(timeoutId); + if (onAbort) signal.removeEventListener('abort', onAbort); + timeout.abort(); + reportUploadResult(batch, result, statusCode); + } + } + + function flush(): Promise { + if (active) return active; + if (stopped || !options.uploadUrl || !options.uploadGrant) return Promise.resolve(); + active = performFlush() + .catch(() => undefined) + .finally(() => { + active = undefined; + }); + return active; + } + + function start(): void { + if (timer || stopped || !options.uploadUrl || !options.uploadGrant) return; + void flush(); + timer = setInterval(() => { + void flush(); + }, options.intervalMs ?? 5000); + timer.unref(); + } + + function finalize(timeoutMs = 4000): Promise { + if (finalizing) return finalizing; + accepting = false; + if (timer) clearInterval(timer); + finalizing = (async () => { + const deadline = setTimeout(() => { + stopped = true; + stop.abort(); + }, timeoutMs); + try { + await active; + while ( + !stopped && + options.uploadUrl && + options.uploadGrant && + (pending || records.length) + ) { + await flush(); + if (pending) break; + } + } finally { + clearTimeout(deadline); + stopped = true; + stop.abort(); + } + })().catch(() => undefined); + return finalizing; + } + + return { onDiagnostic, start, flush, finalize }; +} diff --git a/services/cloud-agent-next/wrapper/src/control/main.ts b/services/cloud-agent-next/wrapper/src/control/main.ts index 1549832af7..c6f1ad2515 100644 --- a/services/cloud-agent-next/wrapper/src/control/main.ts +++ b/services/cloud-agent-next/wrapper/src/control/main.ts @@ -16,13 +16,30 @@ import { import { eventKiloSessionId, sessionEventIdentity, updateSessionSnapshots } from './feed'; import { createControlTerminalRuntime } from './terminal-runtime'; import { createWorktreeKiloRuntimes } from './worktree-runtime'; +import { createControlDiagnostics, type ControlDiagnostics } from './diagnostics'; +import { controlLogWrapperIdSchema } from '../../../src/shared/control-diagnostics.js'; -function main(): void { +const retirementCauses = new Map([ + ['Kilo event feed is no longer healthy', 'event_feed_unhealthy'], + ['Sandbox control connection lost', 'control_disconnected'], + ['Preparation event delivery failed', 'preparation_delivery_failed'], + ['Sandbox shutting down', 'requested_shutdown'], + ['Wrapper received SIGTERM', 'sigterm'], + ['Wrapper received SIGINT', 'sigint'], + ['Wrapper uncaught exception', 'uncaught_exception'], + ['Wrapper unhandled rejection', 'unhandled_rejection'], + ['Kilo cancellation failed', 'cancellation_failed'], + ['Session outcome delivery failed', 'outcome_delivery_failed'], + ['Execution exceeded the 60 minute limit', 'execution_deadline'], + ['Session preparation timed out', 'preparation_deadline'], +]); + +function main(diagnostics: ControlDiagnostics, wrapperInstanceId: string): void { const controlConfig = { SANDBOX_CONTROL_URL: process.env.SANDBOX_CONTROL_URL, SANDBOX_CONTROL_CREDENTIAL: process.env.SANDBOX_CONTROL_CREDENTIAL, PROVIDER_INSTANCE_ID: process.env.PROVIDER_INSTANCE_ID, - wrapperInstanceId: crypto.randomUUID(), + wrapperInstanceId, }; delete process.env.SANDBOX_CONTROL_CREDENTIAL; @@ -32,6 +49,7 @@ function main(): void { let shuttingDown = false; let heartbeatReason: SandboxHeartbeatPayload['kilo']['reason']; const kiloRuntimes = createWorktreeKiloRuntimes({ + onDiagnostic: diagnostics.onDiagnostic, onEvent: (runtime, event) => { const identity = sessionEventIdentity({ ...event, @@ -71,6 +89,7 @@ function main(): void { }) : undefined; const deps: HandlerDeps = { + onDiagnostic: diagnostics.onDiagnostic, kiloRuntimes, version: WRAPPER_VERSION, get kiloReady() { @@ -109,32 +128,64 @@ function main(): void { if (shuttingDown) return; shuttingDown = true; heartbeatReason = diagnosticReason; - logToFile(`control-plane wrapper retiring: ${reason}`); - try { - control?.sendEvent?.('sandbox.heartbeat', withHeartbeatReason(buildHeartbeatPayload(deps))); - } catch { - logToFile('control-plane final heartbeat delivery failed'); - } - const stopped = cancelControlTasks(deps, reason, exitCode === 0 ? 'cancelled' : 'failed'); - abort.abort(); - terminalRuntime?.shutdown(); + const shutdownAt = Date.now(); const finish = (): void => { - control?.close(); - kiloRuntimes.shutdown(); - process.exit(exitCode); + try { + control?.close(); + } finally { + try { + kiloRuntimes.shutdown(); + } finally { + process.exit(exitCode); + } + } }; const deadline = setTimeout(finish, KILO_CONTROL_REQUEST_TIMEOUT_MS); - void stopped.finally(() => { - clearTimeout(deadline); - setTimeout(finish, 0); + diagnostics.onDiagnostic('wrapper.lifecycle', { + phase: 'stopping', + exitCode, + retirementCause: + retirementCauses.get(reason) ?? + (diagnosticReason.startsWith('feed_') ? 'event_feed_unhealthy' : 'unknown'), }); + void diagnostics.flush(); + logToFile(`control-plane wrapper retiring exitCode=${exitCode}`); + const stopped = (async () => { + try { + control?.sendEvent?.('sandbox.heartbeat', withHeartbeatReason(buildHeartbeatPayload(deps))); + } catch { + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'failed', exitCode }); + logToFile('control-plane final heartbeat delivery failed'); + } + const tasks = cancelControlTasks(deps, reason, exitCode === 0 ? 'cancelled' : 'failed'); + try { + abort.abort(); + terminalRuntime?.shutdown(); + } finally { + await tasks; + } + })(); + void stopped + .catch(() => undefined) + .then(async () => { + const remaining = KILO_CONTROL_REQUEST_TIMEOUT_MS - (Date.now() - shutdownAt) - 100; + await diagnostics.finalize(Math.max(1, Math.min(4000, remaining))); + }) + .finally(() => { + clearTimeout(deadline); + setTimeout(finish, 0); + }); } process.once('SIGTERM', () => shutdown(0, 'Wrapper received SIGTERM')); process.once('SIGINT', () => shutdown(0, 'Wrapper received SIGINT')); + process.once('uncaughtException', () => shutdown(1, 'Wrapper uncaught exception')); + process.once('unhandledRejection', () => shutdown(1, 'Wrapper unhandled rejection')); control = maybeStartSandboxControlClient(controlConfig, logToFile, { + onDiagnostic: diagnostics.onDiagnostic, wrapperVersion: WRAPPER_VERSION, isReady: () => deps.kiloReady, + onConnected: () => diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'ready', ok: true }), onDisconnected: () => shutdown(1, 'Sandbox control connection lost', 'control_disconnected'), onRequest: (operation, session, payload) => handleControlRequest(operation, session, payload, { @@ -155,12 +206,30 @@ function main(): void { getHeartbeatPayload: async () => withHeartbeatReason(await refreshHeartbeatPayload(deps)), }); + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'started', ok: Boolean(control) }); logToFile(`control-plane wrapper ready callHome=${Boolean(control)}`); } +const configuredWrapperId = controlLogWrapperIdSchema.safeParse( + process.env.CONTROL_WRAPPER_INSTANCE_ID +); +const wrapperInstanceId = configuredWrapperId.success + ? configuredWrapperId.data + : crypto.randomUUID(); +const diagnostics = createControlDiagnostics({ + uploadUrl: process.env.CONTROL_LOG_UPLOAD_URL, + uploadGrant: process.env.CONTROL_LOG_UPLOAD_GRANT, +}); +delete process.env.CONTROL_LOG_UPLOAD_URL; +delete process.env.CONTROL_LOG_UPLOAD_GRANT; +delete process.env.CONTROL_WRAPPER_INSTANCE_ID; +diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'starting' }); +diagnostics.start(); + try { - main(); + main(diagnostics, wrapperInstanceId); } catch { + diagnostics.onDiagnostic('wrapper.lifecycle', { phase: 'start_failed' }); logToFile('control-plane wrapper failed'); - process.exit(1); + void diagnostics.finalize().finally(() => process.exit(1)); } diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-client.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-client.ts index 2b759867d4..0ead0a3316 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-client.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-client.ts @@ -1,13 +1,19 @@ import { setTimeout as delay } from 'node:timers/promises'; +import { + emitControlDiagnostic, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import { z } from 'zod'; import { prepareIngestFrame } from '../../../src/shared/ingest-frame.js'; import type { IngestEvent } from '../../../src/shared/protocol.js'; import { + CONTROL_OPERATIONS, MAX_SANDBOX_CONTROL_FRAME_BYTES, SANDBOX_CONTROL_AUTO_PING, SANDBOX_CONTROL_PROTOCOL_VERSION, SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, controlFrameSchema, + controlErrorCodes, sandboxHelloResultSchema, sessionEventPayloadSchema, type ControlError, @@ -39,6 +45,7 @@ export type SandboxControlClientOptions = { onRequest?: SandboxControlRequestHandler; onDisconnected?: () => void; log?: (message: string) => void; + onDiagnostic?: ControlDiagnosticReporter; reconnectDelayMs?: (attempt: number) => number; }; @@ -137,10 +144,18 @@ export function createSandboxControlClient( ): SandboxControlClient { const wrapperInstanceId = options.wrapperInstanceId; let state: ClientState = { kind: 'idle' }; + let eventSequence = 0; + const diagnostic = (phase: string, ws?: WebSocket): void => + emitControlDiagnostic(options.onDiagnostic, 'control.socket', { + phase, + readyState: ws?.readyState, + bufferedBytes: ws?.bufferedAmount, + }); function retireConnection(ws: WebSocket): void { if (state.kind !== 'ready' || state.socket !== ws) return; const current = state; + diagnostic('retired', ws); state = { kind: 'closed' }; current.dispose(); options.onDisconnected?.(); @@ -148,6 +163,22 @@ export function createSandboxControlClient( async function dispatchRequest(ws: WebSocket, request: RequestFrame): Promise { if (state.kind !== 'ready' || state.socket !== ws || !options.onRequest) return; + const startedAt = Date.now(); + let errorCode: string | undefined; + let retryable: boolean | undefined; + const requestDiagnostic = (phase: string, ok?: boolean): void => + emitControlDiagnostic(options.onDiagnostic, 'control.request', { + phase, + operation: CONTROL_OPERATIONS.find(operation => operation === request.operation) ?? 'other', + requestId: request.requestId, + sessionId: request.session?.sessionId, + kiloSessionId: request.session?.kiloSessionId, + elapsedMs: Date.now() - startedAt, + ok, + errorCode, + retryable, + }); + requestDiagnostic('received'); let outcome: Awaited>; try { outcome = await options.onRequest(request.operation, request.session, request.payload); @@ -158,8 +189,17 @@ export function createSandboxControlClient( }; } - if (state.kind !== 'ready' || state.socket !== ws) return; + if (!outcome.ok) { + errorCode = controlErrorCodes.find(code => code === outcome.error?.code) ?? 'other'; + retryable = outcome.error?.retryable; + } + requestDiagnostic('completed', outcome.ok); + if (state.kind !== 'ready' || state.socket !== ws) { + requestDiagnostic('response_skipped', outcome.ok); + return; + } if (ws.readyState !== 1) { + requestDiagnostic('response_failed', outcome.ok); retireConnection(ws); return; } @@ -180,7 +220,9 @@ export function createSandboxControlClient( }), }) ); + requestDiagnostic('response_sent', outcome.ok); } catch { + requestDiagnostic('response_failed', outcome.ok); retireConnection(ws); } } @@ -190,6 +232,7 @@ export function createSandboxControlClient( deadlineAt: number ): Promise { return new Promise((resolve, reject) => { + diagnostic('opening'); const ws = (options.openWebSocket ?? defaultOpenWebSocket)(options.url, options.credential); const signal = starting.abort.signal; const requestId = crypto.randomUUID(); @@ -203,27 +246,41 @@ export function createSandboxControlClient( ws.removeEventListener('open', onOpen); ws.removeEventListener('message', onMessage); ws.removeEventListener('error', onFailure); - ws.removeEventListener('close', onFailure); + ws.removeEventListener('close', onClose); if (ws.readyState === 0 || ws.readyState === 1) ws.close(); } function fail(): void { if (phase === 'finished') return; + diagnostic('failed', ws); dispose(); reject(new Error('sandbox control connect failed')); } function onFailure(): void { + diagnostic('failed', ws); if (state.kind === 'ready' && state.socket === ws) retireConnection(ws); else fail(); } + function onClose(event: CloseEvent): void { + emitControlDiagnostic(options.onDiagnostic, 'control.socket', { + phase: 'closed', + closeCode: event.code, + wasClean: event.wasClean, + readyState: ws.readyState, + bufferedBytes: ws.bufferedAmount, + }); + onFailure(); + } + function onOpen(): void { if (phase !== 'opening' || state !== starting) return; if (Date.now() >= deadlineAt) { fail(); return; } + diagnostic('opened', ws); phase = 'hello'; clearTimeout(timeout); timeout = setTimeout(fail, Math.min(HELLO_TIMEOUT_MS, deadlineAt - Date.now())); @@ -240,6 +297,7 @@ export function createSandboxControlClient( }; try { ws.send(JSON.stringify(hello)); + diagnostic('hello_sent', ws); } catch { onFailure(); } @@ -273,6 +331,7 @@ export function createSandboxControlClient( return; } phase = 'status'; + diagnostic('hello_accepted', ws); return; } if ( @@ -296,12 +355,15 @@ export function createSandboxControlClient( const keepalive = setInterval(() => { if (state.kind !== 'ready' || state.socket !== ws) return; if (ws.readyState !== 1) { + diagnostic('keepalive_failed', ws); retireConnection(ws); return; } try { ws.send(SANDBOX_CONTROL_AUTO_PING); + diagnostic('keepalive_sent', ws); } catch { + diagnostic('keepalive_failed', ws); retireConnection(ws); } }, KEEPALIVE_INTERVAL_MS); @@ -314,6 +376,7 @@ export function createSandboxControlClient( dispose(); }, }; + diagnostic('ready', ws); resolve(); } @@ -321,7 +384,7 @@ export function createSandboxControlClient( ws.addEventListener('open', onOpen); ws.addEventListener('message', onMessage); ws.addEventListener('error', onFailure); - ws.addEventListener('close', onFailure); + ws.addEventListener('close', onClose); if (signal.aborted || ws.readyState > 1) fail(); else if (ws.readyState === 1) onOpen(); }); @@ -341,6 +404,10 @@ export function createSandboxControlClient( signal.throwIfAborted(); if (Date.now() >= deadlineAt) throw new Error('sandbox control startup timeout'); try { + emitControlDiagnostic(options.onDiagnostic, 'control.socket', { + phase: 'connect_attempt', + attempt, + }); await connectAttempt(starting, deadlineAt); return; } catch { @@ -353,6 +420,11 @@ export function createSandboxControlClient( (options.reconnectDelayMs ?? defaultReconnectDelayMs)(attempt) ); options.log?.(`sandbox control reconnect scheduled in ${delayMs}ms (connect failed)`); + emitControlDiagnostic(options.onDiagnostic, 'control.socket', { + phase: 'retry_scheduled', + attempt, + delayMs, + }); await delay(delayMs, undefined, { signal }); } } @@ -383,6 +455,7 @@ export function createSandboxControlClient( close(): void { const current = state; + diagnostic('closed', current.kind === 'ready' ? current.socket : undefined); state = { kind: 'closed' }; if (current.kind === 'starting') current.abort.abort(new Error('sandbox control client closed')); @@ -390,16 +463,48 @@ export function createSandboxControlClient( }, sendEvent(event: string, payload: unknown, session?: SessionEventIdentity): boolean { - if (state.kind !== 'ready') return false; + eventSequence += 1; + const category = + event === 'session.event' + ? payload !== null && + typeof payload === 'object' && + 'type' in payload && + payload.type === 'session.message.outcome' + ? 'outcome' + : 'session_event' + : event === 'session.preparing' + ? 'preparing' + : event === 'sandbox.heartbeat' + ? 'heartbeat' + : event === 'sandbox.ready' + ? 'ready' + : 'other'; + const eventDiagnostic = (phase: string, bytes?: number): void => + emitControlDiagnostic(options.onDiagnostic, 'control.event', { + phase, + category, + sequence: eventSequence, + kiloSessionId: session?.kiloSessionId, + bytes, + bufferedBytes: state.kind === 'ready' ? state.socket.bufferedAmount : undefined, + }); + if (state.kind !== 'ready') { + eventDiagnostic('skipped'); + return false; + } const { socket } = state; if (socket.readyState !== 1) { + eventDiagnostic('send_failed'); retireConnection(socket); return false; } try { - socket.send(serializeEvent(event, payload, session)); + const serialized = serializeEvent(event, payload, session); + socket.send(serialized); + eventDiagnostic('sent', Buffer.byteLength(serialized)); return true; } catch { + eventDiagnostic('send_failed'); retireConnection(socket); return false; } diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.test.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.test.ts index fcbca22409..1a8e196b0b 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.test.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.test.ts @@ -3997,7 +3997,7 @@ describe('control wrapper heartbeat source policy', () => { 'shuttingDown = true;', 'heartbeatReason = diagnosticReason;', "control?.sendEvent?.('sandbox.heartbeat', withHeartbeatReason(buildHeartbeatPayload(deps)))", - 'const stopped = cancelControlTasks(deps, reason,', + 'cancelControlTasks(deps, reason,', 'abort.abort();', ].map(step => source.indexOf(step)); expect(steps.every(index => index >= 0)).toBe(true); diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts index e3ea306c60..717d293c5d 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts @@ -1,4 +1,8 @@ import path from 'node:path'; +import { + emitControlDiagnostic, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import { SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, SANDBOX_CONTROL_EXECUTION_TIMEOUT_MS, @@ -211,6 +215,7 @@ export type HandlerDeps = { emitSessionEvent: (session: SessionRequestIdentity, payload: SessionEventPayload) => void; retireRuntime: (reason: string) => void; onShutdown?: () => void; + onDiagnostic?: ControlDiagnosticReporter; emitPreparing?: AttachPreparingEmitter; terminalRuntime?: ControlTerminalRuntime; applyAttach?: typeof applySessionAttach; @@ -336,6 +341,17 @@ function startSessionTask( deps: HandlerDeps, run: (task: OwnedSessionTask) => Promise ): OwnedSessionTask { + const startedAt = Date.now(); + const diagnostic = (phase: string): void => + emitControlDiagnostic(deps.onDiagnostic, 'session.task', { + sessionId: session.sessionId, + kiloSessionId: session.kiloSessionId, + messageId: identity.messageId, + kind: identity.kind, + phase, + elapsedMs: Date.now() - startedAt, + }); + diagnostic('started'); const completion = Promise.withResolvers(); const controller = new AbortController(); const task: OwnedSessionTask = { @@ -359,6 +375,7 @@ function startSessionTask( identity.kind !== 'preparation' ? 'Execution exceeded the 60 minute limit' : 'Session preparation timed out'; + diagnostic('deadline_expired'); controller.abort(new ControlTaskCancellation('failed', reason)); deps.retireRuntime(reason); }, @@ -381,6 +398,7 @@ function startSessionTask( delete snapshot.pendingInputs; } } + diagnostic(result.ok ? 'finished' : 'failed'); completion.resolve(result); }); return task; @@ -854,6 +872,17 @@ async function executePrompt( const { session, signal } = task; const { kiloClient, env } = runtime; const { messageId, turn, agent } = request; + const startedAt = Date.now(); + const diagnostic = (phase: string, status?: SessionMessageOutcome['status']): void => + emitControlDiagnostic(deps.onDiagnostic, 'session.execution', { + sessionId: session.sessionId, + kiloSessionId: session.kiloSessionId, + messageId, + phase, + status, + elapsedMs: Date.now() - startedAt, + aborted: signal.aborted, + }); let outcome: SessionMessageOutcome; let result = ok({}); let failureReason = 'Kilo execution failed'; @@ -891,6 +920,7 @@ async function executePrompt( { signal } ); signal.throwIfAborted(); + diagnostic('prompt_started'); completion = await withTimeoutAndAbort( kiloClient.sendPrompt({ ...options, @@ -900,14 +930,18 @@ async function executePrompt( }), deadline ); + diagnostic('prompt_completed'); } else if (turn.command === 'compact') { if (!agent.model) throw new Error('Model is required for compact'); failureReason = 'Context condensation failed'; emitStatus('Condensing context...'); + diagnostic('compact_started'); await summarizeOwnedSession(task, kiloClient, { providerID: 'kilo', modelID: agent.model }); + diagnostic('compact_completed'); signal.throwIfAborted(); emitStatus('Context condensed successfully'); } else { + diagnostic('command_started'); completion = await withTimeoutAndAbort( kiloClient.sendCommand({ ...options, @@ -919,13 +953,16 @@ async function executePrompt( }), deadline ); + diagnostic('command_completed'); } signal.throwIfAborted(); const error = completion?.info.error; if (!error && (request.finalization?.autoCommit || request.finalization?.condenseOnComplete)) { task.kind = 'finalizing'; + diagnostic('finalization_started'); if (request.finalization.autoCommit) { failureReason = 'Auto-commit failed'; + diagnostic('autocommit_started'); const committed = await (deps.runAutoCommit ?? runAutoCommit)({ workspacePath: session.directory, kiloClient, @@ -936,6 +973,7 @@ async function executePrompt( }); signal.throwIfAborted(); if (!committed.success) throw new Error('Auto-commit failed'); + diagnostic('autocommit_completed'); } if (request.finalization.condenseOnComplete) { failureReason = 'Context condensation failed'; @@ -946,7 +984,9 @@ async function executePrompt( : undefined; if (!model) throw new Error('Model is required for condensation'); emitStatus('Condensing context...'); + diagnostic('condense_started'); await summarizeOwnedSession(task, kiloClient, model, true); + diagnostic('condense_completed'); signal.throwIfAborted(); emitStatus('Context condensed successfully'); } @@ -959,6 +999,7 @@ async function executePrompt( } : { messageId, status: 'completed' }; } catch { + diagnostic('execution_failed'); const cancellation: unknown = signal.reason; outcome = { messageId, @@ -967,18 +1008,24 @@ async function executePrompt( cancellation instanceof ControlTaskCancellation ? cancellation.message : failureReason, }; try { + diagnostic('abort_started'); await abortKiloSession(session, kiloClient); + diagnostic('abort_completed'); } catch (error) { + diagnostic('abort_failed'); deps.retireRuntime('Kilo cancellation failed'); result = kiloFailure(error); } } try { + diagnostic('outcome_sending', outcome.status); deps.emitSessionEvent(session, { type: 'session.message.outcome', properties: sessionMessageOutcomeSchema.parse(outcome), }); + diagnostic('outcome_sent', outcome.status); } catch { + diagnostic('outcome_failed', outcome.status); deps.retireRuntime('Session outcome delivery failed'); return fail('not_ready', 'Session outcome delivery failed', false); } diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-runtime.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-runtime.ts index 8d08766cc4..29888d5106 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-runtime.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-runtime.ts @@ -1,4 +1,8 @@ import { withTimeoutAndAbort } from '../utils.js'; +import { + emitControlDiagnostic, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import { createSandboxControlClient, type SandboxControlClient, @@ -21,6 +25,7 @@ type StartOptions = { onDisconnected?: () => void; getHeartbeatPayload?: () => unknown; isReady?: () => boolean; + onDiagnostic?: ControlDiagnosticReporter; }; type SandboxControlEventFeedOptions = { @@ -28,6 +33,7 @@ type SandboxControlEventFeedOptions = { open: (signal: AbortSignal) => Promise<{ stream?: AsyncIterable }>; consume: (stream: AsyncIterable) => Promise; onUnexpectedClose: (error: unknown) => void; + onDiagnostic?: ControlDiagnosticReporter; now?: () => number; }; @@ -86,6 +92,7 @@ export async function startSandboxControlEventFeed( let feed: { stream?: AsyncIterable }; let iterator: AsyncIterator; let first: IteratorResult; + emitControlDiagnostic(options.onDiagnostic, 'control.feed', { phase: 'opening' }); try { feed = await withTimeoutAndAbort(options.open(signal), { signal, @@ -108,20 +115,35 @@ export async function startSandboxControlEventFeed( throw new Error('Kilo global event feed ended before startup'); } } catch (error) { + emitControlDiagnostic(options.onDiagnostic, 'control.feed', { phase: 'start_failed' }); controller.abort(); throw error; } let lastEventAt = now(); + let eventsReceived = 1; + const diagnostic = (phase: string): void => + emitControlDiagnostic(options.onDiagnostic, 'control.feed', { + phase, + lastEventAt, + ageMs: Math.max(0, now() - lastEventAt), + eventsReceived, + }); + diagnostic('started'); const isFresh = () => !signal.aborted && now() - lastEventAt < KILO_FEED_FRESHNESS_TIMEOUT_MS; - const fail = (error: unknown): void => { + const fail = (error: unknown, phase: 'stale' | 'ended' | 'failed'): void => { if (signal.aborted) return; + diagnostic(phase); controller.abort(); options.onUnexpectedClose(error); }; const freshnessTimer = setInterval(() => { if (!isFresh()) - fail(new KiloEventFeedError('feed_stale', 'Kilo global event feed stopped responding')); + fail( + new KiloEventFeedError('feed_stale', 'Kilo global event feed stopped responding'), + 'stale' + ); + else diagnostic('freshness'); }, 10_000); freshnessTimer.unref(); signal.addEventListener('abort', () => clearInterval(freshnessTimer), { once: true }); @@ -133,12 +155,14 @@ export async function startSandboxControlEventFeed( const next = await iterator.next(); if (signal.aborted || next.done) return; if (isFeedConnectedEvent(next.value)) { + diagnostic('reconnected'); throw new KiloEventFeedError( 'feed_reconnected', 'Kilo global event feed reconnected with a delivery gap' ); } lastEventAt = now(); + eventsReceived += 1; yield next.value; } } finally { @@ -147,8 +171,8 @@ export async function startSandboxControlEventFeed( } void options.consume(establishedFeed()).then( - () => fail(new KiloEventFeedError('feed_ended', 'Kilo global event feed ended')), - error => fail(error) + () => fail(new KiloEventFeedError('feed_ended', 'Kilo global event feed ended'), 'ended'), + error => fail(error, 'failed') ); return { isFresh }; } @@ -169,11 +193,21 @@ export function maybeStartSandboxControlClient( let heartbeat: ReturnType | null = null; let heartbeatInFlight = false; let closed = false; + let heartbeatSequence = 0; + let lastSentAt: number | undefined; + const diagnostic = (phase: string): void => + emitControlDiagnostic(options.onDiagnostic, 'control.heartbeat', { + phase, + sequence: heartbeatSequence, + lastSentAt, + sinceLastSentMs: lastSentAt === undefined ? undefined : Date.now() - lastSentAt, + }); function stopHeartbeat(): void { if (!heartbeat) return; clearTimeout(heartbeat); heartbeat = null; + diagnostic('stopped'); } function handleDisconnected(): void { @@ -192,16 +226,28 @@ export function maybeStartSandboxControlClient( ) return; heartbeatInFlight = true; + heartbeatSequence += 1; + diagnostic('sending'); try { const payload = await options.getHeartbeatPayload(); if (closed || options.isReady?.() === false) return; try { - if (!active.sendEvent?.('sandbox.heartbeat', payload)) handleDisconnected(); + if (!active.sendEvent?.('sandbox.heartbeat', payload)) { + diagnostic('send_failed'); + handleDisconnected(); + } else { + lastSentAt = Date.now(); + diagnostic('sent'); + } } catch { + diagnostic('send_threw'); handleDisconnected(); } } catch { - if (!closed) log('sandbox control heartbeat failed'); + if (!closed) { + diagnostic('send_threw'); + log('sandbox control heartbeat failed'); + } } finally { heartbeatInFlight = false; if (!closed && options.isReady?.() !== false) { @@ -236,6 +282,7 @@ export function maybeStartSandboxControlClient( log, onDisconnected: handleDisconnected, ...(options.onRequest ? { onRequest: options.onRequest } : {}), + ...(options.onDiagnostic ? { onDiagnostic: options.onDiagnostic } : {}), }); const originalClose = client.close.bind(client); diff --git a/services/cloud-agent-next/wrapper/src/control/worktree-runtime.ts b/services/cloud-agent-next/wrapper/src/control/worktree-runtime.ts index 7225959bb9..bcf4a51ef6 100644 --- a/services/cloud-agent-next/wrapper/src/control/worktree-runtime.ts +++ b/services/cloud-agent-next/wrapper/src/control/worktree-runtime.ts @@ -6,6 +6,10 @@ import path from 'node:path'; import { createKiloClient } from '@kilocode/sdk'; import { createKiloClient as createKiloEventClient } from '@kilocode/sdk/v2/client'; import { CONTROL_PLANE_SANDBOX_PERMISSION } from '../../../src/shared/control-plane-permission.js'; +import { + emitControlDiagnostic, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import type { ControlErrorCode, SessionAttachPayload, @@ -272,6 +276,7 @@ export function createWorktreeKiloRuntimes(options: { inheritedEnv?: NodeJS.ProcessEnv; startServer?: (options: ServerOptions) => Promise; onEvent?: (runtime: WorktreeKiloRuntime, event: WorktreeKiloEvent) => void; + onDiagnostic?: ControlDiagnosticReporter; onUnexpectedClose: (failure: WorktreeKiloFailure) => void; }): WorktreeKiloRuntimes { const entries = new Map(); @@ -419,6 +424,11 @@ export function createWorktreeKiloRuntimes(options: { entry.feed = await withTimeoutAndAbort( startSandboxControlEventFeed({ signal: abort.signal, + onDiagnostic: (event, fields) => + emitControlDiagnostic(options.onDiagnostic, event, { + ...fields, + scopeId: entry.kilo.scopeId, + }), open: signal => eventClient.global.event({ signal, From 3e42b051ca0e529c33ac59f2120fdbeb2e4e1c7e Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Tue, 1 Sep 2026 21:09:50 +0200 Subject: [PATCH 2/6] feat(cloud-agent-next): trace shared-worktree lifecycles --- services/cloud-agent-next/DEBUG.md | 8 + .../src/router/handlers/session-worktree.ts | 437 +++++++++++++++++- .../src/router/handlers/worktree-deletion.ts | 115 ++++- .../src/sandbox-control/worktree-deletion.ts | 200 +++++--- .../src/sandbox-control/worktree-ownership.ts | 134 ++++-- .../src/shared/control-diagnostics.ts | 44 +- .../wrapper/src/control/apply-attach.ts | 60 ++- .../wrapper/src/control/delete-worktree.ts | 166 +++++-- .../wrapper/src/control/main.ts | 3 + .../src/control/sandbox-control-handlers.ts | 25 + 10 files changed, 985 insertions(+), 207 deletions(-) diff --git a/services/cloud-agent-next/DEBUG.md b/services/cloud-agent-next/DEBUG.md index 86b5cb3f94..338716ac5b 100644 --- a/services/cloud-agent-next/DEBUG.md +++ b/services/cloud-agent-next/DEBUG.md @@ -190,6 +190,14 @@ Worker/DO diagnostics remain in Cloudflare logs/Axiom, not these wrapper archive Uploads are best effort: an abrupt kill or network failure can lose unuploaded records. The buffer holds 512 records and each batch holds up to 128 records or 256 KiB. A recorded WebSocket send is a local handoff, not proof that a session DO applied the event; correlate it with the Worker forwarding and durable message-transition logs. +### Shared-worktree Lifecycle + +`worktreeId` identifies the shared checkout and chat group; `sessionId` is the Cloud Agent chat ID and `kiloSessionId` is the Kilo session ID. Worker `worktree_chat_*` events cover admission, progress, reconciliation, settlement, and the result, correlating the source and resulting chats with the existing worktree. Their durations are phase-local; a reconciliation-pending result describes required recovery, while the separate reconciliation and settlement records report persistence outcomes. Wrapper attachment does not receive an explicit worktree ID, so join its chat IDs with Worker records rather than treating a credential `scopeId` or directory as the worktree identity. + +Worker `worktree_ownership` records distinguish `exclusive`, `shared`, and `unresolved` decisions and identify the evidence used. Unresolved ownership is not proof of sharing or permission to destroy a sandbox. `worktree_runtime_cleanup` records the cleanup strategy, failure stage, and confirmed journal flags. `worktree_cleanup_location` confirms resources cleaned at one runtime location; it is not overall deletion completion. Only `worktree_deletion` with `result=completed` or `result=replayed` confirms the complete deletion request. + +Wrapper `control.request` attachment summaries separate `workspaceAction` (reuse or bootstrap) from `sessionResolution` (existing, restored, or created chat). Worktree deletion records include the first fence/drain, preparation/deletion outcome, stage, and session count. These records contain IDs and fixed outcomes, not repository paths, credentials, or session content. + ## Interpreting Common States - Worker queueing succeeds, but no wrapper logs appear: diff --git a/services/cloud-agent-next/src/router/handlers/session-worktree.ts b/services/cloud-agent-next/src/router/handlers/session-worktree.ts index a70dcb26f8..53c978842b 100644 --- a/services/cloud-agent-next/src/router/handlers/session-worktree.ts +++ b/services/cloud-agent-next/src/router/handlers/session-worktree.ts @@ -21,6 +21,7 @@ import { CurrentSessionMetadataSchema, type SessionMetadata, } from '../../persistence/session-metadata.js'; +import { logControlDiagnostic } from '../../sandbox-control/diagnostics.js'; import { getSandboxSessionStub } from '../../sandbox-session/session-stub.js'; import { generateSessionId, isControlPlaneOwner } from '../../session-plane.js'; import { @@ -350,9 +351,25 @@ function assertRegisteredMetadata( } async function markPending(db: WorkerDb, rowId: string): Promise { + const startedAt = Date.now(); try { - await markReconcilePending(db, { rowId }); + const row = await markReconcilePending(db, { rowId }); + logControlDiagnostic('worktree_chat_reconciliation', { + operationRowId: rowId, + result: row?.status === 'reconcile_pending' ? 'pending' : 'not_pending', + durationMs: Date.now() - startedAt, + }); } catch { + logControlDiagnostic( + 'worktree_chat_reconciliation', + { + operationRowId: rowId, + result: 'mark_failed', + stage: 'reconciliation_mark', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); return; } } @@ -364,6 +381,15 @@ async function createOwnershipRow( ctx: TRPCContext, progress: OperationProgress ): Promise { + const startedAt = Date.now(); + const diagnostic = { + operationRowId: rowId, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: source.ownership.cloudAgentSessionId, + sourceKiloSessionId: source.ownership.kiloSessionId, + cloudAgentSessionId: progress.cloudAgentSessionId, + kiloSessionId: progress.kiloSessionId, + }; let response: unknown; try { response = await ctx.env.SESSION_INGEST.createSessionForCloudAgent({ @@ -381,23 +407,92 @@ async function createOwnershipRow( gitUrl: source.ownership.gitUrl ?? canonicalRepositoryUrl(source.repository), }); } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'ownership', + reason: 'ownership_outcome_unknown', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw error; } const parsed = ingestResultSchema.safeParse(response); if (!parsed.success || parsed.data.status === 'in_progress') { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'ownership', + reason: parsed.success ? 'ownership_in_progress' : 'ownership_response_invalid', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw creationInProgress(); } if (parsed.data.status === 'rejected') { - await settleOperation(db, { rowId, status: 'failed', outcomeCode: 'ownership_row_rejected' }); + try { + const settlement = await settleOperation(db, { + rowId, + status: 'failed', + outcomeCode: 'ownership_row_rejected', + }); + logControlDiagnostic('worktree_chat_settlement', { + ...diagnostic, + requestedStatus: 'failed', + outcomeCode: 'ownership_row_rejected', + settled: settlement.settled, + durationMs: Date.now() - startedAt, + }); + } catch (error) { + logControlDiagnostic( + 'worktree_chat_settlement', + { + ...diagnostic, + result: 'failed', + stage: 'ownership_settlement', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'rejected', + stage: 'ownership', + reason: 'ownership_row_rejected', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); throw creationFailed(); } if ( parsed.data.clone.sessionId !== progress.kiloSessionId || parsed.data.clone.copiedItemCount !== 0 ) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'ownership', + reason: 'ownership_result_mismatch', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw creationInProgress(); } @@ -408,6 +503,18 @@ async function completeOperation( rowId: string, progress: OperationProgress ): Promise { + const startedAt = Date.now(); + const diagnostic = { + operationRowId: rowId, + worktreeId: progress.worktreeId, + cloudAgentSessionId: progress.cloudAgentSessionId, + kiloSessionId: progress.kiloSessionId, + }; + logControlDiagnostic('worktree_chat_settlement', { + ...diagnostic, + requestedStatus: 'completed', + result: 'started', + }); try { const settlement = await settleOperation(db, { rowId, @@ -415,8 +522,25 @@ async function completeOperation( outcomeCode: 'ok', canonicalResult: resultFromProgress(progress), }); + logControlDiagnostic('worktree_chat_settlement', { + ...diagnostic, + requestedStatus: 'completed', + outcomeCode: 'ok', + settled: settlement.settled, + durationMs: Date.now() - startedAt, + }); if (!settlement.settled) throw creationInProgress(); } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'completion_settlement', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw error; } @@ -429,6 +553,15 @@ async function registerWorktreeSession( ctx: TRPCContext, progress: OperationProgress ): Promise { + const startedAt = Date.now(); + const diagnostic = { + operationRowId: rowId, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: source.ownership.cloudAgentSessionId, + sourceKiloSessionId: source.ownership.kiloSessionId, + cloudAgentSessionId: progress.cloudAgentSessionId, + kiloSessionId: progress.kiloSessionId, + }; const registrationInput = buildRegistrationInput(source, ctx, progress); let registrationAttempted = false; let response: unknown; @@ -441,6 +574,11 @@ async function registerWorktreeSession( const existing = await stub.getMetadata(); if (existing) { assertRegisteredMetadata(existing, source, progress); + logControlDiagnostic('worktree_chat_reconciliation', { + ...diagnostic, + result: 'registration_recovered', + durationMs: Date.now() - startedAt, + }); return { success: true }; } } @@ -450,12 +588,34 @@ async function registerWorktreeSession( 'registerSession' ); } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'registration', + reason: 'registration_outcome_unknown', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw error; } const result = registrationResultSchema.safeParse(response); if (!result.success) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'registration', + reason: 'registration_response_invalid', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw creationInProgress(); } @@ -467,14 +627,56 @@ async function registerWorktreeSession( onlyIfEmpty: true, }); } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'registration_cleanup', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); await markPending(db, rowId); throw error; } - await settleOperation(db, { - rowId, - status: 'failed', - outcomeCode: 'registration_rejected', - }); + try { + const settlement = await settleOperation(db, { + rowId, + status: 'failed', + outcomeCode: 'registration_rejected', + }); + logControlDiagnostic('worktree_chat_settlement', { + ...diagnostic, + requestedStatus: 'failed', + outcomeCode: 'registration_rejected', + settled: settlement.settled, + durationMs: Date.now() - startedAt, + }); + } catch (error) { + logControlDiagnostic( + 'worktree_chat_settlement', + { + ...diagnostic, + result: 'failed', + stage: 'registration_settlement', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'rejected', + stage: 'registration', + reason: 'registration_rejected', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); throw new TRPCError({ code: 'INTERNAL_SERVER_ERROR', message: 'worktree_chat_registration_failed', @@ -491,16 +693,49 @@ async function executeWorktreeCreate( ctx: TRPCContext, fingerprint: string ): Promise { + const startedAt = Date.now(); const progress = operationProgressSchema.parse({ cloudAgentSessionId: generateSessionId('control'), kiloSessionId: generateKiloSessionId(), worktreeId: source.worktreeId, [SESSION_CREATE_INTENT_FINGERPRINT_KEY]: fingerprint, }); - const recorded = await recordOperationProgress(db, row.id, progress); - if (!recorded) throw creationInProgress(); + const diagnostic = { + operationRowId: row.id, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: source.ownership.cloudAgentSessionId, + sourceKiloSessionId: source.ownership.kiloSessionId, + cloudAgentSessionId: progress.cloudAgentSessionId, + kiloSessionId: progress.kiloSessionId, + }; + try { + const recorded = await recordOperationProgress(db, row.id, progress); + if (!recorded) throw creationInProgress(); + } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'reconciliation_pending', + stage: 'progress_recording', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } + logControlDiagnostic('worktree_chat_progress', { + ...diagnostic, + result: 'recorded', + durationMs: Date.now() - startedAt, + }); await createOwnershipRow(db, row.id, source, ctx, progress); await registerWorktreeSession(db, row.id, source, ctx, progress); + logControlDiagnostic('worktree_chat_result', { + ...diagnostic, + result: 'new', + durationMs: Date.now() - startedAt, + }); return resultFromProgress(progress); } @@ -512,21 +747,81 @@ async function reconcileWorktreeCreate( progress: OperationProgress | undefined, fingerprint: string ): Promise { + const startedAt = Date.now(); + const diagnostic = { + operationRowId: row.id, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: source.ownership.cloudAgentSessionId, + sourceKiloSessionId: source.ownership.kiloSessionId, + cloudAgentSessionId: progress?.cloudAgentSessionId, + kiloSessionId: progress?.kiloSessionId, + }; + logControlDiagnostic('worktree_chat_reconciliation', { + ...diagnostic, + result: progress ? 'started' : 'no_progress', + }); if (!progress) return executeWorktreeCreate(db, row, source, ctx, fingerprint); const existingMetadata = await withDORetry( () => getSandboxSessionStub(ctx.env, ctx.userId, progress.cloudAgentSessionId), stub => stub.getMetadata(), 'getMetadata' - ); - if (existingMetadata) assertRegisteredMetadata(existingMetadata, source, progress); + ).catch(error => { + logControlDiagnostic( + 'worktree_chat_reconciliation', + { + ...diagnostic, + result: 'failed', + stage: 'reconciliation_metadata_read', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + }); + if (existingMetadata) { + try { + assertRegisteredMetadata(existingMetadata, source, progress); + } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'rejected', + stage: 'reconciliation_metadata', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } + } const ownership = await findOwnershipRow( db, ctx.userId, progress.kiloSessionId, progress.cloudAgentSessionId - ); + ).catch(error => { + logControlDiagnostic( + 'worktree_chat_reconciliation', + { + ...diagnostic, + result: 'failed', + stage: 'reconciliation_ownership_read', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + }); + logControlDiagnostic('worktree_chat_reconciliation', { + ...diagnostic, + result: 'observed', + hasRegisteredMetadata: Boolean(existingMetadata), + hasOwnership: Boolean(ownership), + durationMs: Date.now() - startedAt, + }); if (ownership) { if ( ownership.organizationId !== source.ownership.organizationId || @@ -534,6 +829,16 @@ async function reconcileWorktreeCreate( ownership.parentSessionId !== null || ownership.cloudAgentSessionScopeId !== progress.cloudAgentSessionId ) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'rejected', + stage: 'reconciliation_ownership', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); throw operationConflict(); } } else { @@ -546,6 +851,11 @@ async function reconcileWorktreeCreate( await registerWorktreeSession(db, row.id, source, ctx, progress); } + logControlDiagnostic('worktree_chat_result', { + ...diagnostic, + result: 'replayed', + durationMs: Date.now() - startedAt, + }); return resultFromProgress(progress, true); } @@ -553,6 +863,7 @@ const createWorktreeChatHandler = internalApiProtectedProcedure .input(CreateWorktreeChatInput) .output(CreateWorktreeChatOutput) .mutation(async ({ input, ctx }) => { + const startedAt = Date.now(); const db = getPgDb(ctx.env); const source = await loadWorktreeSource(db, ctx, input); const fingerprint = await worktreeIntentFingerprint(input, source.worktreeId); @@ -565,25 +876,109 @@ const createWorktreeChatHandler = internalApiProtectedProcedure resourceKey: source.worktreeId, taxonomy: 'safe-retry', leaseSeconds: WORKTREE_CREATE_LEDGER_LEASE_SECONDS, + }).catch(error => { + logControlDiagnostic( + 'worktree_chat_admission', + { + operationKey: input.operationKey, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: input.sourceCloudAgentSessionId, + sourceKiloSessionId: input.sourceKiloSessionId, + result: 'failed', + stage: 'admission', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; }); - - assertSessionOperationIdentity(admission.row, { - userId: ctx.userId, - intent: 'create_worktree_chat', - organizationId: input.kilocodeOrganizationId, - resourceKey: source.worktreeId, + const diagnostic = { + operationKey: input.operationKey, + operationRowId: admission.row.id, + worktreeId: source.worktreeId, + sourceCloudAgentSessionId: input.sourceCloudAgentSessionId, + sourceKiloSessionId: input.sourceKiloSessionId, + admission: admission.admission, + }; + logControlDiagnostic('worktree_chat_admission', { + ...diagnostic, + durationMs: Date.now() - startedAt, }); - const progress = readOperationProgress(admission.row, source, fingerprint); + + let progress: OperationProgress | undefined; + try { + assertSessionOperationIdentity(admission.row, { + userId: ctx.userId, + intent: 'create_worktree_chat', + organizationId: input.kilocodeOrganizationId, + resourceKey: source.worktreeId, + }); + progress = readOperationProgress(admission.row, source, fingerprint); + } catch (error) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...diagnostic, + result: 'rejected', + stage: 'operation_identity', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw error; + } + const resultDiagnostic = { + ...diagnostic, + cloudAgentSessionId: progress?.cloudAgentSessionId, + kiloSessionId: progress?.kiloSessionId, + }; switch (admission.admission) { case 'admitted': - if (progress) throw operationConflict(); + if (progress) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...resultDiagnostic, + result: 'rejected', + stage: 'admission', + reason: 'unexpected_progress', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw operationConflict(); + } return executeWorktreeCreate(db, admission.row, source, ctx, fingerprint); case 'duplicate_settled': - if (admission.row.status !== 'completed' || !progress) throw creationFailed(); + if (admission.row.status !== 'completed' || !progress) { + logControlDiagnostic( + 'worktree_chat_result', + { + ...resultDiagnostic, + result: 'rejected', + stage: 'replay', + reason: 'settled_result_unavailable', + durationMs: Date.now() - startedAt, + }, + 'warn' + ); + throw creationFailed(); + } + logControlDiagnostic('worktree_chat_result', { + ...resultDiagnostic, + result: 'replayed', + durationMs: Date.now() - startedAt, + }); return resultFromProgress(progress, true); case 'duplicate_in_flight': case 'duplicate_reconcile_in_progress': + logControlDiagnostic('worktree_chat_result', { + ...resultDiagnostic, + result: 'reconciliation_pending', + stage: 'admission', + durationMs: Date.now() - startedAt, + }); throw creationInProgress(); case 'takeover': case 'duplicate_reconcile_pending': diff --git a/services/cloud-agent-next/src/router/handlers/worktree-deletion.ts b/services/cloud-agent-next/src/router/handlers/worktree-deletion.ts index 94454e9fdf..b56dfb0c08 100644 --- a/services/cloud-agent-next/src/router/handlers/worktree-deletion.ts +++ b/services/cloud-agent-next/src/router/handlers/worktree-deletion.ts @@ -14,7 +14,11 @@ import { hasOrganizationAccess } from '@kilocode/worker-utils'; import { getPgDb } from '../../db/pg'; import { getSandboxSessionStub } from '../../sandbox-session/session-stub'; import { getSandboxControlStub } from '../../sandbox-control/stub'; -import { worktreeDeleteResultSchema } from '../../shared/sandbox-control-protocol'; +import { + worktreeDeleteResultSchema, + type WorktreeDeleteResult, +} from '../../shared/sandbox-control-protocol'; +import { logControlDiagnostic } from '../../sandbox-control/diagnostics'; import { withDORetry } from '../../utils/do-retry'; import { getWorktreeWorkspacePath } from '../../workspace'; import type { TRPCContext } from '../../types'; @@ -45,6 +49,14 @@ export async function deleteWorktreeResources( kiloUserId: ctx.userId, ...(input.kilocodeOrganizationId ? { organizationId: input.kilocodeOrganizationId } : {}), }; + const startedAt = Date.now(); + let stage = 'authorize'; + let outcome = 'failed'; + let sessionCount: number | undefined; + let locationCount: number | undefined; + let errorCode: string | undefined; + let retryable: boolean | undefined; + logControlDiagnostic('worktree_deletion', { worktreeId: params.worktreeId, phase: 'started' }); try { if ( params.organizationId && @@ -55,14 +67,19 @@ export async function deleteWorktreeResources( ) { throw new TRPCError({ code: 'FORBIDDEN', message: 'Worktree access denied' }); } + stage = 'begin_deletion'; let state = cloudAgentWorktreeDeletionStateSchema.parse( await ctx.env.SESSION_INGEST.beginCloudAgentWorktreeDeletion(params) ); - if (state.completed) + sessionCount = state.manifest.sessions.length; + locationCount = state.runtimeLocations.length; + if (state.completed) { + outcome = 'replayed'; return { success: true, deletedSessionIds: state.manifest.sessions.map(session => session.sessionId), }; + } const runtimeLocations = [...state.runtimeLocations]; const directory = getWorktreeWorkspacePath( params.organizationId, @@ -70,6 +87,7 @@ export async function deleteWorktreeResources( params.worktreeId ); const childSessions: NonNullable = []; + stage = 'collect_sessions'; for (const session of state.manifest.sessions) { if (!session.cloudAgentSessionId) continue; const cloudAgentSessionId = session.cloudAgentSessionId; @@ -102,7 +120,10 @@ export async function deleteWorktreeResources( runtimeLocations.push(location); } } + stage = 'runtime_history'; + locationCount = runtimeLocations.length; if (runtimeLocations.length === 0) throw new Error(WORKTREE_RUNTIME_HISTORY_UNAVAILABLE); + stage = 'record_manifest'; state = cloudAgentWorktreeDeletionStateSchema.parse( await ctx.env.SESSION_INGEST.recordCloudAgentWorktreeCleanup({ ...params, @@ -111,27 +132,51 @@ export async function deleteWorktreeResources( ...(childSessions.length > 0 ? { childSessions } : {}), }) ); + sessionCount = state.manifest.sessions.length; + locationCount = state.runtimeLocations.length; for (const location of state.runtimeLocations) { - const result = worktreeDeleteResultSchema.parse( - await withDORetry( - () => getSandboxControlStub(ctx.env, location.sandboxId), - stub => - stub.deleteWorktreeResources({ - ...params, - location, - sessionIds: state.manifest.sessions.map(session => session.sessionId), - }), - 'deleteWorktreeResources' - ) - ); + stage = 'runtime_cleanup'; + const locationStartedAt = Date.now(); + let cleanup: WorktreeDeleteResult | undefined; + try { + cleanup = worktreeDeleteResultSchema.parse( + await withDORetry( + () => getSandboxControlStub(ctx.env, location.sandboxId), + stub => + stub.deleteWorktreeResources({ + ...params, + location, + sessionIds: state.manifest.sessions.map(session => session.sessionId), + }), + 'deleteWorktreeResources' + ) + ); + } finally { + logControlDiagnostic( + 'worktree_cleanup_location', + { + worktreeId: params.worktreeId, + sandboxId: location.sandboxId, + provider: location.provider, + result: cleanup ? 'resources_cleaned' : 'failed', + sessionCount: cleanup?.sessionIds.length, + durationMs: Date.now() - locationStartedAt, + }, + cleanup ? 'info' : 'warn' + ); + } + stage = 'record_cleanup'; state = cloudAgentWorktreeDeletionStateSchema.parse( await ctx.env.SESSION_INGEST.recordCloudAgentWorktreeCleanup({ ...params, directory, - sessionIds: result.sessionIds, + sessionIds: cleanup.sessionIds, }) ); + sessionCount = state.manifest.sessions.length; + locationCount = state.runtimeLocations.length; } + stage = 'finish_sessions'; for (const session of state.manifest.sessions) { if (!session.cloudAgentSessionId) continue; const cloudAgentSessionId = session.cloudAgentSessionId; @@ -141,12 +186,26 @@ export async function deleteWorktreeResources( 'finishWorktreeDeletion' ); } - return DeleteWorktreeOutput.parse( + stage = 'complete_deletion'; + const output = DeleteWorktreeOutput.parse( await ctx.env.SESSION_INGEST.completeCloudAgentWorktreeDeletion(params) ); + sessionCount = output.deletedSessionIds.length; + outcome = 'completed'; + return output; } catch (error) { - if (error instanceof TRPCError) throw error; + if (error instanceof TRPCError) { + outcome = + error.code === 'FORBIDDEN' || error.code === 'UNAUTHORIZED' || error.code === 'BAD_REQUEST' + ? 'rejected' + : 'failed'; + errorCode = error.code; + throw error; + } if (error instanceof Error && error.message.includes(WORKTREE_RUNTIME_HISTORY_UNAVAILABLE)) { + outcome = 'history_unavailable'; + errorCode = 'WORKTREE_RUNTIME_HISTORY_UNAVAILABLE'; + retryable = false; throw new TRPCError({ code: 'INTERNAL_SERVER_ERROR', message: 'Worktree runtime history is unavailable; recovery is required', @@ -154,8 +213,14 @@ export async function deleteWorktreeResources( }); } if (error instanceof Error && error.message.includes('worktree_access_denied')) { + outcome = 'rejected'; + errorCode = 'FORBIDDEN'; + retryable = false; throw new TRPCError({ code: 'FORBIDDEN', message: 'Worktree access denied' }); } + outcome = 'pending'; + errorCode = 'WORKTREE_DELETION_PENDING'; + retryable = true; throw new TRPCError({ code: 'INTERNAL_SERVER_ERROR', message: 'Worktree deletion is incomplete; retry the same worktree', @@ -165,6 +230,22 @@ export async function deleteWorktreeResources( retryable: true, }, }); + } finally { + logControlDiagnostic( + 'worktree_deletion', + { + worktreeId: params.worktreeId, + phase: 'finished', + stage, + result: outcome, + sessionCount, + locationCount, + errorCode, + retryable, + durationMs: Date.now() - startedAt, + }, + outcome === 'completed' || outcome === 'replayed' || outcome === 'rejected' ? 'info' : 'warn' + ); } } diff --git a/services/cloud-agent-next/src/sandbox-control/worktree-deletion.ts b/services/cloud-agent-next/src/sandbox-control/worktree-deletion.ts index a36ede425b..6b05c80f86 100644 --- a/services/cloud-agent-next/src/sandbox-control/worktree-deletion.ts +++ b/services/cloud-agent-next/src/sandbox-control/worktree-deletion.ts @@ -9,6 +9,7 @@ import type { ProviderAdapter } from './provider'; import { loadPhysicalRecord, loadRouteTable } from './durable-state'; import { sameAllocation, type PhysicalRecord } from './physical-lifecycle'; import { DEADLINE_MS } from './deadlines'; +import { logControlDiagnostic } from './diagnostics'; import type { SandboxControlOutboundRequest } from './socket'; import { worktreeDeleteResultSchema, @@ -86,80 +87,141 @@ export async function cleanWorktreeRuntime(input: { sendRequest: (request: SandboxControlOutboundRequest) => Promise; exclusive: boolean; }): Promise { - const key = `${WORKTREE_DELETION_PREFIX}${input.request.worktreeId}`; - const previous = await loadWorktreeDeletionJournal(input.storage, input.request.worktreeId); - const sessionIds = [...new Set([...(previous?.sessionIds ?? []), ...input.request.sessionIds])]; - const scopedCleanupConfirmed = - previous?.resourcesCleaned === true && previous.sessionIds.length === sessionIds.length; - if (scopedCleanupConfirmed && (!input.exclusive || previous.destroyed)) return previous; - const journal: WorktreeRuntimeDeletionJournal = { - sessionIds, - resourcesCleaned: scopedCleanupConfirmed, - destroyed: previous?.destroyed ?? false, - completed: false, - exclusiveTeardown: input.exclusive || (previous?.exclusiveTeardown ?? false), - }; - await input.storage.put(key, journal); - if (await isUnallocatedControlRuntime(input.storage, input.hasConnection)) { - journal.resourcesCleaned = true; - journal.destroyed = input.exclusive; - await input.storage.put(key, journal); - return journal; - } - const physical = await loadPhysicalRecord(input.storage); - if (physical.state === 'stopped') { - journal.resourcesCleaned = true; - journal.destroyed = input.exclusive; - await input.storage.put(key, journal); - return journal; - } - const provider = await input.getProvider(); - if (input.exclusive) { - if ((await input.stopRuntime()).state !== 'stopped') { - throw new Error('Worktree provider stop is unconfirmed'); + const startedAt = Date.now(); + let stage = 'load_journal'; + let cleanupMode = 'pending'; + let result = 'failed'; + let journal: WorktreeRuntimeDeletionJournal | undefined; + logControlDiagnostic('worktree_runtime_cleanup', { + worktreeId: input.request.worktreeId, + sandboxId: input.request.location.sandboxId, + provider: input.request.location.provider, + exclusive: input.exclusive, + phase: 'started', + }); + try { + const key = `${WORKTREE_DELETION_PREFIX}${input.request.worktreeId}`; + const previous = await loadWorktreeDeletionJournal(input.storage, input.request.worktreeId); + const sessionIds = [...new Set([...(previous?.sessionIds ?? []), ...input.request.sessionIds])]; + const scopedCleanupConfirmed = + previous?.resourcesCleaned === true && previous.sessionIds.length === sessionIds.length; + if (scopedCleanupConfirmed && (!input.exclusive || previous.destroyed)) { + journal = previous; + cleanupMode = 'journal_reuse'; + result = 'replayed'; + return previous; } - journal.destroyed = true; - } else if (input.hasConnection()) { - const payload = { - worktreeId: input.request.worktreeId, - directory: input.directory, + journal = { sessionIds, + resourcesCleaned: scopedCleanupConfirmed, + destroyed: previous?.destroyed ?? false, + completed: false, + exclusiveTeardown: input.exclusive || (previous?.exclusiveTeardown ?? false), }; - const prepared = await input.sendRequest({ - operation: 'worktree.prepareDeletion', - payload, - timeoutMs: SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, - }); - if (!prepared.ok) throw new Error('Worktree runtime preparation is incomplete'); - const discovery = worktreePrepareDeletionResultSchema.parse(prepared.result); - journal.sessionIds = [...new Set([...sessionIds, ...discovery.sessionIds])]; + stage = 'persist_manifest'; await input.storage.put(key, journal); - const deleted = await input.sendRequest({ - operation: 'worktree.delete', - payload: { ...payload, sessionIds: journal.sessionIds }, - timeoutMs: SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, - }); - if (!deleted.ok) throw new Error('Worktree runtime cleanup is incomplete'); - const confirmed = worktreeDeleteResultSchema.parse(deleted.result); - if (journal.sessionIds.some(id => !confirmed.sessionIds.includes(id))) { - throw new Error('Worktree runtime cleanup manifest is incomplete'); + stage = 'inspect_runtime'; + if (await isUnallocatedControlRuntime(input.storage, input.hasConnection)) { + cleanupMode = 'unallocated'; + journal.resourcesCleaned = true; + journal.destroyed = input.exclusive; + stage = 'persist_result'; + await input.storage.put(key, journal); + result = 'resources_cleaned'; + return journal; } - journal.sessionIds = [...new Set([...journal.sessionIds, ...confirmed.sessionIds])]; - } else { - const observed = await withTimeout( - provider.observe(physical.providerRef, physical.createIntent), - DEADLINE_MS.stopAttempt, - 'Worktree provider observation timed out' - ); - if (observed.status !== 'terminal') { - throw new Error('Shared worktree runtime must reconnect before cleanup'); + const physical = await loadPhysicalRecord(input.storage); + if (physical.state === 'stopped') { + cleanupMode = 'already_stopped'; + journal.resourcesCleaned = true; + journal.destroyed = input.exclusive; + stage = 'persist_result'; + await input.storage.put(key, journal); + result = 'resources_cleaned'; + return journal; } + stage = 'resolve_provider'; + const provider = await input.getProvider(); + if (input.exclusive) { + cleanupMode = 'exclusive_stop'; + stage = 'stop_provider'; + if ((await input.stopRuntime()).state !== 'stopped') { + throw new Error('Worktree provider stop is unconfirmed'); + } + journal.destroyed = true; + } else if (input.hasConnection()) { + cleanupMode = 'shared_wrapper'; + stage = 'prepare_deletion'; + const payload = { + worktreeId: input.request.worktreeId, + directory: input.directory, + sessionIds, + }; + const prepared = await input.sendRequest({ + operation: 'worktree.prepareDeletion', + payload, + timeoutMs: SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, + }); + if (!prepared.ok) throw new Error('Worktree runtime preparation is incomplete'); + const discovery = worktreePrepareDeletionResultSchema.parse(prepared.result); + journal.sessionIds = [...new Set([...sessionIds, ...discovery.sessionIds])]; + stage = 'persist_manifest'; + await input.storage.put(key, journal); + stage = 'delete_runtime'; + const deleted = await input.sendRequest({ + operation: 'worktree.delete', + payload: { ...payload, sessionIds: journal.sessionIds }, + timeoutMs: SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, + }); + if (!deleted.ok) throw new Error('Worktree runtime cleanup is incomplete'); + stage = 'validate_manifest'; + const confirmed = worktreeDeleteResultSchema.parse(deleted.result); + if (journal.sessionIds.some(id => !confirmed.sessionIds.includes(id))) { + throw new Error('Worktree runtime cleanup manifest is incomplete'); + } + journal.sessionIds = [...new Set([...journal.sessionIds, ...confirmed.sessionIds])]; + } else { + cleanupMode = 'terminal_observation'; + stage = 'observe_provider'; + const observed = await withTimeout( + provider.observe(physical.providerRef, physical.createIntent), + DEADLINE_MS.stopAttempt, + 'Worktree provider observation timed out' + ); + if (observed.status !== 'terminal') { + throw new Error('Shared worktree runtime must reconnect before cleanup'); + } + } + stage = 'allocation_fence'; + const current = await loadPhysicalRecord(input.storage); + if (!input.exclusive && current.state !== 'stopped' && !sameAllocation(physical, current)) { + throw new Error('Worktree provider allocation changed during cleanup'); + } + journal.resourcesCleaned = true; + stage = 'persist_result'; + await input.storage.put(key, journal); + result = 'resources_cleaned'; + return journal; + } finally { + const confirmed = result === 'failed' ? undefined : journal; + logControlDiagnostic( + 'worktree_runtime_cleanup', + { + worktreeId: input.request.worktreeId, + sandboxId: input.request.location.sandboxId, + provider: input.request.location.provider, + exclusive: input.exclusive, + phase: 'finished', + cleanupMode, + stage, + result, + sessionCount: journal?.sessionIds.length ?? input.request.sessionIds.length, + resourcesCleaned: confirmed?.resourcesCleaned, + destroyed: confirmed?.destroyed, + completed: confirmed?.completed, + durationMs: Date.now() - startedAt, + }, + result === 'failed' ? 'warn' : 'info' + ); } - const current = await loadPhysicalRecord(input.storage); - if (!input.exclusive && current.state !== 'stopped' && !sameAllocation(physical, current)) { - throw new Error('Worktree provider allocation changed during cleanup'); - } - journal.resourcesCleaned = true; - await input.storage.put(key, journal); - return journal; } diff --git a/services/cloud-agent-next/src/sandbox-control/worktree-ownership.ts b/services/cloud-agent-next/src/sandbox-control/worktree-ownership.ts index dafea50b44..e6c7624281 100644 --- a/services/cloud-agent-next/src/sandbox-control/worktree-ownership.ts +++ b/services/cloud-agent-next/src/sandbox-control/worktree-ownership.ts @@ -11,6 +11,7 @@ import { getSandboxProvider, type SessionMetadata } from '../persistence/session import { getSandboxSessionStub, resolveSessionStub } from '../sandbox-session/session-stub'; import { withDORetry } from '../utils/do-retry'; import type { Env } from '../types'; +import { logControlDiagnostic } from './diagnostics'; export const sessionRuntimeLocatorSchema = z .object({ @@ -40,53 +41,94 @@ export async function resolveSandboxExclusivity( env: Env, params: CanDestroyCloudAgentWorktreeSandboxParams ): Promise { - const result = canDestroyCloudAgentWorktreeSandboxResultSchema.parse( - await env.SESSION_INGEST.canDestroyCloudAgentWorktreeSandbox(params) - ); - if (result.kind === 'exclusive') return true; - if (result.kind === 'shared') return false; - let unavailable = false; - for (const owner of result.owners) { - let located = false; - for (const session of owner.sessions) { - const locator = sessionRuntimeLocatorSchema.nullable().parse( - await withDORetry( - () => - session.cloudAgentSessionId.startsWith('workspace_') - ? getSandboxSessionStub(env, params.kiloUserId, session.cloudAgentSessionId) - : resolveSessionStub(env, params.kiloUserId, session.cloudAgentSessionId), - stub => stub.getRuntimeLocation(), - 'getRuntimeLocation' - ) - ); - if (!locator) continue; - if ( - locator.cloudAgentSessionId !== session.cloudAgentSessionId || - locator.kiloUserId !== params.kiloUserId || - locator.organizationId !== owner.organizationId || - (session.sessionId !== null && - locator.sessionId !== null && - locator.sessionId !== session.sessionId) || - (owner.worktreeId !== null && locator.worktreeId !== owner.worktreeId) - ) { - throw new Error(WORKTREE_RUNTIME_HISTORY_UNAVAILABLE); - } - located = true; - if ( - locator.location.sandboxId === params.location.sandboxId && - locator.location.provider === params.location.provider - ) - return false; + const startedAt = Date.now(); + let decision = 'failed'; + let evidence = 'ledger'; + logControlDiagnostic('worktree_ownership', { + worktreeId: params.worktreeId, + sandboxId: params.location.sandboxId, + provider: params.location.provider, + phase: 'started', + }); + try { + const result = canDestroyCloudAgentWorktreeSandboxResultSchema.parse( + await env.SESSION_INGEST.canDestroyCloudAgentWorktreeSandbox(params) + ); + if (result.kind === 'exclusive') { + decision = 'exclusive'; + return true; + } + if (result.kind === 'shared') { + decision = 'shared'; + return false; } - if (!located && owner.allocationLocation) { - located = true; - if ( - owner.allocationLocation.sandboxId === params.location.sandboxId && - owner.allocationLocation.provider === params.location.provider - ) - return false; + let unavailable = false; + for (const owner of result.owners) { + let located = false; + for (const session of owner.sessions) { + evidence = 'session_locator'; + const locator = sessionRuntimeLocatorSchema.nullable().parse( + await withDORetry( + () => + session.cloudAgentSessionId.startsWith('workspace_') + ? getSandboxSessionStub(env, params.kiloUserId, session.cloudAgentSessionId) + : resolveSessionStub(env, params.kiloUserId, session.cloudAgentSessionId), + stub => stub.getRuntimeLocation(), + 'getRuntimeLocation' + ) + ); + if (!locator) continue; + if ( + locator.cloudAgentSessionId !== session.cloudAgentSessionId || + locator.kiloUserId !== params.kiloUserId || + locator.organizationId !== owner.organizationId || + (session.sessionId !== null && + locator.sessionId !== null && + locator.sessionId !== session.sessionId) || + (owner.worktreeId !== null && locator.worktreeId !== owner.worktreeId) + ) { + decision = 'unresolved'; + evidence = 'locator_mismatch'; + throw new Error(WORKTREE_RUNTIME_HISTORY_UNAVAILABLE); + } + located = true; + if ( + locator.location.sandboxId === params.location.sandboxId && + locator.location.provider === params.location.provider + ) { + decision = 'shared'; + return false; + } + } + if (!located && owner.allocationLocation) { + evidence = 'allocation_fallback'; + located = true; + if ( + owner.allocationLocation.sandboxId === params.location.sandboxId && + owner.allocationLocation.provider === params.location.provider + ) { + decision = 'shared'; + return false; + } + } + if (!located) unavailable = true; } - if (!located) unavailable = true; + decision = unavailable ? 'unresolved' : 'exclusive'; + evidence = unavailable ? 'unavailable_history' : 'runtime_reconciliation'; + return !unavailable; + } finally { + logControlDiagnostic( + 'worktree_ownership', + { + worktreeId: params.worktreeId, + sandboxId: params.location.sandboxId, + provider: params.location.provider, + phase: 'finished', + decision, + evidence, + durationMs: Date.now() - startedAt, + }, + decision === 'failed' || decision === 'unresolved' ? 'warn' : 'info' + ); } - return !unavailable; } diff --git a/services/cloud-agent-next/src/shared/control-diagnostics.ts b/services/cloud-agent-next/src/shared/control-diagnostics.ts index 7911a9d768..e35dd830ed 100644 --- a/services/cloud-agent-next/src/shared/control-diagnostics.ts +++ b/services/cloud-agent-next/src/shared/control-diagnostics.ts @@ -1,5 +1,9 @@ import { z } from 'zod'; -import { CONTROL_OPERATIONS, controlErrorCodes } from './sandbox-control-protocol.js'; +import { + CONTROL_OPERATIONS, + controlErrorCodes, + worktreeDeletePayloadSchema, +} from './sandbox-control-protocol.js'; export const CONTROL_LOG_MAX_BATCH_BYTES = 256 * 1024; export const CONTROL_LOG_MAX_BATCH_RECORDS = 128; @@ -80,6 +84,40 @@ export const controlDiagnosticFieldsSchema = z 'response_skipped', 'skipped', ]), + stage: z + .enum([ + 'attach_validation', + 'runtime_attach', + 'workspace_prepare', + 'git_setup', + 'setup_commands', + 'bootstrap_marker', + 'git_credentials', + 'session_registration', + 'session_probe', + 'session_restore', + 'session_create', + 'attachment_commit', + 'deletion_fence', + 'task_cancellation', + 'runtime_lookup', + 'directory_validation', + 'manifest_discovery', + 'session_abort', + 'manifest_growth', + 'process_cleanup', + 'terminal_cleanup', + 'session_delete', + 'session_delete_confirmation', + 'session_delete_unconfirmed', + 'directory_dispose', + 'runtime_retirement', + 'directory_removal', + 'root_detach', + ]) + .optional(), + workspaceAction: z.enum(['reuse', 'bootstrap', 'not_needed']).optional(), + sessionResolution: z.enum(['existing', 'restored', 'created']).optional(), kind: z.enum(['preparation', 'execution', 'finalizing']).optional(), status: z.enum(['completed', 'failed', 'cancelled']).optional(), category: z @@ -97,6 +135,8 @@ export const controlDiagnosticFieldsSchema = z retirementCause: z .enum([ 'event_feed_unhealthy', + 'process_exited', + 'credential_refresh_failed', 'control_disconnected', 'preparation_delivery_failed', 'requested_shutdown', @@ -114,6 +154,7 @@ export const controlDiagnosticFieldsSchema = z errorCode: z.enum([...controlErrorCodes, 'other']).optional(), retryable: z.boolean().optional(), scopeId: identifier.optional(), + worktreeId: worktreeDeletePayloadSchema.shape.worktreeId.optional(), sessionId: identifier.optional(), kiloSessionId: identifier.optional(), messageId: identifier.optional(), @@ -128,6 +169,7 @@ export const controlDiagnosticFieldsSchema = z delayMs: milliseconds.optional(), sequence: count.optional(), eventsReceived: count.optional(), + sessionCount: count.optional(), bufferedBytes: count.optional(), bytes: count.optional(), attempt: count.optional(), diff --git a/services/cloud-agent-next/wrapper/src/control/apply-attach.ts b/services/cloud-agent-next/wrapper/src/control/apply-attach.ts index fef5707dd3..faf5180b5d 100644 --- a/services/cloud-agent-next/wrapper/src/control/apply-attach.ts +++ b/services/cloud-agent-next/wrapper/src/control/apply-attach.ts @@ -8,10 +8,14 @@ import { } from '../../../src/shared/sandbox-control-protocol.js'; import type { PreparingEventDataV2, PreparingStep } from '../../../src/shared/protocol.js'; import { CONTROL_RUNTIME_RESERVED_ENV_VARS } from '../../../src/shared/runtime-environment.js'; +import { + emitControlDiagnostic, + type ControlDiagnosticRecord, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import { git, isTimeoutTermination, - logToFile, runProcess, withTimeoutAndAbort, type ExecResult, @@ -47,6 +51,7 @@ const workspacePreparations = new Map void; export type ApplyAttachDeps = { + onDiagnostic?: ControlDiagnosticReporter; kiloRuntimes?: WorktreeKiloRuntimes; canRefreshCredentials?: () => boolean; signal?: AbortSignal; @@ -273,11 +278,33 @@ async function executeSessionAttach( deps: ApplyAttachDeps, directory: string ): Promise { + const startedAt = Date.now(); + let stage: ControlDiagnosticRecord['fields']['stage'] = 'attach_validation'; + let workspaceAction: ControlDiagnosticRecord['fields']['workspaceAction']; + let sessionResolution: ControlDiagnosticRecord['fields']['sessionResolution']; + const diagnostic = (phase: 'completed' | 'failed'): void => + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation: 'session.attach', + phase, + stage, + sessionId: session.sessionId, + kiloSessionId: session.kiloSessionId, + messageId: attach.preparation?.triggerMessageId, + workspaceAction, + sessionResolution, + elapsedMs: Math.max(0, Date.now() - startedAt), + ok: phase === 'completed', + }); const existingDirectory = directoryForSession(session.kiloSessionId); if (existingDirectory && existingDirectory !== directory) { + diagnostic('failed'); return fail('unauthorized', 'Session directory mismatch', false); } - if (!deps.kiloRuntimes) return fail('not_ready', 'Kilo is not ready', true); + stage = 'runtime_attach'; + if (!deps.kiloRuntimes) { + diagnostic('failed'); + return fail('not_ready', 'Kilo is not ready', true); + } let attachment: WorktreeKiloAttachment | undefined; const taskSignal = deps.signal ?? AbortSignal.timeout(SANDBOX_CONTROL_ATTACH_TIMEOUT_MS); @@ -297,6 +324,7 @@ async function executeSessionAttach( abortMessage: 'Session attachment cancelled', }); signal.throwIfAborted(); + stage = 'workspace_prepare'; const mkdir = deps.mkdir ?? (dir => fs.mkdir(dir, { recursive: true }).then(() => undefined)); const hasGit = deps.hasGit ?? defaultHasGit; const hasBootstrapMarker = deps.hasBootstrapMarker ?? defaultHasBootstrapMarker; @@ -317,10 +345,16 @@ async function executeSessionAttach( signal.throwIfAborted(); const setupCommands = attach.setupCommands ?? []; const needsWorkspace = Boolean(attach.git) || setupCommands.length > 0; + workspaceAction = alreadyBootstrapped + ? 'reuse' + : needsWorkspace + ? 'bootstrap' + : 'not_needed'; if (!alreadyBootstrapped && needsWorkspace) { await mkdir(directory); signal.throwIfAborted(); if (attach.git) { + stage = 'git_setup'; const needsClone = !(await hasGit(directory)); signal.throwIfAborted(); const cloneStepId = 'phase:cloning'; @@ -388,6 +422,7 @@ async function executeSessionAttach( signal.throwIfAborted(); } for (const [index, command] of setupCommands.entries()) { + stage = 'setup_commands'; signal.throwIfAborted(); const stepId = `setup_command:${index}`; progress.start('setup_commands', stepId, `Running setup command ${index + 1}`, { @@ -415,11 +450,13 @@ async function executeSessionAttach( } progress.complete('setup_commands', stepId); } + stage = 'bootstrap_marker'; signal.throwIfAborted(); await writeBootstrapMarker(directory); signal.throwIfAborted(); } if (attach.kilo.containmentEnabled === false && attach.git?.token) { + stage = 'git_credentials'; const refreshed = await runGit( [ 'remote', @@ -443,8 +480,12 @@ async function executeSessionAttach( ); } }); - if (workspaceFailure) return workspaceFailure; + if (workspaceFailure) { + diagnostic('failed'); + return workspaceFailure; + } + stage = 'session_registration'; const kiloSessionId = attach.snapshotIdentity ?? session.kiloSessionId; const restore = deps.restoreSession ?? restoreSession; const sessionExists = @@ -455,25 +496,33 @@ async function executeSessionAttach( progress.start('kilo_session', 'phase:kilo_session', 'Starting session…'); await seedSessionIngestRegistration(session.kiloSessionId, env, signal); signal.throwIfAborted(); + stage = 'session_probe'; const exists = await withKiloRequestDeadline( probeSignal => sessionExists(kiloSessionId, directory, probeSignal), signal ); signal.throwIfAborted(); + sessionResolution = exists ? 'existing' : undefined; if (!exists) { + stage = 'session_restore'; progress.progress('kilo_session', 'phase:kilo_session', 'Restoring session…'); const restored = await restore(kiloSessionId, directory, undefined, { env, signal }); signal.throwIfAborted(); if (!restored.ok) { if (restored.code !== 404 && !restored.emptySnapshot) { progress.fail('kilo_session', 'phase:kilo_session', restored.error); + diagnostic('failed'); return fail('not_ready', 'kilo session is not ready', true); } + stage = 'session_create'; progress.progress('kilo_session', 'phase:kilo_session', 'Starting session…'); await withKiloRequestDeadline( probeSignal => kiloClient.ensureSession(kiloSessionId, directory, probeSignal), signal ); + sessionResolution = 'created'; + } else { + sessionResolution = 'restored'; } } signal.throwIfAborted(); @@ -481,8 +530,10 @@ async function executeSessionAttach( } catch { const message = signal.aborted ? 'Session attachment cancelled' : 'kilo session is not ready'; progress.fail('kilo_session', 'phase:kilo_session', message); + diagnostic('failed'); return fail('not_ready', message, true); } + stage = 'attachment_commit'; signal.throwIfAborted(); const alreadyAttached = rootForSession(session.kiloSessionId) === session.kiloSessionId; rememberAttachedRoot(session.kiloSessionId, directory); @@ -494,9 +545,10 @@ async function executeSessionAttach( if (!alreadyAttached) forgetAttachedRoot(session.kiloSessionId, directory); throw error; } - logToFile(`session.attach ready directory=${directory}`); + diagnostic('completed'); return ok(); } catch (error) { + diagnostic('failed'); if (error instanceof WorktreeKiloRuntimeError || error instanceof ControlTerminalRuntimeError) { return fail(error.code, error.message, error.retryable); } diff --git a/services/cloud-agent-next/wrapper/src/control/delete-worktree.ts b/services/cloud-agent-next/wrapper/src/control/delete-worktree.ts index eb008e1846..abfd975efe 100644 --- a/services/cloud-agent-next/wrapper/src/control/delete-worktree.ts +++ b/services/cloud-agent-next/wrapper/src/control/delete-worktree.ts @@ -7,6 +7,11 @@ import { type WorktreeDeletePayload, type WorktreeDeleteResult, } from '../../../src/shared/sandbox-control-protocol'; +import { + emitControlDiagnostic, + type ControlDiagnosticRecord, + type ControlDiagnosticReporter, +} from '../../../src/shared/control-diagnostics.js'; import { fenceDirectoryOperations } from './worktree-operations'; import { directoryForSession, forgetAttachedRoot } from './session-directories'; @@ -149,6 +154,7 @@ async function assertNoSymlinks(directory: string): Promise { } export type WorktreeCleanupDeps = { + onDiagnostic?: ControlDiagnosticReporter; client?: WorktreeKiloCleanupClient; assertDirectory?: (directory: string) => Promise; retireDirectory?: (directory: string) => Promise; @@ -161,68 +167,130 @@ export async function prepareWorktreeDeletion( raw: unknown, deps: WorktreeCleanupDeps ): Promise { + const startedAt = Date.now(); const input = worktreeDeletePayloadSchema.parse(raw); - validateWorktreeDirectory(input); - await fenceDirectoryOperations(input.directory); - await (deps.assertDirectory ?? assertNoSymlinks)(input.directory); - const { client } = deps; - const sessionIds = new Set([ - ...input.sessionIds, - ...(client ? await client.listSessionIds(input.directory) : []), - ]); - for (const sessionId of sessionIds) { - const rememberedDirectory = directoryForSession(sessionId); - if (rememberedDirectory && rememberedDirectory !== input.directory) - throw new Error('Worktree session directory conflict'); - if (!client) continue; - const session = await client.getSession(input.directory, sessionId); - if (session && session.directory !== input.directory) - throw new Error('Worktree session directory conflict'); - await client.abortSession(input.directory, sessionId); - if (!session) continue; - for (const child of await client.children(input.directory, sessionId)) { - if (child.directory !== input.directory) throw new Error('Worktree child directory conflict'); - sessionIds.add(child.id); + let stage: ControlDiagnosticRecord['fields']['stage'] = 'directory_validation'; + let sessionCount = input.sessionIds.length; + const diagnostic = (phase: 'completed' | 'failed'): void => + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation: 'worktree.prepareDeletion', + phase, + stage, + worktreeId: input.worktreeId, + sessionCount, + elapsedMs: Math.max(0, Date.now() - startedAt), + ok: phase === 'completed', + }); + try { + validateWorktreeDirectory(input); + stage = 'deletion_fence'; + await fenceDirectoryOperations(input.directory); + stage = 'directory_validation'; + await (deps.assertDirectory ?? assertNoSymlinks)(input.directory); + const { client } = deps; + stage = 'manifest_discovery'; + const sessionIds = new Set([ + ...input.sessionIds, + ...(client ? await client.listSessionIds(input.directory) : []), + ]); + sessionCount = sessionIds.size; + for (const sessionId of sessionIds) { + stage = 'manifest_discovery'; + const rememberedDirectory = directoryForSession(sessionId); + if (rememberedDirectory && rememberedDirectory !== input.directory) + throw new Error('Worktree session directory conflict'); + if (!client) continue; + const session = await client.getSession(input.directory, sessionId); + if (session && session.directory !== input.directory) + throw new Error('Worktree session directory conflict'); + stage = 'session_abort'; + await client.abortSession(input.directory, sessionId); + if (!session) continue; + stage = 'manifest_discovery'; + for (const child of await client.children(input.directory, sessionId)) { + if (child.directory !== input.directory) + throw new Error('Worktree child directory conflict'); + sessionIds.add(child.id); + sessionCount = sessionIds.size; + } } + stage = 'manifest_discovery'; + diagnostic('completed'); + return [...sessionIds]; + } catch (error) { + diagnostic('failed'); + throw error; } - return [...sessionIds]; } export async function deleteWorktree( raw: unknown, deps: WorktreeCleanupDeps ): Promise { + const startedAt = Date.now(); const input = worktreeDeletePayloadSchema.parse(raw); - const sessionIds = await prepareWorktreeDeletion(input, deps); - const journaled = new Set(input.sessionIds); - if (sessionIds.some(id => !journaled.has(id))) - throw new Error('Worktree cleanup manifest changed'); - const { client } = deps; - if (client) { - for (const sessionId of sessionIds) { - await client.stopSessionProcesses(input.directory, sessionId); + let stage: ControlDiagnosticRecord['fields']['stage'] = 'manifest_discovery'; + let sessionCount = input.sessionIds.length; + const diagnostic = (phase: 'completed' | 'failed'): void => + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation: 'worktree.delete', + phase, + stage, + worktreeId: input.worktreeId, + sessionCount, + elapsedMs: Math.max(0, Date.now() - startedAt), + ok: phase === 'completed', + }); + try { + const sessionIds = await prepareWorktreeDeletion(input, deps); + sessionCount = sessionIds.length; + const journaled = new Set(input.sessionIds); + if (sessionIds.some(id => !journaled.has(id))) { + stage = 'manifest_growth'; + throw new Error('Worktree cleanup manifest changed'); } - } - await deps.detachTerminals?.(input.directory); - if (client) { - await client.closeTerminals(input.directory); - for (const sessionId of [...sessionIds].reverse()) { - await client.deleteSession(input.directory, sessionId); + const { client } = deps; + stage = 'process_cleanup'; + if (client) { + for (const sessionId of sessionIds) { + await client.stopSessionProcesses(input.directory, sessionId); + } } + stage = 'terminal_cleanup'; + await deps.detachTerminals?.(input.directory); + if (client) { + await client.closeTerminals(input.directory); + stage = 'session_delete'; + for (const sessionId of [...sessionIds].reverse()) { + await client.deleteSession(input.directory, sessionId); + } + stage = 'session_delete_confirmation'; + for (const sessionId of sessionIds) { + if (await client.getSession(input.directory, sessionId)) { + stage = 'session_delete_unconfirmed'; + throw new Error('Kilo session deletion was not confirmed'); + } + } + stage = 'directory_dispose'; + await client.disposeDirectory(input.directory); + } + stage = 'runtime_retirement'; + await deps.retireDirectory?.(input.directory); + stage = 'directory_validation'; + await (deps.assertDirectory ?? assertNoSymlinks)(input.directory); + stage = 'directory_removal'; + await ( + deps.removeDirectory ?? (directory => fs.rm(directory, { recursive: true, force: true })) + )(input.directory); + stage = 'root_detach'; for (const sessionId of sessionIds) { - if (await client.getSession(input.directory, sessionId)) - throw new Error('Kilo session deletion was not confirmed'); + forgetAttachedRoot(sessionId, input.directory); + deps.detachRoot?.(sessionId); } - await client.disposeDirectory(input.directory); - } - await deps.retireDirectory?.(input.directory); - await (deps.assertDirectory ?? assertNoSymlinks)(input.directory); - await (deps.removeDirectory ?? (directory => fs.rm(directory, { recursive: true, force: true })))( - input.directory - ); - for (const sessionId of sessionIds) { - forgetAttachedRoot(sessionId, input.directory); - deps.detachRoot?.(sessionId); + diagnostic('completed'); + return { deleted: true, sessionIds }; + } catch (error) { + diagnostic('failed'); + throw error; } - return { deleted: true, sessionIds }; } diff --git a/services/cloud-agent-next/wrapper/src/control/main.ts b/services/cloud-agent-next/wrapper/src/control/main.ts index c6f1ad2515..1b6c003b94 100644 --- a/services/cloud-agent-next/wrapper/src/control/main.ts +++ b/services/cloud-agent-next/wrapper/src/control/main.ts @@ -21,6 +21,8 @@ import { controlLogWrapperIdSchema } from '../../../src/shared/control-diagnosti const retirementCauses = new Map([ ['Kilo event feed is no longer healthy', 'event_feed_unhealthy'], + ['process_exited', 'process_exited'], + ['credential_refresh_failed', 'credential_refresh_failed'], ['Sandbox control connection lost', 'control_disconnected'], ['Preparation event delivery failed', 'preparation_delivery_failed'], ['Sandbox shutting down', 'requested_shutdown'], @@ -146,6 +148,7 @@ function main(diagnostics: ControlDiagnostics, wrapperInstanceId: string): void exitCode, retirementCause: retirementCauses.get(reason) ?? + retirementCauses.get(diagnosticReason) ?? (diagnosticReason.startsWith('feed_') ? 'event_feed_unhealthy' : 'unknown'), }); void diagnostics.flush(); diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts index 717d293c5d..0d95f90f3a 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts @@ -1,6 +1,7 @@ import path from 'node:path'; import { emitControlDiagnostic, + type ControlDiagnosticRecord, type ControlDiagnosticReporter, } from '../../../src/shared/control-diagnostics.js'; import { @@ -450,8 +451,24 @@ export async function handleControlRequest( } const kiloRuntimes = deps.kiloRuntimes; if (!kiloRuntimes) return missingKilo(); + const startedAt = Date.now(); + let failureStage: ControlDiagnosticRecord['fields']['stage'] = 'deletion_fence'; + const diagnostic = ( + phase: 'started' | 'completed' | 'failed', + stage: NonNullable + ): void => + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation, + phase, + stage, + worktreeId: input.worktreeId, + sessionCount: input.sessionIds.length, + elapsedMs: Math.max(0, Date.now() - startedAt), + }); try { const fenced = fenceDirectoryOperations(input.directory); + diagnostic('started', 'deletion_fence'); + failureStage = 'task_cancellation'; const tasks = [...deps.tasks.values()].filter( task => task.session.directory === input.directory ); @@ -459,15 +476,20 @@ export async function handleControlRequest( task.controller.abort(new ControlTaskCancellation('cancelled', 'Worktree deleted')); } const results = await Promise.all(tasks.map(task => task.done)); + failureStage = 'deletion_fence'; await fenced; + diagnostic('completed', 'deletion_fence'); if (results.some((result, index) => !result.ok && tasks[index]?.kind !== 'preparation')) { + diagnostic('failed', 'task_cancellation'); return fail('not_ready', 'Worktree cancellation is incomplete', true); } + failureStage = 'runtime_lookup'; const runtime = kiloRuntimes.get(input.directory); const client = deps.worktreeCleanupClient ?? (runtime ? createWorktreeKiloCleanupClient(runtime.kiloClient.serverUrl) : undefined); const cleanupDeps = { + onDiagnostic: deps.onDiagnostic, client, detachRoot: (id: string) => { deps.activity?.detach(id); @@ -481,6 +503,7 @@ export async function handleControlRequest( await kiloRuntimes.deleteDirectory(directory); }, }; + failureStage = undefined; if (operation === 'worktree.prepareDeletion') { return ok({ prepared: true, @@ -489,6 +512,7 @@ export async function handleControlRequest( } return ok(await deleteWorktree(input, cleanupDeps)); } catch { + if (failureStage) diagnostic('failed', failureStage); return fail('not_ready', 'Worktree cleanup is incomplete', true); } } @@ -640,6 +664,7 @@ async function handleAttach( deps, async owned => { const result = await (deps.applyAttach ?? applySessionAttach)(session, parsed.data, { + onDiagnostic: deps.onDiagnostic, kiloRuntimes: deps.kiloRuntimes, signal: owned.signal, canRefreshCredentials: () => From 97f0e1a37d84fbfc7110af80561c98a3ede700b8 Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Tue, 1 Sep 2026 22:41:16 +0200 Subject: [PATCH 3/6] feat(cloud-agent-next): trace accepted-runtime reconciliation --- services/cloud-agent-next/DEBUG.md | 8 + .../src/sandbox-session/SandboxSession.ts | 354 +++++++++++++----- .../src/shared/control-diagnostics.ts | 20 + .../src/control/sandbox-control-handlers.ts | 168 +++++++-- 4 files changed, 438 insertions(+), 112 deletions(-) diff --git a/services/cloud-agent-next/DEBUG.md b/services/cloud-agent-next/DEBUG.md index 338716ac5b..60b7ac553a 100644 --- a/services/cloud-agent-next/DEBUG.md +++ b/services/cloud-agent-next/DEBUG.md @@ -198,6 +198,14 @@ Worker `worktree_ownership` records distinguish `exclusive`, `shared`, and `unre Wrapper `control.request` attachment summaries separate `workspaceAction` (reuse or bootstrap) from `sessionResolution` (existing, restored, or created chat). Worktree deletion records include the first fence/drain, preparation/deletion outcome, stage, and session count. These records contain IDs and fixed outcomes, not repository paths, credentials, or session content. +### Accepted-message Reconciliation + +For `runtime_unhealthy`, correlate Worker `accepted_reconciliation` and `session_sync` records by `messageId`, expected wrapper identity, and lifecycle epoch. Reconciliation records distinguish healthy, superseded, and unhealthy decisions. The unhealthy decision is logged before failure/cleanup starts; `session_message_committed` remains the durable message-state confirmation. `session_interrupt_failed` identifies the separate explicit-abort path that can produce the same public failure reason. + +`session_sync` identifies its trigger (`accepted_alarm` or `pending_interactions`), failed stage, timeout, observed physical/connection state, and expected versus observed wrapper identity. It records safe response codes and validation counts, never raw errors or response payloads. Compare `receivedQuestionCount`/`receivedPermissionCount` with `questionCount`/`permissionCount` to see root scoping, and check `interactionSnapshotApplied` for revision-fenced snapshots. A successful sync means the snapshot was fetched and processed, not necessarily that accepted work is still active; the reconciliation decision applies the activity rule afterward. + +Wrapper `control.request` records for `session.sync` separate status, question, and permission reads from the overall `sync_result`. `nativeStatus`, `syncStatus`, and `ownedTask` show the task-owned busy override. Pending-query flags are frozen when the shared request signal aborts, so a query that ignores cancellation is still visible. Missing counts mean no successful result was available; they are not zero counts. The three reads retain their original shared deadline and parallel execution. + ## Interpreting Common States - Worker queueing succeeds, but no wrapper logs appear: diff --git a/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts b/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts index 76fd437a96..936ce76749 100644 --- a/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts +++ b/services/cloud-agent-next/src/sandbox-session/SandboxSession.ts @@ -2,6 +2,7 @@ import { DurableObject } from 'cloudflare:workers'; import { TRPCError } from '@trpc/server'; import { withTimeout } from '@kilocode/worker-utils'; import { z } from 'zod'; +import { diagnosticSyncStatus } from '../shared/control-diagnostics.js'; import { cloudAgentWorktreeIdSchema, cloudAgentWorktreeLocationSchema, @@ -82,6 +83,7 @@ import { import { SANDBOX_CONTROL_ATTACH_TIMEOUT_MS, SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, + controlErrorCodes, sessionAttachResultSchema, sessionMessageOutcomeSchema, sessionPromptResultSchema, @@ -652,6 +654,21 @@ export class SandboxSession extends DurableObject { return { success: true }; } catch { if (!this.isCurrentAcceptedMessage(accepted, epoch)) return { success: true }; + logControlDiagnostic( + 'session_interrupt_failed', + { + sessionId: this.sessionId, + messageId: accepted.messageId, + expectedWrapperInstanceId: accepted.wrapperInstanceId, + sandboxId, + kiloSessionId, + worktreeId: metadata?.workspace?.worktreeId, + epoch, + operation: 'session.abort', + cause: 'runtime_unhealthy', + }, + 'warn' + ); await this.failDelivery(accepted.messageId, 'runtime_unhealthy', accepted.wrapperInstanceId); return { success: false, message: 'The session runtime could not be interrupted' }; } @@ -1107,24 +1124,61 @@ export class SandboxSession extends DurableObject { decision.action === 'rearm' ? decision.at : now + DEADLINE_MS.acceptedAlarmCap ); if (decision.action === 'check') { + const startedAt = Date.now(); + const diagnostic: ControlDiagnosticFields = { + sessionId: this.sessionId, + messageId: accepted.messageId, + expectedWrapperInstanceId: accepted.wrapperInstanceId, + epoch, + acceptedAt: accepted.acceptedAt, + lastActivityAt: accepted.lastActivityAt, + stage: 'sync', + }; + const report = (result: 'healthy' | 'superseded' | 'runtime_unhealthy') => + logControlDiagnostic( + 'accepted_reconciliation', + { ...diagnostic, phase: 'finished', result, durationMs: Date.now() - startedAt }, + result === 'runtime_unhealthy' ? 'warn' : 'info' + ); + logControlDiagnostic('accepted_reconciliation', { ...diagnostic, phase: 'started' }); try { - const snapshot = await this.syncAcceptedMessage(accepted, epoch); - if (!snapshot || !this.isCurrentAcceptedMessage(accepted, epoch)) return; + const snapshot = await this.syncAcceptedMessage(accepted, epoch, 'accepted_alarm'); + if (!snapshot || !this.isCurrentAcceptedMessage(accepted, epoch)) { + diagnostic.reason = snapshot ? 'accepted_message_changed' : 'sync_superseded'; + report('superseded'); + return; + } + diagnostic.stage = 'activity_check'; + diagnostic.syncStatus = diagnosticSyncStatus(snapshot.status.type); + diagnostic.questionCount = snapshot.questions.length; + diagnostic.permissionCount = snapshot.permissions.length; const healthy = snapshot.status.type === 'busy' || snapshot.status.type === 'retry' || snapshot.questions.length > 0 || snapshot.permissions.length > 0; - if (!healthy) throw new Error('Accepted execution is no longer active'); + diagnostic.healthy = healthy; + if (!healthy) { + diagnostic.reason = 'inactive_snapshot'; + throw new Error('Accepted execution is no longer active'); + } + diagnostic.stage = 'record_activity'; const active = recordAcceptedMessageActivity(this.loadMessages(), Date.now()); - if (active) this.saveMessages(active, epoch); + diagnostic.activityRecorded = active ? this.saveMessages(active, epoch) : false; + report('healthy'); } catch { if (this.isCurrentAcceptedMessage(accepted, epoch)) { + diagnostic.reason ??= + diagnostic.stage === 'record_activity' ? 'activity_record_failed' : 'sync_failed'; + report('runtime_unhealthy'); await this.failDelivery( accepted.messageId, 'runtime_unhealthy', accepted.wrapperInstanceId ); + } else { + diagnostic.reason = 'accepted_message_changed'; + report('superseded'); } } } @@ -1849,92 +1903,220 @@ export class SandboxSession extends DurableObject { private async syncAcceptedMessage( message: MessageRecord, - epoch: number + epoch: number, + trigger: 'accepted_alarm' | 'pending_interactions' ): Promise { - const metadata = this.terminalLifecycle.getStoredMetadata(); - const sandboxId = metadata?.workspace?.sandboxId; - const kiloSessionId = metadata?.auth.kiloSessionId; - if ( - !metadata || - !sandboxId || - !kiloSessionId || - !message.wrapperInstanceId || - this.pendingRuntimeCleanup() - ) { - throw new Error('Accepted runtime is unavailable'); - } - const control = sandboxControlRpc(this.env, sandboxId); - const status = await withTimeout( - control.getStatus(), - SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, - 'Runtime status timed out' - ); - if (!this.isCurrentAcceptedMessage(message, epoch)) return undefined; - if ( - status.connection !== 'ready' || - status.physical !== 'running' || - status.wrapperInstanceId !== message.wrapperInstanceId - ) { - throw new Error('Accepted runtime is not ready'); - } - const revision = this.readPendingInteractions()?.revision; - const response = await withTimeout( - control.request({ - operation: 'session.sync', - expectedWrapperInstanceId: message.wrapperInstanceId, - session: { - sessionId: metadata.identity.sessionId, - kiloSessionId, - directory: this.directory(metadata), - }, - payload: {}, - }), - SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, - 'Session sync timed out' - ); - if (!this.isCurrentAcceptedMessage(message, epoch)) return undefined; - if (!response.ok) throw new Error('Session sync failed'); - const parsed = sessionSyncResultSchema.parse(response.result); - const belongsToRoot = (request: unknown): boolean => { - if ( - typeof request !== 'object' || - request === null || - Array.isArray(request) || - !('id' in request) || - typeof request.id !== 'string' || - request.id.length === 0 || - !('sessionID' in request) || - typeof request.sessionID !== 'string' || - request.sessionID.length === 0 - ) - return false; - const root = 'rootKiloSessionId' in request ? request.rootKiloSessionId : undefined; - return root === undefined ? request.sessionID === kiloSessionId : root === kiloSessionId; + const startedAt = Date.now(); + const diagnostic: ControlDiagnosticFields = { + sessionId: this.sessionId, + messageId: message.messageId, + expectedWrapperInstanceId: message.wrapperInstanceId, + epoch, + trigger, + stage: 'runtime_context', + timeoutMs: SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, + timedOut: false, }; - const result = metadata.workspace?.worktreeId - ? { - ...parsed, - questions: parsed.questions.filter(belongsToRoot), - permissions: parsed.permissions.filter(belongsToRoot), + let outcome: 'synced' | 'superseded' | 'failed' = 'failed'; + logControlDiagnostic('session_sync', { ...diagnostic, phase: 'started' }); + try { + const metadata = this.terminalLifecycle.getStoredMetadata(); + const sandboxId = metadata?.workspace?.sandboxId; + const kiloSessionId = metadata?.auth.kiloSessionId; + diagnostic.sandboxId = sandboxId; + diagnostic.kiloSessionId = kiloSessionId; + diagnostic.worktreeId = metadata?.workspace?.worktreeId; + if ( + !metadata || + !sandboxId || + !kiloSessionId || + !message.wrapperInstanceId || + this.pendingRuntimeCleanup() + ) { + diagnostic.reason = !metadata + ? 'missing_metadata' + : !sandboxId + ? 'missing_sandbox' + : !kiloSessionId + ? 'missing_kilo_session' + : !message.wrapperInstanceId + ? 'missing_wrapper_identity' + : 'cleanup_pending'; + throw new Error('Accepted runtime is unavailable'); + } + const control = sandboxControlRpc(this.env, sandboxId); + diagnostic.stage = 'runtime_status'; + const status = await withTimeout( + control.getStatus(), + SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, + 'Runtime status timed out', + () => { + diagnostic.timedOut = true; + } + ); + if (!this.isCurrentAcceptedMessage(message, epoch)) { + outcome = 'superseded'; + diagnostic.reason = 'accepted_message_changed'; + return undefined; + } + diagnostic.stage = 'runtime_identity'; + const connection = status?.connection; + const physical = status?.physical; + const observedWrapperId = status?.wrapperInstanceId; + const observedWrapper = wrapperInstanceIdSchema.safeParse(observedWrapperId); + diagnostic.connection = + connection === undefined + ? 'missing' + : ['disconnected', 'connected', 'ready'].includes(connection) + ? connection + : 'other'; + diagnostic.physical = + physical === undefined + ? 'missing' + : ['stopped', 'creating', 'running', 'stopping', 'failed', 'unknown'].includes(physical) + ? physical + : 'other'; + diagnostic.observedWrapperInstanceId = + observedWrapperId === undefined + ? undefined + : observedWrapper.success + ? observedWrapper.data + : 'invalid'; + diagnostic.wrapperMatches = observedWrapperId === message.wrapperInstanceId; + if ( + status.connection !== 'ready' || + status.physical !== 'running' || + status.wrapperInstanceId !== message.wrapperInstanceId + ) { + diagnostic.reason = + status.connection !== 'ready' + ? 'connection_not_ready' + : status.physical !== 'running' + ? 'physical_not_running' + : 'wrapper_mismatch'; + throw new Error('Accepted runtime is not ready'); + } + diagnostic.stage = 'read_interactions'; + const revision = this.readPendingInteractions()?.revision; + diagnostic.interactionRevision = revision; + diagnostic.stage = 'sync_request'; + const response = await withTimeout( + control.request({ + operation: 'session.sync', + expectedWrapperInstanceId: message.wrapperInstanceId, + session: { + sessionId: metadata.identity.sessionId, + kiloSessionId, + directory: this.directory(metadata), + }, + payload: {}, + }), + SANDBOX_CONTROL_REQUEST_TIMEOUT_MS, + 'Session sync timed out', + () => { + diagnostic.timedOut = true; } - : parsed; - if (this.readPendingInteractions()?.revision === revision) { - this.ctx.storage.kv.put(PENDING_INTERACTIONS_KEY, { - revision: (revision ?? 0) + 1, - questions: result.questions, - permissions: result.permissions, + ); + if (!this.isCurrentAcceptedMessage(message, epoch)) { + outcome = 'superseded'; + diagnostic.reason = 'accepted_message_changed'; + return undefined; + } + diagnostic.requestId = response?.requestId; + diagnostic.responseOk = typeof response?.ok === 'boolean' ? response.ok : undefined; + if (!response.ok) { + diagnostic.reason = 'sync_rejected'; + const errorCode = response.error?.code; + diagnostic.errorCode = controlErrorCodes.some(code => code === errorCode) + ? errorCode + : 'other'; + diagnostic.retryable = + typeof response.error?.retryable === 'boolean' ? response.error.retryable : undefined; + throw new Error('Session sync failed'); + } + diagnostic.stage = 'validate_sync_result'; + const parsed = sessionSyncResultSchema.parse(response.result); + diagnostic.syncStatus = diagnosticSyncStatus(parsed.status.type); + diagnostic.receivedQuestionCount = parsed.questions.length; + diagnostic.receivedPermissionCount = parsed.permissions.length; + const belongsToRoot = (request: unknown): boolean => { + if ( + typeof request !== 'object' || + request === null || + Array.isArray(request) || + !('id' in request) || + typeof request.id !== 'string' || + request.id.length === 0 || + !('sessionID' in request) || + typeof request.sessionID !== 'string' || + request.sessionID.length === 0 + ) + return false; + const root = 'rootKiloSessionId' in request ? request.rootKiloSessionId : undefined; + return root === undefined ? request.sessionID === kiloSessionId : root === kiloSessionId; + }; + diagnostic.stage = 'scope_interactions'; + const result = metadata.workspace?.worktreeId + ? { + ...parsed, + questions: parsed.questions.filter(belongsToRoot), + permissions: parsed.permissions.filter(belongsToRoot), + } + : parsed; + diagnostic.questionCount = result.questions.length; + diagnostic.permissionCount = result.permissions.length; + diagnostic.stage = 'interaction_revision'; + const applyInteractions = this.readPendingInteractions()?.revision === revision; + diagnostic.interactionSnapshotApplied = false; + if (applyInteractions) { + diagnostic.stage = 'persist_interactions'; + this.ctx.storage.kv.put(PENDING_INTERACTIONS_KEY, { + revision: (revision ?? 0) + 1, + questions: result.questions, + permissions: result.permissions, + }); + diagnostic.interactionSnapshotApplied = true; + } + diagnostic.stage = 'persist_status'; + persistSandboxControlSessionEvent({ + sessionId: metadata.identity.sessionId, + payload: { + type: 'session.status', + properties: { sessionID: kiloSessionId, status: result.status }, + }, + eventQueries: this.eventQueries, + broadcast: event => this.broadcastStoredEvent(event), }); + outcome = 'synced'; + return result; + } catch (error) { + diagnostic.reason ??= diagnostic.timedOut + ? 'timeout' + : error instanceof z.ZodError + ? 'invalid_response' + : 'operation_failed'; + diagnostic.errorClass = + error instanceof z.ZodError + ? 'validation_error' + : error instanceof TypeError + ? 'type_error' + : error instanceof Error + ? 'error' + : 'non_error'; + if (error instanceof z.ZodError) { + diagnostic.validationIssueCount = error.issues.length; + diagnostic.invalidStatus = error.issues.some(issue => issue.path[0] === 'status'); + diagnostic.invalidQuestions = error.issues.some(issue => issue.path[0] === 'questions'); + diagnostic.invalidPermissions = error.issues.some(issue => issue.path[0] === 'permissions'); + } + throw error; + } finally { + logControlDiagnostic( + 'session_sync', + { ...diagnostic, phase: 'finished', result: outcome, durationMs: Date.now() - startedAt }, + outcome === 'failed' ? 'warn' : 'info' + ); } - persistSandboxControlSessionEvent({ - sessionId: metadata.identity.sessionId, - payload: { - type: 'session.status', - properties: { sessionID: kiloSessionId, status: result.status }, - }, - eventQueries: this.eventQueries, - broadcast: event => this.broadcastStoredEvent(event), - }); - return result; } private async derivePendingInteractions(): Promise< @@ -1945,7 +2127,7 @@ export class SandboxSession extends DurableObject { const accepted = this.loadMessages().find(message => message.state === 'accepted'); if (accepted) { try { - await this.syncAcceptedMessage(accepted, epoch); + await this.syncAcceptedMessage(accepted, epoch, 'pending_interactions'); } catch { logger .withFields({ sessionId: this.sessionId }) diff --git a/services/cloud-agent-next/src/shared/control-diagnostics.ts b/services/cloud-agent-next/src/shared/control-diagnostics.ts index e35dd830ed..c1488e2ca4 100644 --- a/services/cloud-agent-next/src/shared/control-diagnostics.ts +++ b/services/cloud-agent-next/src/shared/control-diagnostics.ts @@ -28,6 +28,7 @@ export const controlLogWrapperIdSchema = z.string().uuid(); const identifier = z.string().regex(/^[A-Za-z0-9_:-]{1,128}$/); const count = z.number().int().min(0).max(Number.MAX_SAFE_INTEGER); const milliseconds = z.number().min(0).max(Number.MAX_SAFE_INTEGER); +const syncStatusSchema = z.enum(['idle', 'busy', 'retry', 'finalizing', 'other']); export const controlDiagnosticFieldsSchema = z .object({ @@ -101,6 +102,11 @@ export const controlDiagnosticFieldsSchema = z 'deletion_fence', 'task_cancellation', 'runtime_lookup', + 'sync_validation', + 'sync_status', + 'sync_questions', + 'sync_permissions', + 'sync_result', 'directory_validation', 'manifest_discovery', 'session_abort', @@ -120,6 +126,8 @@ export const controlDiagnosticFieldsSchema = z sessionResolution: z.enum(['existing', 'restored', 'created']).optional(), kind: z.enum(['preparation', 'execution', 'finalizing']).optional(), status: z.enum(['completed', 'failed', 'cancelled']).optional(), + nativeStatus: z.enum(['missing', ...syncStatusSchema.options]).optional(), + syncStatus: syncStatusSchema.optional(), category: z .enum([ 'outcome', @@ -170,6 +178,8 @@ export const controlDiagnosticFieldsSchema = z sequence: count.optional(), eventsReceived: count.optional(), sessionCount: count.optional(), + questionCount: count.optional(), + permissionCount: count.optional(), bufferedBytes: count.optional(), bytes: count.optional(), attempt: count.optional(), @@ -181,6 +191,11 @@ export const controlDiagnosticFieldsSchema = z wasClean: z.boolean().optional(), ok: z.boolean().optional(), aborted: z.boolean().optional(), + timedOut: z.boolean().optional(), + ownedTask: z.boolean().optional(), + statusQueryPending: z.boolean().optional(), + questionQueryPending: z.boolean().optional(), + permissionQueryPending: z.boolean().optional(), }) .strict(); @@ -226,6 +241,11 @@ export const controlLogBatchSchema = z export type ControlLogBatch = z.infer; +export function diagnosticSyncStatus(value: unknown): z.infer { + const parsed = syncStatusSchema.safeParse(value); + return parsed.success ? parsed.data : 'other'; +} + export function emitControlDiagnostic( callback: ControlDiagnosticReporter | undefined, event: string, diff --git a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts index 0d95f90f3a..2f4bc44581 100644 --- a/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts +++ b/services/cloud-agent-next/wrapper/src/control/sandbox-control-handlers.ts @@ -1,5 +1,6 @@ import path from 'node:path'; import { + diagnosticSyncStatus, emitControlDiagnostic, type ControlDiagnosticRecord, type ControlDiagnosticReporter, @@ -527,6 +528,24 @@ export async function handleControlRequest( operation !== 'session.abort' && operation !== 'session.detach' ) { + if (operation === 'session.sync') { + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation, + phase: 'failed', + stage: 'runtime_lookup', + sessionId: session.sessionId, + kiloSessionId: session.kiloSessionId, + elapsedMs: 0, + ok: false, + errorCode: 'not_ready', + retryable: true, + aborted: deps.signal?.aborted ?? false, + ownedTask: deps.tasks.has(session.kiloSessionId), + statusQueryPending: false, + questionQueryPending: false, + permissionQueryPending: false, + }); + } return missingKilo(); } @@ -1176,36 +1195,122 @@ async function handleSync( payload: unknown, deps: HandlerDeps ): Promise { + const startedAt = Date.now(); + const pending = { sync_status: false, sync_questions: false, sync_permissions: false }; + let pendingAtAbort: typeof pending | undefined; + let nativeStatus: ControlDiagnosticRecord['fields']['nativeStatus']; + let questionCount: number | undefined; + let permissionCount: number | undefined; + const diagnostic = ( + phase: 'completed' | 'failed', + stage: NonNullable, + fields: Partial = {} + ): void => { + const queries = pendingAtAbort ?? pending; + emitControlDiagnostic(deps.onDiagnostic, 'control.request', { + operation: 'session.sync', + phase, + stage, + sessionId: session.sessionId, + kiloSessionId: session.kiloSessionId, + elapsedMs: Math.max(0, Date.now() - startedAt), + ok: phase === 'completed', + aborted: deps.signal?.aborted ?? false, + ownedTask: deps.tasks.has(session.kiloSessionId), + statusQueryPending: queries.sync_status, + questionQueryPending: queries.sync_questions, + permissionQueryPending: queries.sync_permissions, + nativeStatus, + questionCount, + permissionCount, + ...fields, + }); + }; const kiloClient = sessionKiloRuntime(session, deps)?.kiloClient; - if (!kiloClient) return missingKilo(); + if (!kiloClient) { + diagnostic('failed', 'runtime_lookup', { errorCode: 'not_ready', retryable: true }); + return missingKilo(); + } if (!sessionSyncPayloadSchema.safeParse(payload).success) { + diagnostic('failed', 'sync_validation', { errorCode: 'protocol_error', retryable: false }); return fail('protocol_error', 'Invalid payload', false); } try { - const [statuses, questions, permissions] = await withKiloRequestDeadline( - signal => - Promise.all([ - kiloClient.getSessionStatuses( - directoryForSession(session.kiloSessionId) ?? session.directory, - signal - ), - readRootRequests( - session, - (directory, signal) => kiloClient.getQuestions(directory, signal), - signal - ), - readRootRequests( - session, - (directory, signal) => kiloClient.getPermissions(directory, signal), - signal - ), - ]), - deps.signal - ); - return ok({ - status: deps.tasks.has(session.kiloSessionId) - ? { type: 'busy' } - : (statuses[session.kiloSessionId] ?? { type: 'idle' }), + const [statuses, questions, permissions] = await withKiloRequestDeadline(signal => { + signal.addEventListener( + 'abort', + () => { + pendingAtAbort = { ...pending }; + }, + { once: true } + ); + const query = ( + stage: keyof typeof pending, + read: () => Promise, + completed: (value: Value) => void + ): Promise => { + pending[stage] = true; + const failed = (error: unknown): never => { + pending[stage] = false; + diagnostic('failed', stage, { aborted: signal.aborted }); + throw error; + }; + try { + return read().then(value => { + pending[stage] = false; + completed(value); + diagnostic('completed', stage, { aborted: signal.aborted }); + return value; + }, failed); + } catch (error) { + return failed(error); + } + }; + return Promise.all([ + query( + 'sync_status', + () => + kiloClient.getSessionStatuses( + directoryForSession(session.kiloSessionId) ?? session.directory, + signal + ), + statuses => { + const status = statuses?.[session.kiloSessionId]; + nativeStatus = status == null ? 'missing' : diagnosticSyncStatus(status.type); + } + ), + query( + 'sync_questions', + () => + readRootRequests( + session, + (directory, signal) => kiloClient.getQuestions(directory, signal), + signal + ), + questions => { + questionCount = questions.length; + } + ), + query( + 'sync_permissions', + () => + readRootRequests( + session, + (directory, signal) => kiloClient.getPermissions(directory, signal), + signal + ), + permissions => { + permissionCount = permissions.length; + } + ), + ]); + }, deps.signal); + const ownedTask = deps.tasks.has(session.kiloSessionId); + const status = ownedTask + ? { type: 'busy' } + : (statuses[session.kiloSessionId] ?? { type: 'idle' }); + const result = ok({ + status, questions: questions.map(({ request }) => request.sessionID === session.kiloSessionId ? request @@ -1217,7 +1322,18 @@ async function handleSync( : { ...request, rootKiloSessionId: session.kiloSessionId } ), }); + diagnostic('completed', 'sync_result', { + ownedTask, + syncStatus: diagnosticSyncStatus(status.type), + }); + return result; } catch (error) { - return kiloFailure(error); + const result = kiloFailure(error); + diagnostic('failed', 'sync_result', { + errorCode: 'not_ready', + retryable: !result.ok && result.error.retryable, + timedOut: error instanceof Error && error.message === 'Kilo request timed out', + }); + return result; } } From 2ed686585cdd35e0d3e923c63ec733d352b197cb Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Tue, 1 Sep 2026 23:17:46 +0200 Subject: [PATCH 4/6] perf(cloud-agent-next): reduce streaming diagnostic volume --- services/cloud-agent-next/DEBUG.md | 2 +- .../src/persistence/SandboxControl.ts | 22 +++++++++++++++---- .../src/sandbox-control/diagnostics.ts | 16 ++++++++++++++ .../src/sandbox-control/socket.ts | 13 ++++++++++- 4 files changed, 47 insertions(+), 6 deletions(-) diff --git a/services/cloud-agent-next/DEBUG.md b/services/cloud-agent-next/DEBUG.md index 60b7ac553a..de6a88b360 100644 --- a/services/cloud-agent-next/DEBUG.md +++ b/services/cloud-agent-next/DEBUG.md @@ -186,7 +186,7 @@ GET /internal/sandbox-logs//// { dropped: 0, notApplied: 0, failed: 0, + maxQueueWaitMs: 0, + maxRpcWaitMs: 0, + maxTotalForwardMs: 0, }; private lastAcceptedHeartbeat: { connectionId: string; at: number } | null = null; private credentialUpdates: Promise = Promise.resolve(); @@ -2725,9 +2728,11 @@ export class SandboxControl extends DurableObject { .then(async () => { this.forwarding.waiting--; this.forwarding.inFlight++; + const queueWaitMs = Date.now() - queuedAt; + this.forwarding.maxQueueWaitMs = Math.max(this.forwarding.maxQueueWaitMs, queueWaitMs); this.logDiagnostic('forward_started', { ...fields, - queueWaitMs: Date.now() - queuedAt, + queueWaitMs, ...this.forwarding, }); try { @@ -2736,9 +2741,14 @@ export class SandboxControl extends DurableObject { } finally { this.forwarding.inFlight--; this.forwarding.settled++; + const totalForwardMs = Date.now() - queuedAt; + this.forwarding.maxTotalForwardMs = Math.max( + this.forwarding.maxTotalForwardMs, + totalForwardMs + ); this.logDiagnostic('forward_settled', { ...fields, - totalForwardMs: Date.now() - queuedAt, + totalForwardMs, ...this.forwarding, }); } @@ -2790,6 +2800,8 @@ export class SandboxControl extends DurableObject { } ).then( result => { + const rpcWaitMs = Date.now() - startedAt; + this.forwarding.maxRpcWaitMs = Math.max(this.forwarding.maxRpcWaitMs, rpcWaitMs); if (!skipped && result?.applied === false) this.forwarding.notApplied++; this.logDiagnostic('forward_result', { ...diagnostic, @@ -2797,12 +2809,14 @@ export class SandboxControl extends DurableObject { attempts, result: skipped ? 'skipped' : 'delivered', applied: skipped ? undefined : result?.applied, - rpcWaitMs: Date.now() - startedAt, + rpcWaitMs, ...this.forwarding, }); return true; }, () => { + const rpcWaitMs = Date.now() - startedAt; + this.forwarding.maxRpcWaitMs = Math.max(this.forwarding.maxRpcWaitMs, rpcWaitMs); this.forwarding.failed++; this.logDiagnostic( 'forward_result', @@ -2811,7 +2825,7 @@ export class SandboxControl extends DurableObject { operation, attempts, result: timedOut ? 'timed_out' : 'failed', - rpcWaitMs: Date.now() - startedAt, + rpcWaitMs, ...this.forwarding, }, 'warn' diff --git a/services/cloud-agent-next/src/sandbox-control/diagnostics.ts b/services/cloud-agent-next/src/sandbox-control/diagnostics.ts index b411ccb409..fd94807f46 100644 --- a/services/cloud-agent-next/src/sandbox-control/diagnostics.ts +++ b/services/cloud-agent-next/src/sandbox-control/diagnostics.ts @@ -65,12 +65,28 @@ export function diagnosticCause(value: string): string { return CAUSES.has(value) ? value.replaceAll(' ', '_') : 'other'; } +const DELTA_PROGRESS_EVENTS = new Set([ + 'socket_frame_received', + 'forward_enqueued', + 'forward_started', + 'forward_settled', +]); + export function logControlDiagnostic( event: string, fields: ControlDiagnosticFields, level: 'info' | 'warn' = 'info' ): void { try { + if ( + level === 'info' && + fields.eventType === 'message.part.delta' && + (DELTA_PROGRESS_EVENTS.has(event) || + (event === 'forward_result' && fields.result === 'delivered' && fields.applied === true) || + (event === 'session_event_result' && fields.applied === true)) + ) { + return; + } const bounded: ControlDiagnosticFields = {}; for (const [key, value] of Object.entries(fields).slice(0, 48)) { if (!/^[a-zA-Z][a-zA-Z0-9]{0,63}$/.test(key)) continue; diff --git a/services/cloud-agent-next/src/sandbox-control/socket.ts b/services/cloud-agent-next/src/sandbox-control/socket.ts index 179b2ed794..5d0495ea3a 100644 --- a/services/cloud-agent-next/src/sandbox-control/socket.ts +++ b/services/cloud-agent-next/src/sandbox-control/socket.ts @@ -298,11 +298,22 @@ export function createSandboxControlSocketHandler( } const frame = parsed.frame; + let eventType = frame.type === 'event' ? diagnosticEventType(frame.event) : undefined; + if ( + frame.type === 'event' && + frame.event === 'session.event' && + typeof frame.payload === 'object' && + frame.payload !== null && + 'type' in frame.payload && + typeof frame.payload.type === 'string' + ) { + eventType = diagnosticEventType(frame.payload.type); + } const frameDiagnostic = { ...diagnostic, frameType: frame.type, frameBytes: parsed.bytes, - eventType: frame.type === 'event' ? diagnosticEventType(frame.event) : undefined, + eventType, operation: frame.type === 'request' && isControlOperation(frame.operation) ? frame.operation From 129e53c24b8ff1cfc14560239b71d2f4f31769fa Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Tue, 1 Sep 2026 23:42:46 +0200 Subject: [PATCH 5/6] refactor(cloud-agent-next): remove archive read endpoints --- services/cloud-agent-next/DEBUG.md | 9 +-- .../src/sandbox-control/log-routes.test.ts | 62 +++---------------- .../src/sandbox-control/log-routes.ts | 62 +------------------ services/cloud-agent-next/src/server.test.ts | 26 ++++---- services/cloud-agent-next/src/server.ts | 2 +- 5 files changed, 25 insertions(+), 136 deletions(-) diff --git a/services/cloud-agent-next/DEBUG.md b/services/cloud-agent-next/DEBUG.md index de6a88b360..c10ccaecfa 100644 --- a/services/cloud-agent-next/DEBUG.md +++ b/services/cloud-agent-next/DEBUG.md @@ -177,14 +177,7 @@ logs/control////.json `sandboxId` is the logical SandboxControl ID, not the `workspace_*` session ID or physical provider allocation name. Use Worker logs to correlate these IDs. Each allocation/wrapper has separate immutable batches; sort them by the batch `sequence` and record `timestamp`, not the random batch ID. Check `droppedRecords` and `droppedTerminalRecords` for buffer overflow or rejected diagnostic records. -Internal API authentication is required to list or download these archives: - -```text -GET /internal/sandbox-logs/?cursor= -GET /internal/sandbox-logs//// -``` - -Listing returns at most 100 objects and a continuation cursor. Download paths omit the `.json` suffix. These reads use R2 only and work after the container disappears. The legacy `getWrapperLogs` live-file reader and tarball retrieval do not read these JSON archives. +List and download these JSON batches directly from R2 using local tooling and the key prefix above. Uploaded batches remain available after the container disappears, subject to the bucket's retention policy. The legacy `getWrapperLogs` live-file reader and tarball retrieval do not read these JSON archives. Worker/DO diagnostics remain in Cloudflare logs/Axiom, not these wrapper archives. Successful `message.part.delta` forwarding is summarized in heartbeat counters and peak queue/RPC/total forwarding times instead of per-frame Worker logs. These counters and peaks reset when the DO is reconstructed. Failure and lifecycle records remain verbose, and wrapper archive logging is unchanged. Upload result markers on wrapper stderr distinguish HTTP rejection, network failure, timeout, and acceptance. An upload-only grant expires four hours after allocation launch and is not renewed; runtime credential revocation does not revoke it. Grant expiry does not delete archives. R2 retention remains governed by external bucket policy, not the session/report cleanup jobs. diff --git a/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts b/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts index d062781e83..f58aa647f8 100644 --- a/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts +++ b/services/cloud-agent-next/src/sandbox-control/log-routes.test.ts @@ -22,35 +22,16 @@ const batch = { }; function fixture() { - const objects = new Map(); + const objects = new Map(); const put = vi.fn(async (key: string, body: string, options: R2PutOptions) => { expect(options.onlyIf).toEqual({ etagDoesNotMatch: '*' }); if (objects.has(key)) return null; - objects.set(key, { body, sequence: options.customMetadata?.sequence ?? '' }); + objects.set(key, { body }); return { key }; }); - const get = vi.fn(async (key: string) => { - const object = objects.get(key); - return object ? { body: new Response(object.body).body } : null; - }); - const list = vi.fn(async (options: R2ListOptions) => ({ - objects: [...objects] - .filter(([key]) => key.startsWith(options.prefix ?? '')) - .map(([key, value]) => ({ - key, - size: value.body.length, - uploaded: new Date(1000), - customMetadata: { sequence: value.sequence }, - })), - truncated: false, - })); - const env = { NEXTAUTH_SECRET: secret, R2_BUCKET: { put, get, list } } as unknown as Env; + const env = { NEXTAUTH_SECRET: secret, R2_BUCKET: { put } } as unknown as Env; const app = new Hono(); - registerControlLogRoutes(app, c => - c.req.header('x-internal-api-key') === 'internal-secret' - ? null - : new Response('Unauthorized', { status: 401 }) - ); + registerControlLogRoutes(app); const request = (path: string, init?: RequestInit) => app.request(`http://worker.test${path}`, init, env); const upload = ( @@ -63,27 +44,17 @@ function fixture() { headers: { Authorization: `Bearer ${token}`, 'Content-Type': 'application/json' }, body: JSON.stringify(body), }); - return { request, upload, objects, put, get, list }; + return { request, upload, objects, put }; } describe('control log routes', () => { - it('stores validated immutable batches and retrieves them without any provider or DO binding', async () => { + it('stores validated immutable batches without any provider or DO binding', async () => { const f = fixture(); expect((await f.upload()).status).toBe(204); const key = `logs/control/${suffix}.json`; expect(JSON.parse(f.objects.get(key)!.body)).toEqual(batch); expect((await f.upload({ ...batch, sequence: 42 })).status).toBe(204); expect(JSON.parse(f.objects.get(key)!.body).sequence).toBe(0); - const response = await f.request(`/internal/sandbox-logs/${suffix}`, { - headers: { 'x-internal-api-key': 'internal-secret' }, - }); - expect(response.status).toBe(200); - expect(response.headers.get('Cache-Control')).toBe('no-store'); - expect(await response.json()).toEqual(batch); - const listing = await f.request(`/internal/sandbox-logs/${identity.sandboxId}`, { - headers: { 'x-internal-api-key': 'internal-secret' }, - }); - expect(await listing.json()).toMatchObject({ objects: [{ key, sequence: '0' }], cursor: null }); }); it('rejects cross-allocation, cross-wrapper and cross-sandbox writes', async () => { @@ -97,14 +68,10 @@ describe('control log routes', () => { expect(f.put).not.toHaveBeenCalled(); }); - it('rejects raw control credentials and unauthenticated retrieval', async () => { + it('rejects raw control credentials', async () => { const f = fixture(); expect((await f.upload(batch, suffix, 'raw-control-credential')).status).toBe(401); - expect((await f.request(`/internal/sandbox-logs/${suffix}`)).status).toBe(401); - expect((await f.request(`/internal/sandbox-logs/${identity.sandboxId}`)).status).toBe(401); expect(f.put).not.toHaveBeenCalled(); - expect(f.get).not.toHaveBeenCalled(); - expect(f.list).not.toHaveBeenCalled(); }); it.each([ @@ -180,7 +147,7 @@ describe('control log routes', () => { expect(f.put).not.toHaveBeenCalled(); }); - it('preserves earlier wrapper archives and forwards bounded pagination', async () => { + it('preserves earlier wrapper archives', async () => { const f = fixture(); await f.upload(); const nextIdentity = { ...identity, wrapperInstanceId: '2b6e33c0-20f8-4676-ad18-eedc478b161d' }; @@ -189,12 +156,6 @@ describe('control log routes', () => { (await f.upload(batch, nextPath, mintControlLogUploadGrant(nextIdentity, secret))).status ).toBe(204); expect(f.objects.size).toBe(2); - await f.request(`/internal/sandbox-logs/${identity.sandboxId}?cursor=next-page`, { - headers: { 'x-internal-api-key': 'internal-secret' }, - }); - expect(f.list).toHaveBeenCalledWith( - expect.objectContaining({ limit: 100, cursor: 'next-page' }) - ); }); it('rejects archives, malformed JSON and path injection', async () => { @@ -223,12 +184,5 @@ describe('control log routes', () => { const response = await f.upload(); expect(response.status).toBe(503); expect(await response.text()).not.toContain('private-secret'); - expect( - ( - await f.request(`/internal/sandbox-logs/${suffix}`, { - headers: { 'x-internal-api-key': 'internal-secret' }, - }) - ).status - ).toBe(404); }); }); diff --git a/services/cloud-agent-next/src/sandbox-control/log-routes.ts b/services/cloud-agent-next/src/sandbox-control/log-routes.ts index 0363fb596d..ed00b0b223 100644 --- a/services/cloud-agent-next/src/sandbox-control/log-routes.ts +++ b/services/cloud-agent-next/src/sandbox-control/log-routes.ts @@ -5,7 +5,6 @@ import { CONTROL_LOG_MAX_BATCH_BYTES, controlLogBatchSchema, controlLogIdentitySchema, - controlLogSandboxIdSchema, controlLogWrapperIdSchema, type ControlLogIdentity, } from '../shared/control-diagnostics.js'; @@ -51,10 +50,7 @@ function routeIdentity(c: Context) { }); } -export function registerControlLogRoutes( - app: Hono, - requireInternalApi: (c: Context) => Response | null -): void { +export function registerControlLogRoutes(app: Hono): void { app.put('/sandbox-logs/:sandboxId/:allocationId/:wrapperInstanceId/:batchId', async c => { const identity = routeIdentity(c); const batchId = controlLogWrapperIdSchema.safeParse(c.req.param('batchId')); @@ -105,60 +101,4 @@ export function registerControlLogRoutes( } return c.body(null, 204); }); - - app.get('/internal/sandbox-logs/:sandboxId', async c => { - const unauthorized = requireInternalApi(c); - if (unauthorized) return unauthorized; - const sandboxId = controlLogSandboxIdSchema.safeParse(c.req.param('sandboxId')); - const cursor = c.req.query('cursor'); - if (!sandboxId.success || (cursor && cursor.length > 4096)) { - return c.text('Invalid log query', 400); - } - try { - const listed = await c.env.R2_BUCKET.list({ - prefix: `logs/control/${encodeURIComponent(sandboxId.data)}/`, - limit: 100, - ...(cursor ? { cursor } : {}), - include: ['customMetadata'], - }); - c.header('Cache-Control', 'no-store'); - return c.json({ - objects: listed.objects.map(object => ({ - key: object.key, - size: object.size, - uploaded: object.uploaded.toISOString(), - sequence: object.customMetadata?.sequence, - })), - cursor: listed.truncated ? listed.cursor : null, - }); - } catch { - return c.text('Log storage unavailable', 503); - } - }); - - app.get( - '/internal/sandbox-logs/:sandboxId/:allocationId/:wrapperInstanceId/:batchId', - async c => { - const unauthorized = requireInternalApi(c); - if (unauthorized) return unauthorized; - const identity = routeIdentity(c); - const batchId = controlLogWrapperIdSchema.safeParse(c.req.param('batchId')); - if (!identity.success || !batchId.success) return c.text('Invalid log identity', 400); - try { - const object = await c.env.R2_BUCKET.get( - `${archivePrefix(identity.data)}${batchId.data}.json` - ); - if (!object) return c.text('Not found', 404); - return new Response(object.body, { - headers: { - 'Content-Type': 'application/json', - 'Cache-Control': 'no-store', - 'X-Content-Type-Options': 'nosniff', - }, - }); - } catch { - return c.text('Log storage unavailable', 503); - } - } - ); } diff --git a/services/cloud-agent-next/src/server.test.ts b/services/cloud-agent-next/src/server.test.ts index a95897f7d7..a2b6c469dc 100644 --- a/services/cloud-agent-next/src/server.test.ts +++ b/services/cloud-agent-next/src/server.test.ts @@ -1539,18 +1539,20 @@ describe('server control log routes', () => { expect(requireCurrentSessionAccessMock).not.toHaveBeenCalled(); }); - it('protects durable retrieval with the internal API secret', async () => { - const env = Object.assign(createEnv(), { - R2_BUCKET: { list: vi.fn().mockResolvedValue({ objects: [], truncated: false }) }, - }); - const url = 'http://worker.test/internal/sandbox-logs/sandbox_test'; - expect((await fetchWorker(new Request(url), env)).status).toBe(401); - expect(env.R2_BUCKET.list).not.toHaveBeenCalled(); - const response = await fetchWorker( - new Request(url, { headers: { 'x-internal-api-key': 'test-internal-secret' } }), - env - ); - expect(response.status).toBe(200); + it('does not expose log archives over HTTP', async () => { + const env = createEnv(); + for (const path of [ + '/internal/sandbox-logs/sandbox_test', + '/internal/sandbox-logs/sandbox_test/allocation_test/0fce125c-54a3-4143-b503-b7775c4d2135/5886f962-cc33-43f7-bd94-a31c0ed6c13b', + ]) { + const response = await fetchWorker( + new Request(`http://worker.test${path}`, { + headers: { 'x-internal-api-key': 'test-internal-secret' }, + }), + env + ); + expect(response.status).toBe(404); + } expect(env.SANDBOX_CONTROL.getByName).not.toHaveBeenCalled(); }); }); diff --git a/services/cloud-agent-next/src/server.ts b/services/cloud-agent-next/src/server.ts index 1bb504cd6b..fb5620859d 100644 --- a/services/cloud-agent-next/src/server.ts +++ b/services/cloud-agent-next/src/server.ts @@ -225,7 +225,7 @@ function requireInternalApi(c: Context): Response | null { return null; } -registerControlLogRoutes(app, requireInternalApi); +registerControlLogRoutes(app); app.post('/internal/sandbox-control/seed', async (c: Context) => { const unauthorized = requireInternalApi(c); From 7fca44bed46112fadf45f993eabf7d251eb46c42 Mon Sep 17 00:00:00 2001 From: Evgeny Shurakov Date: Wed, 2 Sep 2026 00:17:53 +0200 Subject: [PATCH 6/6] test(cloud-agent-next): fix Workers runner teardown hang Pin this service to vitest-pool-workers 0.18.6 for cloudflare/workers-sdk#14678, which fixes console forwarding from a broken Durable Object input gate. --- pnpm-lock.yaml | 27 ++++++++++++++++++++++++-- services/cloud-agent-next/package.json | 2 +- 2 files changed, 26 insertions(+), 3 deletions(-) diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index c1e89a7818..e085addaf0 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -2033,8 +2033,8 @@ importers: specifier: 0.3.7 version: 0.3.7 '@cloudflare/vitest-pool-workers': - specifier: 'catalog:' - version: 0.16.13(@cloudflare/workers-types@4.20260605.1)(@types/node@24.12.4)(@vitest/runner@4.1.6)(@vitest/snapshot@4.1.6)(bufferutil@4.1.0)(utf-8-validate@6.0.6)(vitest@4.1.6) + specifier: 0.18.6 + version: 0.18.6(@cloudflare/workers-types@4.20260605.1)(@types/node@24.12.4)(@vitest/runner@4.1.6)(@vitest/snapshot@4.1.6)(bufferutil@4.1.0)(utf-8-validate@6.0.6)(vitest@4.1.6) '@kilocode/sdk': specifier: 7.4.20 version: 7.4.20 @@ -4454,6 +4454,13 @@ packages: '@vitest/snapshot': ^4.1.0 vitest: ^4.1.0 + '@cloudflare/vitest-pool-workers@0.18.6': + resolution: {integrity: sha512-6JGqaQsQRZIVq/6jEC4ouJnShZriPIJ2X0yGndwMm+SiPP93pJi5Dp30dYAoztNrNJC7wWK7ec5slLfMBMZ8jA==} + peerDependencies: + '@vitest/runner': ^4.1.0 + '@vitest/snapshot': ^4.1.0 + vitest: ^4.1.0 + '@cloudflare/workerd-darwin-64@1.20260603.1': resolution: {integrity: sha512-cEXDWu6V3ZrpmwWkM4OJE9AeXjdAgOY5rh8EHhcBVCuP5rxnzUbPzLtrVOHx0UUUAcCrFq0Xsa6mZKL1VUZsKQ==} engines: {node: '>=16'} @@ -20530,6 +20537,22 @@ snapshots: - bufferutil - utf-8-validate + '@cloudflare/vitest-pool-workers@0.18.6(@cloudflare/workers-types@4.20260605.1)(@types/node@24.12.4)(@vitest/runner@4.1.6)(@vitest/snapshot@4.1.6)(bufferutil@4.1.0)(utf-8-validate@6.0.6)(vitest@4.1.6)': + dependencies: + '@vitest/runner': 4.1.6 + '@vitest/snapshot': 4.1.6 + cjs-module-lexer: 1.2.3 + esbuild: 0.28.1 + miniflare: 4.20260714.0(@types/node@24.12.4)(bufferutil@4.1.0)(utf-8-validate@6.0.6) + vitest: 4.1.6(@opentelemetry/api@1.9.1)(@types/node@24.12.4)(@vitest/coverage-v8@4.1.6)(@vitest/ui@4.1.6)(esbuild@0.28.1)(jiti@2.7.0)(jsdom@29.1.1)(terser@5.46.0)(tsx@4.21.0)(yaml@2.8.4) + wrangler: 4.112.0(@cloudflare/workers-types@4.20260605.1)(@types/node@24.12.4)(bufferutil@4.1.0)(utf-8-validate@6.0.6) + zod: 3.25.76 + transitivePeerDependencies: + - '@cloudflare/workers-types' + - '@types/node' + - bufferutil + - utf-8-validate + '@cloudflare/workerd-darwin-64@1.20260603.1': optional: true diff --git a/services/cloud-agent-next/package.json b/services/cloud-agent-next/package.json index cee5f5bf10..0e62f4ef89 100644 --- a/services/cloud-agent-next/package.json +++ b/services/cloud-agent-next/package.json @@ -51,7 +51,7 @@ }, "devDependencies": { "@cloudflare/containers": "0.3.7", - "@cloudflare/vitest-pool-workers": "catalog:", + "@cloudflare/vitest-pool-workers": "0.18.6", "@kilocode/sdk": "7.4.20", "@types/jsonwebtoken": "catalog:", "@types/node": "catalog:",