From 496895cae52d3c596fa9f22a8c1626da386675a2 Mon Sep 17 00:00:00 2001 From: lyon Date: Fri, 26 Jun 2026 16:13:12 +0800 Subject: [PATCH] fix: keep terminal workbench timing monotonic --- .../scripts/workbench-r1-parity.test.ts | 22 +++++++ .../scripts/workbench-server-state.test.ts | 45 +++++++++++++ .../workbench/ConversationPanel.vue | 4 +- .../src/composables/useTraceSubscription.ts | 12 +++- .../src/stores/workbench-server-state.ts | 59 ++++++++++++++++- web/hwlab-cloud-web/src/stores/workbench.ts | 65 +++++++++++++++++-- 6 files changed, 200 insertions(+), 7 deletions(-) diff --git a/web/hwlab-cloud-web/scripts/workbench-r1-parity.test.ts b/web/hwlab-cloud-web/scripts/workbench-r1-parity.test.ts index 45fece7c..9c4aea3f 100644 --- a/web/hwlab-cloud-web/scripts/workbench-r1-parity.test.ts +++ b/web/hwlab-cloud-web/scripts/workbench-r1-parity.test.ts @@ -142,6 +142,28 @@ test("R1 trace API snapshots stay authoritative over compact result traces", () assert.equal(merged.events?.[1]?.message, "OK"); }); +test("R1 trace timing merge does not decrease visible duration", () => { + const previous = { + traceId: "trc_timing_merge", + status: "running", + timing: { startedAt: "2026-06-24T00:00:00.000Z", durationMs: 21_000 }, + durationMs: 21_000, + events: [] + } as NonNullable; + const next = { + traceId: "trc_timing_merge", + status: "completed", + timing: { startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:01.000Z", durationMs: 1_000 }, + durationMs: 1_000, + events: [] + } as NonNullable; + + const merged = mergeRunnerTrace(previous, next); + assert.equal(merged.status, "completed"); + assert.equal(merged.durationMs, 21_000); + assert.equal(merged.timing?.durationMs, 21_000); +}); + test("R1 status summary keeps the restored 23-row floor", () => { const message = agentMessage({ status: "failed", diff --git a/web/hwlab-cloud-web/scripts/workbench-server-state.test.ts b/web/hwlab-cloud-web/scripts/workbench-server-state.test.ts index 79d80870..90093a39 100644 --- a/web/hwlab-cloud-web/scripts/workbench-server-state.test.ts +++ b/web/hwlab-cloud-web/scripts/workbench-server-state.test.ts @@ -157,6 +157,51 @@ test("Workbench session messages keep sealed terminal timing on bulk refresh", ( assert.equal(agent?.finishedAt, "2026-06-24T00:00:12.000Z"); }); +test("Workbench session messages repair terminal zero timing from running projection", () => { + let state = createWorkbenchServerState(); + state = reduceWorkbenchServerState(state, { + type: "session.messages", + sessionId: "ses_terminal_zero_repair", + messages: [ + { id: "msg_agent", messageId: "msg_agent", role: "agent", title: "Code Agent", text: "", status: "running", createdAt: "2026-06-24T00:00:00.000Z", sessionId: "ses_terminal_zero_repair", traceId: "trc_terminal_zero_repair", timing: { startedAt: "2026-06-24T00:00:00.000Z", lastEventAt: "2026-06-24T00:00:05.000Z", durationMs: null, valuesRedacted: true }, startedAt: "2026-06-24T00:00:00.000Z", lastEventAt: "2026-06-24T00:00:05.000Z", durationMs: null } + ] + }); + + state = reduceWorkbenchServerState(state, { + type: "message.snapshot", + sessionId: "ses_terminal_zero_repair", + message: { id: "msg_agent", messageId: "msg_agent", role: "agent", title: "Code Agent", text: "OK", status: "completed", createdAt: "2026-06-24T00:00:00.000Z", updatedAt: "2026-06-24T00:00:06.000Z", sessionId: "ses_terminal_zero_repair", traceId: "trc_terminal_zero_repair", timing: { startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:00.000Z", durationMs: 0, valuesRedacted: true }, startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:00.000Z", durationMs: 0 } + }); + + const agent = selectActiveMessages(state, "ses_terminal_zero_repair").find((message) => message.role === "agent"); + assert.equal(agent?.status, "completed"); + assert.equal(agent?.durationMs, 6_000); + assert.equal(agent?.timing?.durationMs, 6_000); +}); + +test("Workbench session messages can replace sealed terminal zero with positive timing", () => { + let state = createWorkbenchServerState(); + state = reduceWorkbenchServerState(state, { + type: "session.messages", + sessionId: "ses_terminal_zero_positive", + messages: [ + { id: "msg_agent", messageId: "msg_agent", role: "agent", title: "Code Agent", text: "OK", status: "completed", createdAt: "2026-06-24T00:00:00.000Z", sessionId: "ses_terminal_zero_positive", traceId: "trc_terminal_zero_positive", timing: { startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:00.000Z", durationMs: 0, valuesRedacted: true }, startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:00.000Z", durationMs: 0 } + ] + }); + + state = reduceWorkbenchServerState(state, { + type: "session.messages", + sessionId: "ses_terminal_zero_positive", + messages: [ + { id: "msg_agent", messageId: "msg_agent", role: "agent", title: "Code Agent", text: "OK", status: "completed", createdAt: "2026-06-24T00:00:00.000Z", sessionId: "ses_terminal_zero_positive", traceId: "trc_terminal_zero_positive", timing: { startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:06.000Z", durationMs: 6_000, valuesRedacted: true }, startedAt: "2026-06-24T00:00:00.000Z", finishedAt: "2026-06-24T00:00:06.000Z", durationMs: 6_000 } + ] + }); + + const agent = selectActiveMessages(state, "ses_terminal_zero_positive").find((message) => message.role === "agent"); + assert.equal(agent?.durationMs, 6_000); + assert.equal(agent?.timing?.durationMs, 6_000); +}); + test("Workbench server-state keeps running card startedAt stable across early snapshots", () => { let state = createWorkbenchServerState(); state = reduceWorkbenchServerState(state, { diff --git a/web/hwlab-cloud-web/src/components/workbench/ConversationPanel.vue b/web/hwlab-cloud-web/src/components/workbench/ConversationPanel.vue index 19e46963..f78934d4 100644 --- a/web/hwlab-cloud-web/src/components/workbench/ConversationPanel.vue +++ b/web/hwlab-cloud-web/src/components/workbench/ConversationPanel.vue @@ -267,7 +267,9 @@ function messageTimingForDisplay(message: ChatMessage): ChatMessage["timing"] { } function terminalMessageDurationMs(timing: ChatMessage["timing"]): number | null { - return finiteDurationMs(timing?.durationMs); + const durationMs = finiteDurationMs(timing?.durationMs); + if (durationMs === 0 && timing?.finishedAt) return 1000; + return durationMs; } function durationSince(timestamp: unknown): number | null { diff --git a/web/hwlab-cloud-web/src/composables/useTraceSubscription.ts b/web/hwlab-cloud-web/src/composables/useTraceSubscription.ts index 90af4616..83f101c6 100644 --- a/web/hwlab-cloud-web/src/composables/useTraceSubscription.ts +++ b/web/hwlab-cloud-web/src/composables/useTraceSubscription.ts @@ -145,7 +145,7 @@ function mergeTraceTimingProjection(previous: unknown, next: unknown): TraceSnap startedAt: nextTiming.startedAt ?? previousTiming.startedAt ?? null, lastEventAt: nextTiming.lastEventAt ?? previousTiming.lastEventAt ?? null, finishedAt: nextTiming.finishedAt ?? previousTiming.finishedAt ?? null, - durationMs: firstTraceDuration(nextTiming.durationMs, previousTiming.durationMs), + durationMs: mergeTraceDuration(previousTiming.durationMs, nextTiming.durationMs), observedAt: nextTiming.observedAt ?? previousTiming.observedAt ?? null, lastEventAgeMs: null, valuesRedacted: previousTiming.valuesRedacted !== false && nextTiming.valuesRedacted !== false @@ -188,6 +188,16 @@ function firstTraceDuration(...values: unknown[]): number | null { return null; } +function mergeTraceDuration(previous: unknown, next: unknown): number | null { + const previousDuration = finiteTraceDuration(previous); + const nextDuration = finiteTraceDuration(next); + if (previousDuration === null) return nextDuration; + if (nextDuration === null) return previousDuration; + if (previousDuration === 0) return nextDuration; + if (nextDuration === 0) return previousDuration; + return Math.max(previousDuration, nextDuration); +} + function finiteTraceDuration(value: unknown): number | null { const number = Number(value); return Number.isFinite(number) && number >= 0 ? Math.trunc(number) : null; diff --git a/web/hwlab-cloud-web/src/stores/workbench-server-state.ts b/web/hwlab-cloud-web/src/stores/workbench-server-state.ts index 5e77a4ad..fff3df7e 100644 --- a/web/hwlab-cloud-web/src/stores/workbench-server-state.ts +++ b/web/hwlab-cloud-web/src/stores/workbench-server-state.ts @@ -184,6 +184,7 @@ function mergeMessageList(existing: ChatMessage[], incoming: ChatMessage[]): Cha } function sealExistingMessageTiming(existing: ChatMessage, incoming: ChatMessage): ChatMessage { + if (!isTerminalMessageStatus(existing.status) && isTerminalMessageStatus(incoming.status)) return sealTerminalTransitionMessageTiming(existing, incoming); if (isTerminalMessageStatus(existing.status)) return sealExistingTerminalMessageTiming(existing, incoming); return sealExistingRunningMessageTiming(existing, incoming); } @@ -206,7 +207,7 @@ function sealExistingRunningMessageTiming(existing: ChatMessage, incoming: ChatM function sealExistingTerminalMessageTiming(existing: ChatMessage, incoming: ChatMessage): ChatMessage { if (!isTerminalMessageStatus(existing.status)) return incoming; - const timing = terminalTimingProjection(existing); + const timing = sealedTerminalTimingProjection(existing, incoming); if (!timing || timing.durationMs == null) return incoming; const patch: Partial = { status: existing.status, @@ -221,6 +222,35 @@ function sealExistingTerminalMessageTiming(existing: ChatMessage, incoming: Chat return { ...incoming, ...patch }; } +function sealTerminalTransitionMessageTiming(existing: ChatMessage, incoming: ChatMessage): ChatMessage { + const incomingTiming = terminalTimingProjection(incoming); + if (positiveDuration(incomingTiming?.durationMs) !== null) return incoming; + const existingTiming = messageTimingProjection(existing); + const startedAt = existingTiming?.startedAt ?? incomingTiming?.startedAt ?? timestampOrNull(existing.createdAt) ?? null; + const finishedAt = terminalFinishedAt(startedAt, incomingTiming?.finishedAt, timestampOrNull(incoming.updatedAt), incomingTiming?.lastEventAt) ?? incomingTiming?.finishedAt ?? null; + const durationMs = positiveDuration(durationBetween(startedAt, finishedAt)) ?? positiveDuration(durationBetween(startedAt, new Date().toISOString())) ?? positiveDuration(incomingTiming?.durationMs) ?? (incomingTiming?.durationMs === 0 ? 1000 : null); + if (durationMs === null) return incoming; + const timing: NonNullable = { + ...(incomingTiming ?? {}), + startedAt, + lastEventAt: incomingTiming?.lastEventAt ?? finishedAt ?? startedAt, + finishedAt: finishedAt ?? incomingTiming?.finishedAt ?? null, + durationMs, + valuesRedacted: incomingTiming?.valuesRedacted !== false && existingTiming?.valuesRedacted !== false, + }; + return { ...incoming, timing, startedAt: timing.startedAt ?? null, lastEventAt: timing.lastEventAt ?? null, finishedAt: timing.finishedAt ?? null, durationMs: timing.durationMs ?? null }; +} + +function sealedTerminalTimingProjection(existing: ChatMessage, incoming: ChatMessage): ChatMessage["timing"] | null { + const existingTiming = terminalTimingProjection(existing); + const incomingTiming = terminalTimingProjection(incoming); + const existingDuration = positiveDuration(existingTiming?.durationMs); + if (existingTiming && existingDuration !== null) return existingTiming; + const incomingDuration = positiveDuration(incomingTiming?.durationMs) ?? positiveDuration(durationBetween(incomingTiming?.startedAt, terminalFinishedAt(incomingTiming?.startedAt, incomingTiming?.finishedAt, incomingTiming?.lastEventAt))); + if (incomingTiming && incomingDuration !== null) return { ...(existingTiming ?? {}), ...incomingTiming, durationMs: incomingDuration, valuesRedacted: incomingTiming.valuesRedacted !== false && existingTiming?.valuesRedacted !== false }; + return existingTiming ?? incomingTiming; +} + function terminalTimingProjection(message: ChatMessage): ChatMessage["timing"] | null { return messageTimingProjection(message); } @@ -262,6 +292,33 @@ function nonNegativeDuration(value: unknown): number | null { return Number.isFinite(number) && number >= 0 ? Math.trunc(number) : null; } +function positiveDuration(value: unknown): number | null { + const duration = nonNegativeDuration(value); + return duration !== null && duration > 0 ? duration : null; +} + +function durationBetween(startedAt: unknown, finishedAt: unknown): number | null { + const startedMs = timestampMs(startedAt); + const finishedMs = timestampMs(finishedAt); + if (startedMs === null || finishedMs === null || finishedMs <= startedMs) return null; + return Math.trunc(finishedMs - startedMs); +} + +function terminalFinishedAt(startedAt: unknown, ...values: unknown[]): string | null { + for (const value of values) { + const timestamp = timestampOrNull(value); + if (durationBetween(startedAt, timestamp) !== null) return timestamp; + } + return null; +} + +function timestampMs(value: unknown): number | null { + const timestamp = timestampOrNull(value); + if (!timestamp) return null; + const parsed = Date.parse(timestamp); + return Number.isFinite(parsed) ? parsed : null; +} + function mergeSessionRecord(existing: WorkbenchSessionRecord | undefined, incoming: WorkbenchSessionRecord): WorkbenchSessionRecord { if (!existing) return incoming; const incomingMessages = Array.isArray(incoming.messages) ? incoming.messages : undefined; diff --git a/web/hwlab-cloud-web/src/stores/workbench.ts b/web/hwlab-cloud-web/src/stores/workbench.ts index 551fbfa7..2390e2d9 100644 --- a/web/hwlab-cloud-web/src/stores/workbench.ts +++ b/web/hwlab-cloud-web/src/stores/workbench.ts @@ -1705,7 +1705,8 @@ function normalizeChatMessage(message: ChatMessage): ChatMessage { : "" : firstNonEmptyString(baseText, finalText, errorText) ?? ""; const messageId = firstNonEmptyString((message as Record).messageId, message.id) ?? nextProtocolId("msg"); - return { ...message, ...messageTimingPatch(message), role, text, id: messageId, messageId, title: normalizeWorkbenchMessageTitle(role, message.title), createdAt: message.createdAt ?? new Date().toISOString(), status, runnerTrace, error: error ?? message.error ?? null, projection, projectionStatus: projection?.projectionStatus ?? null, projectionHealth: projection?.projectionHealth ?? null, blocker: projection?.blocker ?? null, agentRun: agentRun ?? undefined }; + const timingPatch = isTerminalMessageStatus(status) ? terminalMessageTimingPatchForNormalize(message) : messageTimingPatch(message); + return { ...message, ...timingPatch, role, text, id: messageId, messageId, title: normalizeWorkbenchMessageTitle(role, message.title), createdAt: message.createdAt ?? new Date().toISOString(), status, runnerTrace, error: error ?? message.error ?? null, projection, projectionStatus: projection?.projectionStatus ?? null, projectionHealth: projection?.projectionHealth ?? null, blocker: projection?.blocker ?? null, agentRun: agentRun ?? undefined }; } function activeTraceIdFromMessages(messages: ChatMessage[], turnStatusAuthority: Record): string | null { @@ -1860,12 +1861,27 @@ function normalizeTimingProjection(value: unknown): WorkbenchTurnTimingProjectio function messageTimingPatch(value: unknown): Partial { const timing = normalizeTimingProjection(value); if (!timing) return {}; + return messageTimingPatchFromProjection(timing); +} + +function messageTimingPatchFromProjection(timing: WorkbenchTurnTimingProjection): Partial { return { timing, startedAt: timing.startedAt ?? null, lastEventAt: timing.lastEventAt ?? null, finishedAt: timing.finishedAt ?? null, durationMs: timing.durationMs ?? null }; } function messageTimingPatchForMerge(message: ChatMessage, value: unknown): Partial { - void value; - return messageTimingPatch(message); + const incomingTiming = normalizeTimingProjection(value); + if (!incomingTiming || !isTerminalTimingSource(value)) return messageTimingPatch(message); + const existingTiming = normalizeTimingProjection(message); + const existingDuration = firstPositiveFiniteNumber(existingTiming?.durationMs); + if (isTerminalMessageStatus(message.status) && existingTiming && existingDuration !== null) return messageTimingPatchFromProjection(existingTiming); + const incomingDuration = firstPositiveFiniteNumber(incomingTiming.durationMs) ?? positiveDurationBetween(incomingTiming.startedAt, incomingTiming.finishedAt) ?? positiveDurationBetween(incomingTiming.startedAt, incomingTiming.lastEventAt); + if (incomingDuration !== null) return messageTimingPatchFromProjection({ ...(existingTiming ?? {}), ...incomingTiming, durationMs: incomingDuration, valuesRedacted: incomingTiming.valuesRedacted !== false && existingTiming?.valuesRedacted !== false }); + const runningDuration = isTerminalMessageStatus(message.status) ? null : runningDurationFromTiming(existingTiming); + if (runningDuration !== null) { + const finishedAt = incomingTiming.finishedAt ?? incomingTiming.lastEventAt ?? new Date().toISOString(); + return messageTimingPatchFromProjection({ ...(incomingTiming ?? {}), startedAt: existingTiming?.startedAt ?? incomingTiming.startedAt ?? null, lastEventAt: incomingTiming.lastEventAt ?? finishedAt, finishedAt, durationMs: runningDuration, valuesRedacted: incomingTiming.valuesRedacted !== false && existingTiming?.valuesRedacted !== false }); + } + return terminalMessageTimingPatchForNormalize(value); } function messageTerminalSealPatchForProjectionMerge(message: ChatMessage, previous: ChatMessage | null): Partial { @@ -1874,10 +1890,51 @@ function messageTerminalSealPatchForProjectionMerge(message: ChatMessage, previo const patch: Partial = { status: previous.status, traceAutoLifecycle: previous.traceAutoLifecycle ?? "terminal" }; if (typeof previous.text === "string" && previous.text.trim()) patch.text = previous.text; const previousTiming = normalizeTimingProjection(previous); - if (previousTiming?.durationMs == null) return { ...incomingTimingPatch, ...patch }; + if (firstPositiveFiniteNumber(previousTiming?.durationMs) === null) return { ...terminalMessageTimingPatchForNormalize(message), ...patch }; return { ...messageTimingPatch(previous), ...patch }; } +function terminalMessageTimingPatchForNormalize(value: unknown): Partial { + const timing = normalizeTimingProjection(value); + if (!timing) return {}; + const record = recordValue(value); + const durationMs = firstPositiveFiniteNumber(timing.durationMs) + ?? positiveDurationBetween(timing.startedAt, timing.finishedAt) + ?? positiveDurationBetween(timing.startedAt, timing.lastEventAt) + ?? positiveDurationBetween(timing.startedAt, record?.updatedAt) + ?? (timing.durationMs === 0 ? 1000 : null); + return messageTimingPatchFromProjection({ ...timing, durationMs }); +} + +function isTerminalTimingSource(value: unknown): boolean { + const record = recordValue(value); + if (!record) return false; + const runnerTrace = recordValue(record.runnerTrace); + return record.terminal === true || isTerminalMessageStatus(record.status) || isTerminalMessageStatus(record.traceStatus) || isTerminalMessageStatus(runnerTrace?.status) || isTerminalMessageStatus(runnerTrace?.traceStatus) || normalizeTimingProjection(value)?.finishedAt != null; +} + +function runningDurationFromTiming(timing: WorkbenchTurnTimingProjection | null): number | null { + const startedMs = timestampMs(timing?.startedAt); + if (startedMs === null) return null; + const duration = Math.trunc(Date.now() - startedMs); + return duration > 0 ? Math.max(1000, duration) : 1000; +} + +function positiveDurationBetween(startedAt: unknown, finishedAt: unknown): number | null { + const startedMs = timestampMs(startedAt); + const finishedMs = timestampMs(finishedAt); + if (startedMs === null || finishedMs === null || finishedMs <= startedMs) return null; + return Math.trunc(finishedMs - startedMs); +} + +function timestampMs(value: unknown): number | null { + if (typeof value !== "string") return null; + const text = value.trim(); + if (!text) return null; + const parsed = Date.parse(text); + return Number.isFinite(parsed) ? parsed : null; +} + function messageStatusPatchForTerminalMerge(message: ChatMessage, resultStatus: string | null, terminal: boolean): Partial { if (!terminal || isTerminalMessageStatus(message.status)) return {}; if (resultStatus && isTerminalMessageStatus(resultStatus)) return { status: resultStatus as ChatMessage["status"] };