Merge pull request #2195 from pikasTech/fix/2194-workbench-terminal-timing
fix: keep terminal Workbench timing monotonic
This commit is contained in:
@@ -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<ChatMessage["runnerTrace"]>;
|
||||
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<ChatMessage["runnerTrace"]>;
|
||||
|
||||
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",
|
||||
|
||||
@@ -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, {
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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;
|
||||
|
||||
@@ -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<ChatMessage> = {
|
||||
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<ChatMessage["timing"]> = {
|
||||
...(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;
|
||||
|
||||
@@ -1705,7 +1705,8 @@ function normalizeChatMessage(message: ChatMessage): ChatMessage {
|
||||
: ""
|
||||
: firstNonEmptyString(baseText, finalText, errorText) ?? "";
|
||||
const messageId = firstNonEmptyString((message as Record<string, unknown>).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, TurnStatusAuthority>): string | null {
|
||||
@@ -1860,12 +1861,27 @@ function normalizeTimingProjection(value: unknown): WorkbenchTurnTimingProjectio
|
||||
function messageTimingPatch(value: unknown): Partial<ChatMessage> {
|
||||
const timing = normalizeTimingProjection(value);
|
||||
if (!timing) return {};
|
||||
return messageTimingPatchFromProjection(timing);
|
||||
}
|
||||
|
||||
function messageTimingPatchFromProjection(timing: WorkbenchTurnTimingProjection): Partial<ChatMessage> {
|
||||
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<ChatMessage> {
|
||||
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<ChatMessage> {
|
||||
@@ -1874,10 +1890,51 @@ function messageTerminalSealPatchForProjectionMerge(message: ChatMessage, previo
|
||||
const patch: Partial<ChatMessage> = { 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<ChatMessage> {
|
||||
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<ChatMessage> {
|
||||
if (!terminal || isTerminalMessageStatus(message.status)) return {};
|
||||
if (resultStatus && isTerminalMessageStatus(resultStatus)) return { status: resultStatus as ChatMessage["status"] };
|
||||
|
||||
Reference in New Issue
Block a user