diff --git a/docs/remote-workspace-local-latency-observer-plan.md b/docs/remote-workspace-local-latency-observer-plan.md index 8949ef61c4..ef9f442397 100644 --- a/docs/remote-workspace-local-latency-observer-plan.md +++ b/docs/remote-workspace-local-latency-observer-plan.md @@ -162,14 +162,14 @@ Why it matters: Measure: -- [ ] number of full-state pushes per request +- [x] number of full-state pushes per request - [x] total full-state payload bytes per request -- [ ] number of partial-message events per request +- [x] number of partial-message events per request - [x] number of partial-message events per request - [x] total partial-message payload bytes per request - [ ] number of task UI deltas per request where supported - [x] number of task UI deltas per request where supported -- [ ] persistence flush counts where supported +- [x] persistence flush counts where supported Why it matters: @@ -213,10 +213,10 @@ These should work on both `main` and `eve_troubleshooting-remote-workspaces` wit These may only exist natively on `eve_troubleshooting-remote-workspaces` or may require additional light plumbing on `main`: - [ ] chunk-to-webview timing -- [ ] full-state post counts / bytes -- [ ] partial-message event counts -- [ ] task UI delta counts -- [ ] persistence flush metrics +- [x] full-state post counts / bytes +- [x] partial-message event counts +- [x] task UI delta counts +- [x] persistence flush metrics ### Recommended implementation rule diff --git a/src/services/latency/LatencyObserverService.ts b/src/services/latency/LatencyObserverService.ts index bf072ad8c8..4eb55651c8 100644 --- a/src/services/latency/LatencyObserverService.ts +++ b/src/services/latency/LatencyObserverService.ts @@ -3,16 +3,27 @@ import { DEFAULT_LATENCY_OBSERVER_CAPABILITIES, type LatencyObserverCapabilities, type LatencyObserverLogEntry, + type LatencyObserverRequestCounterSummary, type LatencyObserverSessionMetadata, type LatencyObserverStateSnapshot, type LatencySample, } from "@/shared/LatencyObserver" type ActiveRequest = { + taskId: string requestId: string startedAt: number firstVisibleRecorded: boolean firstFullStateRecorded: boolean + counterBaseline: Record< + | "fullStatePushes" + | "fullStateBytes" + | "partialMessageEvents" + | "partialMessageBytes" + | "taskUiDeltaEvents" + | "persistenceFlushes", + number + > } export class LatencyObserverService { @@ -34,6 +45,7 @@ export class LatencyObserverService { private readonly requestStartSamples: LatencySample[] = [] private readonly firstVisibleUpdateSamples: LatencySample[] = [] private readonly firstFullStateUpdateSamples: LatencySample[] = [] + private readonly requestCounterSummaries: LatencyObserverRequestCounterSummary[] = [] private readonly logs: LatencyObserverLogEntry[] = [] private optionalCounters: Record< | "fullStatePushes" @@ -87,10 +99,12 @@ export class LatencyObserverService { markRequestStart(taskId: string, requestId: string, startedAt = performance.now()): void { this.activeRequests.set(taskId, { + taskId, requestId, startedAt, firstVisibleRecorded: false, firstFullStateRecorded: false, + counterBaseline: { ...this.optionalCounters }, }) this.requestStartSamples.push({ startedAt, @@ -141,6 +155,22 @@ export class LatencyObserverService { return } + this.requestCounterSummaries.push({ + requestId: activeRequest.requestId, + taskId: activeRequest.taskId, + startedAt: activeRequest.startedAt, + completedAt: performance.now(), + fullStatePushes: this.optionalCounters.fullStatePushes - activeRequest.counterBaseline.fullStatePushes, + fullStateBytes: this.optionalCounters.fullStateBytes - activeRequest.counterBaseline.fullStateBytes, + partialMessageEvents: this.optionalCounters.partialMessageEvents - activeRequest.counterBaseline.partialMessageEvents, + partialMessageBytes: this.optionalCounters.partialMessageBytes - activeRequest.counterBaseline.partialMessageBytes, + taskUiDeltaEvents: this.optionalCounters.taskUiDeltaEvents - activeRequest.counterBaseline.taskUiDeltaEvents, + persistenceFlushes: this.optionalCounters.persistenceFlushes - activeRequest.counterBaseline.persistenceFlushes, + }) + if (this.requestCounterSummaries.length > 50) { + this.requestCounterSummaries.shift() + } + this.activeRequests.delete(taskId) this.pushLog(`request completed`, taskId, activeRequest.requestId) } @@ -182,6 +212,7 @@ export class LatencyObserverService { samples: [...this.firstFullStateUpdateSamples], stats: createRollingLatencyStats(this.firstFullStateUpdateSamples), }, + requestCounterSummaries: [...this.requestCounterSummaries], logs: [...this.logs], optionalCounters: { ...this.optionalCounters }, } @@ -205,6 +236,7 @@ export class LatencyObserverService { this.requestStartSamples.length = 0 this.firstVisibleUpdateSamples.length = 0 this.firstFullStateUpdateSamples.length = 0 + this.requestCounterSummaries.length = 0 this.logs.length = 0 this.optionalCounters = { fullStatePushes: 0, diff --git a/src/services/latency/__tests__/LatencyObserverService.test.ts b/src/services/latency/__tests__/LatencyObserverService.test.ts index d7bd049583..a103625720 100644 --- a/src/services/latency/__tests__/LatencyObserverService.test.ts +++ b/src/services/latency/__tests__/LatencyObserverService.test.ts @@ -64,6 +64,34 @@ describe("LatencyObserverService", () => { assert.equal(snapshot.optionalCounters?.partialMessageBytes, 128) }) + it("captures per-request richer counter summaries on completion", () => { + const service = new LatencyObserverService() + + service.markRequestStart("task-4", "task-4:req-1", 50) + service.incrementCounter("fullStatePushes", 2) + service.incrementCounter("fullStateBytes", 300) + service.incrementCounter("partialMessageEvents", 3) + service.incrementCounter("partialMessageBytes", 120) + service.incrementCounter("taskUiDeltaEvents", 4) + service.incrementCounter("persistenceFlushes", 1) + service.completeRequest("task-4") + + const snapshot = service.getSnapshot() + assert.equal(snapshot.requestCounterSummaries.length, 1) + assert.deepEqual(snapshot.requestCounterSummaries[0], { + requestId: "task-4:req-1", + taskId: "task-4", + startedAt: 50, + completedAt: snapshot.requestCounterSummaries[0].completedAt, + fullStatePushes: 2, + fullStateBytes: 300, + partialMessageEvents: 3, + partialMessageBytes: 120, + taskUiDeltaEvents: 4, + persistenceFlushes: 1, + }) + }) + it("uses capability support values in metric snapshots", () => { const service = new LatencyObserverService() @@ -102,6 +130,7 @@ describe("LatencyObserverService", () => { assert.equal(snapshot.requestStart.stats.count, 0) assert.equal(snapshot.firstVisibleUpdate.stats.count, 0) assert.equal(snapshot.firstFullStateUpdate.stats.count, 0) + assert.equal(snapshot.requestCounterSummaries.length, 0) assert.equal(snapshot.logs.length, 0) assert.equal(snapshot.optionalCounters?.fullStatePushes, 0) }) diff --git a/src/shared/LatencyObserver.ts b/src/shared/LatencyObserver.ts index a489c3d766..1ef333adb0 100644 --- a/src/shared/LatencyObserver.ts +++ b/src/shared/LatencyObserver.ts @@ -67,6 +67,19 @@ export interface LatencyObserverMetricSnapshot { stats: RollingLatencyStats } +export interface LatencyObserverRequestCounterSummary { + requestId: string + taskId?: string + startedAt: number + completedAt: number + fullStatePushes: number + fullStateBytes: number + partialMessageEvents: number + partialMessageBytes: number + taskUiDeltaEvents: number + persistenceFlushes: number +} + export interface LatencyObserverLogEntry { ts: number message: string @@ -82,6 +95,7 @@ export interface LatencyObserverStateSnapshot { requestStart: LatencyObserverMetricSnapshot firstVisibleUpdate: LatencyObserverMetricSnapshot firstFullStateUpdate: LatencyObserverMetricSnapshot + requestCounterSummaries: LatencyObserverRequestCounterSummary[] logs: LatencyObserverLogEntry[] optionalCounters?: LatencyObserverMetricSet["optionalCounters"] } diff --git a/webview-ui/src/components/settings/sections/DebugSection.spec.tsx b/webview-ui/src/components/settings/sections/DebugSection.spec.tsx index 47d53a34e0..0f203f87c3 100644 --- a/webview-ui/src/components/settings/sections/DebugSection.spec.tsx +++ b/webview-ui/src/components/settings/sections/DebugSection.spec.tsx @@ -38,6 +38,18 @@ type MockLatencyObserverState = { firstVisibleUpdate: MockLatencyObserverState["transport"] firstFullStateUpdate: MockLatencyObserverState["transport"] logs: unknown[] + requestCounterSummaries: Array<{ + requestId: string + taskId?: string + startedAt: number + completedAt: number + fullStatePushes: number + fullStateBytes: number + partialMessageEvents: number + partialMessageBytes: number + taskUiDeltaEvents: number + persistenceFlushes: number + }> optionalCounters?: { fullStatePushes: number fullStateBytes: number @@ -88,6 +100,20 @@ const extensionStateMock = vi.hoisted(() => ({ stats: { count: 1, minMs: 14, maxMs: 14, avgMs: 14, lastMs: 14, totalMs: 14 }, }, logs: [], + requestCounterSummaries: [ + { + requestId: "task-1:req-1", + taskId: "task-1", + startedAt: 10, + completedAt: 24, + fullStatePushes: 2, + fullStateBytes: 512, + partialMessageEvents: 3, + partialMessageBytes: 256, + taskUiDeltaEvents: 4, + persistenceFlushes: 1, + }, + ], optionalCounters: { fullStatePushes: 3, fullStateBytes: 1024, @@ -156,6 +182,20 @@ describe("DebugSection", () => { stats: { count: 1, minMs: 14, maxMs: 14, avgMs: 14, lastMs: 14, totalMs: 14 }, }, logs: [], + requestCounterSummaries: [ + { + requestId: "task-1:req-1", + taskId: "task-1", + startedAt: 10, + completedAt: 24, + fullStatePushes: 2, + fullStateBytes: 512, + partialMessageEvents: 3, + partialMessageBytes: 256, + taskUiDeltaEvents: 4, + persistenceFlushes: 1, + }, + ], optionalCounters: { fullStatePushes: 3, fullStateBytes: 1024, @@ -201,6 +241,8 @@ describe("DebugSection", () => { expect(screen.getByText(/State pushes: 3/)).toBeTruthy() expect(screen.getByText(/State bytes: 1024/)).toBeTruthy() expect(screen.getByText(/Partial bytes: 256/)).toBeTruthy() + expect(screen.getByText(/Req state pushes: 2/)).toBeTruthy() + expect(screen.getByText(/Req partial bytes: 256/)).toBeTruthy() expect(screen.getByText(/Transport probe: Supported/)).toBeTruthy() expect(screen.getByText(/First full-state avg: 14.00 ms/)).toBeTruthy() expect(screen.getByText(/Task UI delta metrics: Unsupported on this branch/)).toBeTruthy() diff --git a/webview-ui/src/components/settings/sections/DebugSection.tsx b/webview-ui/src/components/settings/sections/DebugSection.tsx index a75d7fbdc7..00ad0f93bd 100644 --- a/webview-ui/src/components/settings/sections/DebugSection.tsx +++ b/webview-ui/src/components/settings/sections/DebugSection.tsx @@ -60,6 +60,7 @@ const DebugSection = ({ onResetState, renderSectionHeader }: DebugSectionProps) OBSERVATION_SCENARIOS.find((scenario) => scenario.id === selectedScenarioId) ?? OBSERVATION_SCENARIOS[0] const transportSamples = latencyObserver?.transport.samples ?? [] + const latestRequestSummary = latencyObserver?.requestCounterSummaries.at(-1) const effectiveTransportSamples = useMemo(() => { if (transportSamples.length > 0) { return transportSamples @@ -307,6 +308,17 @@ const DebugSection = ({ onResetState, renderSectionHeader }: DebugSectionProps)