Repository navigation
fix: show a stopped event log in inspect and in a timed-out wait - #357
Conversation
When the event log reached its byte or event limit, inspect gave no sign
of it and a wait for later output timed out without a reason.
- inspect --json adds eventLogStop ({ reason: 'bytes' | 'events', seq }),
read from the stop marker in events.jsonl, and prints one line for it.
The field is absent when the log has not stopped.
- A render wait that times out, and a timed-out batch wait step, add a
sentence that names the stop. The error code stays WAIT_TIMEOUT.
- readEventLogStop finds the marker with the check that EventLog.open
uses to start a reopened log stopped, so both agree.
…irst stop marker wins
|
@codex review |
|
@codex security review |
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
🛡️ Codex Security ReviewSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 6229dbe993
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
|
@codex review |
|
@codex security review |
|
Codex Review: Didn't find any major issues. Another round soon, please! Reviewed commit: ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
If Codex has suggestions, it will comment; otherwise it will react with 👍. Codex can also answer questions or update the PR. Try commenting "@codex address that feedback". |
🛡️ Codex Security ReviewSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
readline also splits on U+2028 and U+2029, which JSON.stringify writes raw, so inspect missed a stop after such an output and counted one entry too many. The scan now splits on '\n' and joins the pieces of a long line once. Tests pin both separators, a bad line before a marker whose seq follows, and an unclosed limit.
|
@codex review |
|
@codex security review |
|
Codex Review: Didn't find any major issues. 🚀 Reviewed commit: ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
If Codex has suggestions, it will comment; otherwise it will react with 👍. Codex can also answer questions or update the PR. Try commenting "@codex address that feedback". |
🛡️ Codex Security ReviewSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
|
@codex review |
|
@codex security review |
🛡️ Codex Security ReviewSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
|
Codex Review: Didn't find any major issues. Keep it up! Reviewed commit: ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
If Codex has suggestions, it will comment; otherwise it will react with 👍. Codex can also answer questions or update the PR. Try commenting "@codex address that feedback". |
Why
After #340 the host stops the event log at 52,428,800 bytes or at 250,000 events and writes one stop marker. Later output is not recorded.
inspectshowed onlyeventCountandeventLogBytes. Await --textfor text that arrived after the stop timed out and said nothing about the stop. A user saw frozen snapshots and waits and had no way to tell why.This is the second version of the change. The first version read the stop marker from
events.jsonlin the CLI with its own line parser. Review found these problems:events.jsonl. It skipped bad lines and never checked thatseqis contiguous. AGENTS.md keeps parsing and validation of the persisted log insrc/storage/eventLogCodec.ts.batch --keep-going, every failed wait read the whole log again.inspectfailed withINTERNAL_ERRORon a stop marker whose label names no limit.mainprints the session there.inspectread the event count, the size and the stop in three reads. During the stop the numbers can disagree, witheventLogStop.seqabovelastEventSeq.wait --text <later text>failed withREPLAY_ERRORand said nothing about the stop.batchstopped passing the stop on.What
Behavior a user sees:
inspect --jsonhas an optional fieldeventLogStop:{ "reason": "bytes" | "events" | "unknown", "seq": <n> }.reasonis the limit that stopped the log.seqis theseqof the stop marker.unknownmeans that the marker is in the log but its label names no limit. The host treats such a marker as a stop too, soinspectshows it and does not fail. Without--json, one line followsEvent Log Bytes:, for exampleEvent Log Stopped: at seq 7868 (byte limit); later events are not recorded. Forunknownit reads(reason unknown).waitthat times out on a stopped log addsThe event log stopped at seq 7868 (byte limit), so output after it is not seen.to its message, with and without--json.error.details.eventLogStopcarries{ reason, seq }. The code staysWAIT_TIMEOUTand the exit code stays 11. Abatchwaitstep adds the same sentence to its message.--idle-msand--exitwaits and waits that match do not change.waitreplays the stored log. When the replayed screen does not satisfy the wait, theREPLAY_ERRORmessage ends with the same sentence anderror.details.eventLogStopcarries the same facts.How it works:
src/storage/eventLogCodec.ts, the one place that parsesevents.jsonl.EVENT_LOG_LIMIT_LABEL_PREFIXandeventLogStopLabel(the label the host writes) moved there fromsrc/host/eventLog.ts.findEventLogStop(records)finds the first stop marker in records and reads its limit.EventLog.openand the offline wait use it.scanEventLog(path)streams the file once and returns{ entryCount, byteCount, stop }. It uses the codec's ownparseEventLogLineandassertSeqFollows(the checks ofparseEventLogContent), soinspectand replay agree on what a valid record is. It does not enforce the 50 MB read limit, soinspectstill works on a log that an older version wrote past it.scanEventLoglooks for the stop only in the lines that replay accepts, up to the first bad line. A bad line ends the search and the count goes on. Soinspectstill shows a log that replay rejects, and it does not report a marker behind a torn last line.inspecttakes the count, the size and the stop from onescanEventLogcall. The scan opens the file, measures it, and reads exactly those bytes. A host that appends meanwhile cannot make the three numbers disagree, andeventLogStop.seqis never abovelastEventSeq.EventLog.getStop()reads it from the host's own record buffer. The marker is in the buffer as soon asrecordStoptakes itsseq, before its write settles. The host'swaitForRendertimeout result carries it as the new optional fieldeventLogStop. The CLI never reads the log file for a wait, so the race is gone by construction.batchgets the stop from the same host result. A--keep-goingbatch with many failed waits does no extra read. The code insrc/cli/commands/batch.tsis the same as onmain.replayInput.events, the events that the replay already read.readEventLogStop,readEventLogStopForTimeout,countEventLogEntriesandstatEventLogBytes.CLI JSON and RPC contract changes. All are additions, no existing field changes:
inspectresult: optionaleventLogStop(reasonisbytes,eventsorunknown).waitForRenderRPC result: optionaleventLogStop, set only on a timed-out result of a host whose log stopped. It also appears underresultof theWAIT_TIMEOUTenvelope.WAIT_TIMEOUTand the offlineREPLAY_ERROR: one added sentence in the message anddetails.eventLogStop.EventLogStopSchemaandEventLogStopReasonSchemalive insrc/protocol/schemas.ts(strict) andmessages.tsre-exports them. Schemas, the golden envelope tests,docs/USAGE.md,docs/TROUBLESHOOTING.mdand the READMEs ofsrc/batch,src/cli,src/cli/commands,src/host,src/protocolandsrc/storagechanged in this PR.Limits:
A CLI of an older version that talks to a host of this version gets
RPC_ERROR("RPC result failed validation for method waitForRender") instead ofWAIT_TIMEOUTfor a timed-out wait on a stopped log, because its result schema is strict. I saw this with the CLI ofmainagainst a host of this branch. A newer CLI with an older host works and adds no sentence.When a log that agent-tty did not write leaves no room for the stop marker, the host stops without a marker.
getStop(),inspectand replay then report no stop, because the stop is defined by the marker in the log.inspectnow parses every record up to the stop marker. On a 52 MB log,scanEventLogtakes 101 to 129 ms and a line count alone takes 38 to 86 ms.scanEventLogsplits lines on\nonly, asparseEventLogContentdoes, so an output that holds U+2028 or U+2029 counts as one record and a stop after it is found. (readlinesplit on those characters, which also made the line count on main one too high.)Validation
npm run format:check,npm run lint,npm run typecheckand.agents/skills/verify-session-lifecycle/scripts/check.sh --drift-onlypass. The check went STALE becauseEventLog.opennow callsfindEventLogStopinstead ofsome(isStopMarker). The lifecycle model still describes the code, because that call only sets the stopped flag that the model does not use. I ran--update-coverage, stopped it after it rewrotecoverage.json(CI runs TLC), formatted the file and confirmed the check passes. Only theEventLog.openfingerprint changed.npx vitest run test/unit: 147 files, 2240 tests pass.mainhas 2168, so 68 tests are new.--maxWorkers=1 --retry=0: 39 integration and e2e files that reachinspect,wait,batch, the host or the event log (all integration and e2e files except the eval ones andcross-backend-screen-hash) give 409 passed, 3 skipped (other-user-groupneeds a setpriv copy) and 3 failed. The 3 failed passed when I reran them alone:lifecycle.test.ts("destroy of an exited session from a CLI that sees no /proc, in another pid namespace, names /proc while its leftover runs"),export-fixtures.test.ts("captures a color-grid screenshot with a non-trivial PNG artifact") andscreenshot-missing-glyphs.test.ts("says the glyph check is incomplete when a screen has too many glyphs to probe"). The host was under heavy load from other work, and none of the three touches the event log stop. The first of them is the test that test: make the no-/proc destroy test independent of host timing #355 made independent of host timing. This branch is one commit behindmainand does not have that fix yet. A trial merge withmainhas no conflict.test/unit/storage/eventLogScan.test.ts(new):scanEventLogon missing, empty, counted, multibyte and over-limit files, stops from a real writer for both limits, look-alikes, first marker wins, unknown reason, bad lines before the marker (bad JSON, bad shape, gap, repeat, firstseqnot 0), the same logs throughreadEventLogRecords, a torn last line, agreement withEventLog.open, and one snapshot while a host appends.eventLogCodec.test.ts: label wording,findEventLogStopand theunknownreason.eventLog.test.ts:EventLog.getStop(), including that it reports the stop before the marker write settles.wait.test.ts: the stop from the host result for each render flag,--json, the timeout wording, the three reason words, no stop, matched waits, legacy waits and the offlineREPLAY_ERROR.batch.test.ts(command level),executor.test.ts,inspect.test.ts,rpcServer.test.ts,messages.test.tsandgolden-envelopes.test.ts.test/integration/event-log.test.ts: a real host on a planted stopped log. Cases: liveinspect, a timed-outwait, a failedbatch, a--keep-goingbatch with two timed-out waits, an exited session (inspectand an offlinewait), and anunknownmarker.Mutation results
scanEventLogskips theseqcheckreports no stop for a gap in the seq values,... a repeated seq,... a first seq that is not 0scanEventLogskips the schema checkreports no stop for a line that is not an event record before the markerscanEventLogenforces the 50 MB limitreads a log that is over the size limit that replay readsscanEventLogreads to the live end of the filedescribes one snapshot of the file ...inspectreads the stop in a second calltakes the count, the size and the stop from one read of the loginspectdrops the size from the scantakes the count, the size and the stop ...,surfaces eventLogBytes in both live and offline modesreports a stop marker that names no limit ... reason unknown,keeps honouring a marker with the reserved prefix ...and the fivefindEventLogStopcasesEventLog.getStop()returnsundefinedreports the stop as soon as the append that stops the log returns, before its marker is writteneventLogStopevent-log.test.ts(integration):shows the stop in inspect, in a timed-out wait and in batch waits of a live sessionandshows a stop marker that names no limit ...wait.test.ts, among themnames the stop that the host reports in the WAIT_TIMEOUT of a --text waitdetails.eventLogStopoutwait.test.tsnames the stop of the replayed events when the snapshot does not satisfy the wait,names a stop whose label names no limitexecutor.test.ts:names where the host reports ...,names a stop in each timed-out wait of a keep-going batch.batch.test.ts:names the stop in every timed-out wait of a --keep-going batch,names the stop in the error of a failed batch under --jsonWaitForRenderResultSchemadrops the fieldbatch.test.ts(2 tests),rpcServer.test.ts:carries the event log stop of a timed-out wait to the client,messages.test.ts:accepts a timed-out waitForRender result that carries the event log stopunknownchangeswords the unknown reason as "reason unknown",names a stop whose label names no limit,reports the stop of the stored log with the unknown reason, from a live hosthostMain.tspassesgetStop()into its timeout result) has no unit test, because the handler lives insiderunHost. The integration test above covers it.getStop()itself has unit tests.node --import tsx src/cli/main.ts) against real sessions that stopped. The same input ran under the CLI ofmainand under this branch.AFTER-THE-STOP. The log stopped at seq 6084 with 52,423,099 bytes. Underinspect --json(live)eventLogStopis{"reason":"bytes","seq":6084}andeventCountis 6085, so the stop is the last counted record.wait --text AFTER-THE-STOP --timeout 3000exits 11 withWait timed out before its condition was met. The event log stopped at seq 6084 (byte limit), so output after it is not seen.anddetails.eventLogStop. Abatch --keep-goingwith two timed-out waits puts the sentence in both steps.wait --regex '\S'still matches the stored screen.inspectshows the sameeventLogStop(eventCount6086).wait --text AFTER-THE-STOPfails withREPLAY_ERROR. Its message ends with the stop sentence anddetails.eventLogStopis{"reason":"bytes","seq":6084}. Onmainthe same command gives theREPLAY_ERRORmessage without the sentence.(event limit), ininspect, in a timed-outwait, in both steps of a--keep-goingbatch, and in the offlineREPLAY_ERRORafter the exit.... (soon). This branch:inspectexits 0 with{"reason":"unknown","seq":1}, the lineEvent Log Stopped: at seq 1 (reason unknown); later events are not recorded, and a timed-outwaitthat says(reason unknown). The PR head6229dbefails withINTERNAL_ERROR: stop marker label must name its limit.mainprints the session.inspect --jsonon the byte-limit session, 3 runs each, including about 1 s of start-up: live 1.16, 1.13, 1.12 s here, 1.53, 1.23, 1.11 s at the PR head, 1.44, 1.07, 1.08 s onmain. Exited: 1.10, 1.12, 1.23 s here and 1.00, 1.04, 1.16 s onmain. I measured no difference beyond noise.scanEventLogalone: 101 to 129 ms on this log, against 38 to 86 ms for a line count.Generated with
xum• Model:anthropic:claude-sonnet-5-5• Thinking:xhigh