Commit 89699f6
fix(tracing): trace waterfall + summary prompt + chat tab all lose data after each agent turn (#895)
* fix(tracing): waterfall view collapses to system-prompt span on agent-finish
Symptom: opening `/traces` mid-session and watching the waterfall view
during agent execution shows the rich trace populating correctly, but
the moment the agent finishes its turn the view collapses to a single
"system-prompt" span — and the data is genuinely lost on disk, not
just from the viewer.
Chain (verified by reading worker.ts + routes/session/index.tsx + tracing.ts):
1. `routes/session/index.tsx` has
`createEffect(() => session()?.workspaceID && sdk.setWorkspace(...))`.
SolidJS dirty-tracks any signal read inside the effect — so it
re-runs on EVERY `session()` change (message count, status, parts
updates), including the cascade at agent-finish.
2. Each fire calls `worker.setWorkspace` via RPC.
3. `worker.setWorkspace` unconditionally calls `startEventStream`.
4. `startEventStream`:
for (const [, trace] of sessionTraces) {
void trace.endTrace().catch(() => {}) // fire-and-forget
}
sessionTraces.clear()
5. On the next event for the same session, `getOrCreateTrace` hits a
cache miss, calls `Trace.create()` + `startTrace(sessionID, {})`,
which pushes a single root span into a freshly-empty `this.spans`
and calls `this.snapshot()`. The snapshot path is derived purely
from sessionID (`tracing.ts:836`), so it overwrites the rich
`ses_<id>.json` with a 1-span file.
Distinct from #867 — that PR fixed intra-Trace-instance concurrency
(snapshot debounce M2; FileExporter ↔ flushSync race M3). This bug is
at the worker-level cache lifecycle: a new Trace instance gets
constructed and its near-empty initial state clobbers the previous
instance's rich state on disk.
Two minimal fixes lock the contract:
* `worker.ts` — make `setWorkspace` idempotent. Track
`currentWorkspaceID` at module scope; early-return when the incoming
value matches. Spurious calls from the UI no longer destroy traces.
* `routes/session/index.tsx` — switch the workspaceID effect to
`createEffect(on(() => session()?.workspaceID, ...))`. The `on()`
projector restricts SolidJS dirty-tracking to that one field, so the
effect only fires when workspaceID actually changes — defense in
depth at the upstream trigger.
Regression test in `test/cli/tui/worker-trace-clearing.test.ts`
locks both contracts via source-grep (the worker-import side has
top-level side effects that make in-process unit testing awkward).
Out of scope (follow-up): `getOrCreateTrace` on cache miss does not
rehydrate `this.spans` from the existing `ses_<id>.json` file. After
the two fixes above, this matters only on worker restart or
MAX_TRACES=100 eviction — both uncommon. Worth tracking as defense in
depth so the disk file is always authoritative.
Typecheck clean. 152 TUI tests pass; 35 existing tracing tests pass
unchanged.
* fix(tracing): real root cause — session.status=idle was destroying the Trace every turn
Previous commit on this branch was correct but not load-bearing. The
actual hot path that collapsed the on-disk trace after every agent
turn is in `worker.ts`:
if (event.type === "session.status") {
if (status === "idle" && sid) {
const trace = sessionTraces.get(sid)
if (trace) {
void trace.endTrace().catch(() => {})
sessionTraces.delete(sid) // ← every turn
sessionUserMsgIds.delete(sid)
}
}
}
`session.status === "idle"` fires after every busy→idle transition,
which happens once per turn — not once per session. Each fire ended
the trace AND deleted the cache entry. The next event for the same
session in the next turn hit a cache miss, constructed a fresh
`Trace.create()`, called `startTrace(sessionID, {})` (which pushes a
single root span into empty `this.spans`), and the immediate
`snapshot()` clobbered the rich on-disk `ses_<id>.json` with a 1-span
file.
This also explains the "What was asked / No prompt recorded" symptom:
`metadata.prompt` was captured on the now-destroyed first instance and
never persisted into the replacement.
Fixes in this commit:
* `worker.ts`: removed the destructive `session.status === "idle"`
handler. Sessions in altimate-code are long-lived; the Trace lives
as long as the worker has the session in cache. Finalization
happens on `shutdown` and on MAX_TRACES eviction only — both
already correct.
* `tracing.ts`: new `Trace.rehydrateFromFile(sessionId)` that reads
the existing on-disk file and restores `this.spans`, `this.metadata`,
`this.rootSpanId`, `this.startTime`, counters, and clears the root's
endTime so the trace renders as still-in-progress. Returns true on
success; false on missing/mismatched/malformed file.
* `worker.ts:getOrCreateTrace`: on cache miss, calls
`rehydrateFromFile` before falling back to `startTrace`. Defense in
depth for the worker-restart / MAX_TRACES-eviction paths — even if
some future path destroys the in-memory instance, the new instance
loads disk state instead of overwriting.
Verification
* Behavioral test (`test/altimate/tracing-rehydrate.test.ts`, 4 cases):
proves end-to-end that rehydrate preserves spans+metadata across
Trace-instance reconstruction, returns false on missing/mismatched
files, and clears the root endTime so re-opened traces accept new
events.
* Source-grep regression tests for worker.ts continue to lock the
no-idle-clobber and rehydrate-before-startTrace contracts.
* 449 pass / 0 fail across the full tracing + TUI suites (1 network
flake in tracing-adversarial-2 unrelated to this change, passes on
re-run).
What I traced before declaring done
* Inventoried every `sessionTraces.delete`, `sessionTraces.clear`,
`endTrace()`, `Trace.create()`, `Trace.withExporters()`, and direct
trace-file write across the whole repo.
* Confirmed `this.spans` is never reassigned mid-instance (only
pushed) except by the new `rehydrateFromFile`.
* Confirmed no external callers of `trace.snapshot()` outside
`tracing.ts`.
Post-fix, the only ways a new `Trace` instance can replace an existing
session's in-memory Trace are: worker boot (once), `setWorkspace` with
an actually-changed workspaceID (rare, also idempotency-guarded), and
MAX_TRACES eviction (uncommon at 100 sessions). All three now go
through `rehydrateFromFile` first.
* fix(tracing): capture user prompt via setPrompt; drop time.end gate
Per codex review (2026-06-05): the previous user-text branch in worker.ts
gated on `part.time?.end` (which user-input parts never have set) AND
called `trace.setTitle(text, text)` which would have regressed the
auto-generated session title from Path C (`session.updated`) back to
the raw user input ('Greeting' → 'hi') if the ordering went sideways.
* New `Trace.setPrompt(prompt)` method that only mutates `metadata.prompt`.
Decouples prompt capture from title mutation.
* Path B in worker.ts now: (a) accepts user text parts without
`part.time?.end` (it's an assistant-side concept only); (b) calls
`setPrompt(text)` only — never `setTitle` — for user-identified
messages. Assistant text still requires `time.end` for `logText`.
* Source-grep regression tests lock both contracts: no more
`part.time?.end` on the user branch, no `setTitle` from the user
branch, `setPrompt` exists and doesn't touch title.
* fix(tracing): record user messages as spans so chat tab renders multi-turn
The chat tab in the trace viewer renders 'metadata.prompt' as a single
'You' bubble at the top, then iterates 'kind: generation' spans for
assistant replies. There's no place for any user message beyond the
first to land — `setPrompt` overwrites on every call, and the viewer
only reads the latest value. Symptom: a 3-turn session shows only the
LAST user prompt followed by all earlier assistant responses, with the
older user messages dropped.
Fix splits the data and the rendering:
* New `Trace.logUserMessage(text)` pushes a `kind: 'user-message'`
span with the user text as input. Snapshots immediately like other
log* methods.
* New 'user-message' variant added to the TraceSpan.kind union.
* worker.ts Path B: now also calls `logUserMessage(text)` alongside
`setPrompt(text)` for user-identified text parts (the first one
populates metadata.prompt for the Summary tab; all of them populate
per-turn spans for the Chat tab).
* viewer.ts chat-view: builds a chronologically sorted list of
user-message + generation spans and walks it in startTime order.
Older traces without user-message spans fall back to rendering
metadata.prompt as before.
* Behavioral test in tracing-rehydrate.test.ts proves the spans are
written, ordered chronologically, and preserve the user text.
10 unit tests in worker-trace-clearing + 8 in tracing-rehydrate pass;
35 existing tracing tests pass unchanged; typecheck clean.
* docs: trace-bugs followup to #867 — what this branch actually fixes
* fix(tracing): address PR #895 bot review feedback
* Trace.rehydrateFromFile (cubic P2): restore traceId from the on-disk file
so post-rehydrate snapshots/exports preserve trace identity across instance
lifetimes. Without this, every snapshot after rehydration writes a fresh
random traceId.
* Trace.rehydrateFromFile (cubic P2): normalize sessionId via the same
sanitization buildTraceFile applies before comparing to trace.sessionId.
Previously, sessions with /, \, ., or : in the id would be falsely
rejected and recreated.
* viewer chat-view (cubic P2): always render metadata.prompt at the top
unless an existing user-message span carries the same text. Pre-fix
traces (only metadata.prompt) and mixed traces (rehydrated pre-fix data
+ new turns) now render the first user turn correctly. Previously, the
fallback was gated on userMsgs.length === 0 and dropped the legacy
first turn in mixed traces.
* worker-trace-clearing.test.ts (CodeRabbit, cubic P3): broaden the
negative regression guards to catch all three flagged bug spellings —
inline expression, inline ternary, block body with if — for the
workspaceID effect; and to reject part.time?.end nested inside the
user-text branch (identified by sessionUserMsgIds.get(...).has(...)).
* routes/session/index.tsx: paraphrased the bug-shape literal that was
in a comment so the broadened test regex doesn't catch our own
documentation as the bug.
* tracing-rehydrate.test.ts: behavioral tests for the traceId
preservation and sanitized-sessionId match.
Skipped CodeRabbit's tmpdir-fixture-style suggestion — the convention
isn't followed by the existing tracing tests (tracing-display-crash,
tracing-rename-race) so changing this one file alone would be inconsistent
and out of scope for this PR.
48 affected tests pass; typecheck clean.
* test(tracing): migrate tracing-rehydrate to tmpdir() fixture
CodeRabbit pointed out that `packages/opencode/test/AGENTS.md` documents
`tmpdir()` from `fixture/fixture.ts` as the project convention. My
earlier reply skipped the migration on the grounds that sibling tracing
tests don't follow the convention — but for code I'm adding fresh, the
right move is to follow the documented standard. The sibling tests
predate it and should be swept in a separate cleanup PR.
Replaces the manual `os.tmpdir() + beforeEach/afterEach` pattern with
`await using tmp = await tmpdir()` per test. Helpers `makeTrace` and
`readTraceFile` now take `dir` as a first parameter so each test
threads its own tmp directory through. 46 affected tests pass.
* fix(viewer): dedupe metadata.prompt against truncated user-message input
cubic flagged that `Trace.logUserMessage` slices user text at 4000 chars
when persisting to the span, while `metadata.prompt` keeps the full
string. The strict equality check in viewer chat-view (`u.input ===
t.metadata.prompt`) misses the dedupe for prompts longer than 4000 chars
and renders the same text twice — once as the top-level "You" fallback
bubble, once as the first user-message span.
Match against both the full and the truncated form. Same fix shape cubic
suggested.
* docs: remove redundant spec/trace-bugs-followup-867.md
The PR description already carries the bug-by-bug origin table and the
explanation of why #867's scope was disjoint from these bugs. Keeping a
295-line spec file in the repo to say the same thing again is bloat —
the PR is the right place for this content.
* fix(tracing): synthetic-part gate, in-flight gen interrupt, shared truncation constant
Three follow-ups from the multi-LLM consensus review of PR #895, codex-validated:
* Worker user-text branch now skips parts with `synthetic` or `ignored`
set (Major #1 in the review, codex-confirmed). `Session.createUserMessage`
in prompt.ts attaches many synthetic text parts to the user messageID for
MCP resource banners, decoded file contents, retry/reminder text,
plan-mode reminders, and agent-handoff tags. Without the gate they pass
the `sessionUserMsgIds.has(messageID)` check, `metadata.prompt` ends up
holding the LAST synthetic part (typically a file blob), and the chat tab
renders one fake "▶ You" bubble per synthetic span — defeating the two
display surfaces this PR fixes. Gated on an `isAuthoredText` predicate
so the symmetric assistant-text branch is also protected. Continue via
predicate rather than `continue` keyword so the outer event loop still
forwards the event downstream via `Rpc.emit`.
* `Trace.rehydrateFromFile` now marks any open generation span as
interrupted (Major #2). The transient state `logStepStart` populated
(`currentGenerationSpanId`, `generationText`, `generationToolCalls`,
`pendingToolResults`) is memory-only and can't be reconstructed from
disk. If we leave open spans open, the next `step-finish` for that turn
drops at the `!this.currentGenerationSpanId` guard and follow-up
`logToolCall` mis-parents tool spans to the root, silently degrading the
trace shape. Closing the span with `status: "error"` and a
`statusMessage` describing the interruption preserves the partial data
and makes the boundary visible in the viewer.
* Extracted the 4000-char truncation cap as `USER_MESSAGE_INPUT_MAX_CHARS`
exported from tracing.ts (new cubic P3 on viewer.ts:1331). The viewer's
chat-tab dedupe now interpolates the same constant so the two sides can't
drift if the truncation cap ever changes. Also reused a single
`Date.now()` call for the user-message span's start/end timestamps
(cosmetic, addresses review nit #16).
Skipped from the review:
- Major #3 (no per-messageID dedupe in logUserMessage): codex confirmed
user text doesn't stream/chunk — message.part.delta is assistant-only
— so the symptom the review described is subsumed by Major #1's
synthetic gate. No separate fix needed.
- Major #5 (Path A `setTitle(text, text)` couples title and prompt):
codex grep-verified that no in-repo code path populates
`userMsg.summary.title` or `summary.body`; the branch is inert.
Cleanup risk only, tracked in #896.
Tests
- New behavioral test in tracing-rehydrate.test.ts asserts that an open
generation span (no `step-finish` before reconstruction) ends up
with `endTime` set, `status: "error"`, and a statusMessage matching
`/interrupted/i` after rehydrate + a snapshot-triggering call.
- New source-grep test in worker-trace-clearing.test.ts locks both
the synthetic-gate literal (`!part.synthetic && !part.ignored`) and
the requirement that both `trace.setPrompt` and `trace.logUserMessage`
sit inside the `isAuthoredText &&` guard.
42 affected tests pass; typecheck clean.
* test: tighten worker-trace-clearing regex to scope-bounded match (CodeRabbit)
CodeRabbit flagged that the previous source-grep assertions matched
across the entire `worker.ts` file, so unrelated code positioning
could satisfy them without the synthetic-gate fix being present in
the actual user-text branch.
* The `isAuthoredText` declaration check now asserts the const is
built from BOTH flags (`!part.synthetic && !part.ignored`), not
just that the literal exists somewhere.
* The two write-path checks now require `trace.setPrompt` and
`trace.logUserMessage` to sit inside the same `if (text) { ... }`
body within the `sessionUserMsgIds...has(part.messageID)` branch.
The `[^{}]` bounds on the inner spans prevent the match from
extending past the closing brace of that body, so calls elsewhere
in the file can't false-green the assertion.
* fix(tracing): make rehydrateFromFile async to unblock the event-loop hot path
cubic flagged that `fsSync.readFileSync` in `rehydrateFromFile` blocks
the worker event loop during a trace cache miss. The hot path is
bounded (cache miss only fires on worker restart, MAX_TRACES eviction,
or initial-boot resumption of a stale session), but a multi-MB trace
file makes the pause visible.
* `Trace.rehydrateFromFile` now returns `Promise<boolean>` and uses
the async `fs.readFile`.
* `getOrCreateTrace` in worker.ts becomes `async` and the three call
sites in the event-stream loop now `await` it. The loop body was
already async (`for await (const event of events.stream)`), so the
conversion is local.
* Behavioural tests in `tracing-rehydrate.test.ts` converted to
`await` the now-async method (7 call sites).
* The source-grep contract test for `getOrCreateTrace`'s
rehydrate-before-startTrace shape now matches the `await` form.
Not addressed in this commit (will reply on PR):
- cubic also flagged a theoretical event-ordering race where
`message.part.updated` could arrive before `message.updated`,
leaving `sessionUserMsgIds` empty when the part handler runs. The
producer (`Session.createUserMessage` → `updateMessage` THEN
`updatePart` for each part) emits in order, and the consumer reads
the event stream sequentially. The race is theoretical given the
current producer; if we ever reorder, the defensive fix is to buffer
unrouted parts by messageID. Out of scope for this PR.
---------
Co-authored-by: Haider <haider@altimate.ai>1 parent 7e909a9 commit 89699f6
6 files changed
Lines changed: 749 additions & 36 deletions
File tree
- packages/opencode
- src
- altimate/observability
- cli/cmd/tui
- routes/session
- test
- altimate
- cli/tui
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
42 | 42 | | |
43 | 43 | | |
44 | 44 | | |
45 | | - | |
| 45 | + | |
46 | 46 | | |
47 | 47 | | |
48 | 48 | | |
| |||
345 | 345 | | |
346 | 346 | | |
347 | 347 | | |
| 348 | + | |
| 349 | + | |
| 350 | + | |
| 351 | + | |
| 352 | + | |
| 353 | + | |
348 | 354 | | |
349 | 355 | | |
350 | 356 | | |
| |||
490 | 496 | | |
491 | 497 | | |
492 | 498 | | |
| 499 | + | |
| 500 | + | |
| 501 | + | |
| 502 | + | |
| 503 | + | |
| 504 | + | |
| 505 | + | |
| 506 | + | |
| 507 | + | |
| 508 | + | |
| 509 | + | |
| 510 | + | |
| 511 | + | |
| 512 | + | |
| 513 | + | |
| 514 | + | |
| 515 | + | |
| 516 | + | |
| 517 | + | |
| 518 | + | |
| 519 | + | |
| 520 | + | |
| 521 | + | |
| 522 | + | |
| 523 | + | |
| 524 | + | |
| 525 | + | |
| 526 | + | |
| 527 | + | |
| 528 | + | |
| 529 | + | |
| 530 | + | |
| 531 | + | |
| 532 | + | |
| 533 | + | |
| 534 | + | |
| 535 | + | |
| 536 | + | |
| 537 | + | |
| 538 | + | |
| 539 | + | |
| 540 | + | |
| 541 | + | |
| 542 | + | |
| 543 | + | |
| 544 | + | |
| 545 | + | |
| 546 | + | |
| 547 | + | |
| 548 | + | |
| 549 | + | |
| 550 | + | |
| 551 | + | |
| 552 | + | |
| 553 | + | |
| 554 | + | |
| 555 | + | |
| 556 | + | |
| 557 | + | |
| 558 | + | |
| 559 | + | |
| 560 | + | |
| 561 | + | |
| 562 | + | |
| 563 | + | |
| 564 | + | |
| 565 | + | |
| 566 | + | |
| 567 | + | |
| 568 | + | |
| 569 | + | |
| 570 | + | |
| 571 | + | |
| 572 | + | |
| 573 | + | |
| 574 | + | |
| 575 | + | |
| 576 | + | |
| 577 | + | |
| 578 | + | |
| 579 | + | |
| 580 | + | |
| 581 | + | |
| 582 | + | |
| 583 | + | |
| 584 | + | |
| 585 | + | |
| 586 | + | |
| 587 | + | |
| 588 | + | |
| 589 | + | |
| 590 | + | |
| 591 | + | |
| 592 | + | |
| 593 | + | |
| 594 | + | |
| 595 | + | |
| 596 | + | |
| 597 | + | |
| 598 | + | |
| 599 | + | |
| 600 | + | |
| 601 | + | |
493 | 602 | | |
494 | 603 | | |
495 | 604 | | |
| |||
515 | 624 | | |
516 | 625 | | |
517 | 626 | | |
| 627 | + | |
| 628 | + | |
| 629 | + | |
| 630 | + | |
| 631 | + | |
| 632 | + | |
| 633 | + | |
| 634 | + | |
| 635 | + | |
| 636 | + | |
| 637 | + | |
| 638 | + | |
| 639 | + | |
| 640 | + | |
| 641 | + | |
| 642 | + | |
| 643 | + | |
| 644 | + | |
| 645 | + | |
| 646 | + | |
| 647 | + | |
| 648 | + | |
| 649 | + | |
| 650 | + | |
| 651 | + | |
| 652 | + | |
| 653 | + | |
| 654 | + | |
| 655 | + | |
| 656 | + | |
| 657 | + | |
| 658 | + | |
| 659 | + | |
| 660 | + | |
| 661 | + | |
| 662 | + | |
| 663 | + | |
| 664 | + | |
| 665 | + | |
| 666 | + | |
518 | 667 | | |
519 | 668 | | |
520 | 669 | | |
| |||
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
12 | 12 | | |
13 | 13 | | |
14 | 14 | | |
15 | | - | |
| 15 | + | |
16 | 16 | | |
17 | 17 | | |
18 | 18 | | |
| |||
1310 | 1310 | | |
1311 | 1311 | | |
1312 | 1312 | | |
| 1313 | + | |
| 1314 | + | |
| 1315 | + | |
| 1316 | + | |
| 1317 | + | |
| 1318 | + | |
| 1319 | + | |
| 1320 | + | |
| 1321 | + | |
| 1322 | + | |
| 1323 | + | |
| 1324 | + | |
1313 | 1325 | | |
1314 | | - | |
1315 | | - | |
| 1326 | + | |
| 1327 | + | |
| 1328 | + | |
| 1329 | + | |
| 1330 | + | |
| 1331 | + | |
| 1332 | + | |
| 1333 | + | |
| 1334 | + | |
| 1335 | + | |
| 1336 | + | |
| 1337 | + | |
| 1338 | + | |
| 1339 | + | |
| 1340 | + | |
| 1341 | + | |
1316 | 1342 | | |
1317 | | - | |
1318 | | - | |
1319 | | - | |
| 1343 | + | |
| 1344 | + | |
| 1345 | + | |
| 1346 | + | |
| 1347 | + | |
| 1348 | + | |
| 1349 | + | |
| 1350 | + | |
| 1351 | + | |
| 1352 | + | |
| 1353 | + | |
| 1354 | + | |
1320 | 1355 | | |
1321 | 1356 | | |
1322 | 1357 | | |
| |||
Lines changed: 18 additions & 5 deletions
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
183 | 183 | | |
184 | 184 | | |
185 | 185 | | |
186 | | - | |
187 | | - | |
188 | | - | |
189 | | - | |
190 | | - | |
| 186 | + | |
| 187 | + | |
| 188 | + | |
| 189 | + | |
| 190 | + | |
| 191 | + | |
| 192 | + | |
| 193 | + | |
| 194 | + | |
| 195 | + | |
| 196 | + | |
| 197 | + | |
| 198 | + | |
| 199 | + | |
| 200 | + | |
| 201 | + | |
| 202 | + | |
| 203 | + | |
191 | 204 | | |
192 | 205 | | |
193 | 206 | | |
| |||
0 commit comments