main · last commit
13 days ago ·
7g0stsfu
ah-1cx.15 ahub-run should drop message_update while teeing: 95% of every event stream is unread
Past Stand
bd reopen ah-1cx.15
| Created by | Eugene Blikh |
| Owner | bigbes@gmail.com |
| Created | 2026-08-04T23:43:44Z |
| Updated | 2026-08-05T00:06:50Z |
| Closed | 2026-08-05T00:06:50Z |
Root cause behind the 202 MB event streams (ah-07g) that motivated ah-1cx.1, quantified during the ah-1cx.4 capture. In a fresh real pi 0.82.1 run, message_update events were 123 of 143 lines and about 95% of the 166 KB. They exist so an interactive UI can render a partial message as it streams, and each one embeds the WHOLE partial message — so their volume grows quadratically with message length. Nothing in this codebase reads them: ParseEvents only consumes the session header and message_end. Having ahub-run filter message_update out while teeing events.jsonl (or rotate/compress the file) would shrink real streams by roughly 20×, which would make even the full parse cheap and would retire the tail of this whole class of bug — ah-1cx.1's asymmetric read path, ah-1cx.9's repeated crash-path parse, and the disk footprint of every archived worktree.
EVIDENCE for the design decision, measured on a real pi 0.82.1 capture (the same run that settled ah-1cx.4): Line-type histogram over 143 lines / 166 KB: 123 {"type":"message_update",... <- 86% of lines, ~95% of bytes 4 {"type":"message_start",... 4 {"type":"message_end",... <- the only ones ParseEvents sums 2 {"type":"turn_start"} 2 {"type":"turn_end",... 2 {"type":"tool_execution_update",... 1 {"type":"tool_execution_start",... 1 {"type":"tool_execution_end",... (plus session, agent_start, agent_end, agent_settled) KEY IMPLEMENTATION FACT: 'type' is the FIRST key on every single line, so a filter can decide from a short fixed-length prefix and never has to buffer a whole line. That matters because message_update embeds the whole partial message, so lines grow with the conversation — the parser's own maxEventLine cap is 10 MB. A filtering writer should therefore be prefix-driven and stateful ('am I inside a line I already decided to drop?'), NOT line-buffering, or it reintroduces the memory problem it exists to solve. The current tee is a raw byte MultiWriter set as cmd.Stdout (cmd/ahub-run/main.go:129-141), so this means inserting a small stateful io.Writer in front of the FILE half only. RISK NOTE: events.jsonl is the file every completion fact is read from — session id, cost, and since ah-tqc the final-turn verdict. A filter bug corrupts the daemon's entire view of a run. Whatever lands must (a) keep the output a valid JSONL stream, (b) never drop a line whose type it did not positively recognise as message_update (fail OPEN, not closed), and (c) be covered by a test that replays testdata/pi-events-multi-real.jsonl's raw form through the filter and asserts ParseEvents gets byte-identical facts. OPEN DECISION, needs an operator answer before coding: is events.jsonl only the daemon's fact source, or also a human debugging artifact? message_update is the ONLY record of the streaming assistant text as it was produced; dropping it means a human reading an archived worktree tarball sees the final messages but not the process. If it is only a fact source, filtering is free. If humans read it, prefer rotation/compression, or filter the teed copy while keeping the raw stream separately under a size cap. internal/runner/archive.go is the other consumer to check.
A real multi-minute run's events.jsonl is an order of magnitude smaller, the daemon's parsed facts are unchanged, and whatever is lost for human debugging is stated explicitly in SPEC section 9.
ah-1cx
— Hardening: post-audit bug sweep (2026-07-20)
parent-child
open
Nothing depends on this issue.
| id | ah-1cx.15 |
| content_hash | 7ea33ea771d8c5c30bad682cadf1d09f6b4388d61a2903ce4a9a77768b12afe0 |
| title | ahub-run should drop message_update while teeing: 95% of every event stream is unread |
| description | Root cause behind the 202 MB event streams (ah-07g) that motivated ah-1cx.1, quantified during the ah-1cx.4 capture. In a fresh real pi 0.82.1 run, message_update events were 123 of 143 lines and about 95% of the 166 KB. They exist so an interactive UI can render a partial message as it streams, and each one embeds the WHOLE partial message — so their volume grows quadratically with message length. Nothing in this codebase reads them: ParseEvents only consumes the session header and message_end. Having ahub-run filter message_update out while teeing events.jsonl (or rotate/compress the file) would shrink real streams by roughly 20×, which would make even the full parse cheap and would retire the tail of this whole class of bug — ah-1cx.1's asymmetric read path, ah-1cx.9's repeated crash-path parse, and the disk footprint of every archived worktree. |
| design | EVIDENCE for the design decision, measured on a real pi 0.82.1 capture (the same run that settled ah-1cx.4): Line-type histogram over 143 lines / 166 KB: 123 {"type":"message_update",... <- 86% of lines, ~95% of bytes 4 {"type":"message_start",... 4 {"type":"message_end",... <- the only ones ParseEvents sums 2 {"type":"turn_start"} 2 {"type":"turn_end",... 2 {"type":"tool_execution_update",... 1 {"type":"tool_execution_start",... 1 {"type":"tool_execution_end",... (plus session, agent_start, agent_end, agent_settled) KEY IMPLEMENTATION FACT: 'type' is the FIRST key on every single line, so a filter can decide from a short fixed-length prefix and never has to buffer a whole line. That matters because message_update embeds the whole partial message, so lines grow with the conversation — the parser's own maxEventLine cap is 10 MB. A filtering writer should therefore be prefix-driven and stateful ('am I inside a line I already decided to drop?'), NOT line-buffering, or it reintroduces the memory problem it exists to solve. The current tee is a raw byte MultiWriter set as cmd.Stdout (cmd/ahub-run/main.go:129-141), so this means inserting a small stateful io.Writer in front of the FILE half only. RISK NOTE: events.jsonl is the file every completion fact is read from — session id, cost, and since ah-tqc the final-turn verdict. A filter bug corrupts the daemon's entire view of a run. Whatever lands must (a) keep the output a valid JSONL stream, (b) never drop a line whose type it did not positively recognise as message_update (fail OPEN, not closed), and (c) be covered by a test that replays testdata/pi-events-multi-real.jsonl's raw form through the filter and asserts ParseEvents gets byte-identical facts. OPEN DECISION, needs an operator answer before coding: is events.jsonl only the daemon's fact source, or also a human debugging artifact? message_update is the ONLY record of the streaming assistant text as it was produced; dropping it means a human reading an archived worktree tarball sees the final messages but not the process. If it is only a fact source, filtering is free. If humans read it, prefer rotation/compression, or filter the teed copy while keeping the raw stream separately under a size cap. internal/runner/archive.go is the other consumer to check. |
| acceptance_criteria | A real multi-minute run's events.jsonl is an order of magnitude smaller, the daemon's parsed facts are unchanged, and whatever is lost for human debugging is stated explicitly in SPEC section 9. |
| notes | |
| status | closed |
| priority | 3 |
| issue_type | feature |
| assignee | NULL |
| estimated_minutes | NULL |
| created_at | 2026-08-04T23:43:44Z |
| created_by | Eugene Blikh |
| owner | bigbes@gmail.com |
| updated_at | 2026-08-05T00:06:50Z |
| closed_at | 2026-08-05T00:06:50Z |
| closed_by_session | |
| external_ref | NULL |
| spec_id | |
| compaction_level | 0 |
| compacted_at | NULL |
| compacted_at_commit | NULL |
| original_size | NULL |
| sender | |
| ephemeral | 0 |
| wisp_type | |
| pinned | 0 |
| is_template | 0 |
| mol_type | |
| work_type | |
| source_system | |
| metadata | �{} |
| source_repo | |
| close_reason | Done in c956724. DECISION MADE AND RECORDED: filter the FILE half of the tee only, leave stdout raw. The evidence that this loses nothing is that the final message_end carries the COMPLETE content array (verified on the pi 0.82.1 capture: thinking + text/toolCall, whole), so every message survives in full and only the superseded redraw increments are dropped; and a human watching LIVE is looking at the pane, which is untouched. That made the 'is the stream a human debugging artifact?' question answerable without an operator: it is, and filtering does not damage it. Implementation (cmd/ahub-run/eventfilter.go): a stateful prefix-driven io.Writer wrapping the file, inserted into the MultiWriter's file half. Prefix-driven rather than line-buffering because a single message_update can reach megabytes and buffering one would reintroduce the memory problem this exists to solve — pi writes 'type' as the FIRST key on every event, which is what makes a fixed 24-byte decision window possible. FAILS OPEN: a line is dropped only when its opening bytes positively match the marker, so anything unrecognized, malformed, split oddly or truncated passes through — events.jsonl is where every completion fact comes from (session id, cost, and since ah-tqc the final-turn verdict), so dropping too much costs correctness while dropping too little only costs disk. Write() reports the full input consumed even though fewer bytes reach the sink, because io.MultiWriter treats a short write as io.ErrShortWrite and would abort the tee. Close() flushes an undecided trailing partial line (a SIGKILLed child mid-write) rather than discarding evidence of how the run died. The load-bearing test is chunk-independence: cmd.Stdout hands the filter whatever a pipe read returns, so the marker can arrive split anywhere inside its 24 bytes. The suite replays each stream through EVERY single split point and one byte at a time, plus the fail-open cases (a space after the key, the marker as a longer type's prefix, the word as a later value, garbage/blank lines, lines shorter than the marker) and a 4 MB update line asserting the buffer never grows past the marker length. MEASURED end to end on the real capture, out of band: 166814 → 8212 bytes (20.3x, 4.9% kept), 143 → 20 lines, byte-identical to the same stream filtered by jq. SPEC §9 step 1 records the filter, the fail-open rule and these numbers. Knock-on: this shrinks real streams enough that ah-1cx.14 (the crash-confirmed full parse repeating every poll) stops being a starvation risk in practice, though the O(stream) call is still there. |
| event_kind | |
| actor | |
| target | |
| payload | |
| await_type | |
| await_id | |
| timeout_ns | 0 |
| waiters | |
| hook_bead | |
| role_bead | |
| agent_state | |
| last_activity | NULL |
| role_type | |
| rig | |
| due_at | NULL |
| defer_until | NULL |
| no_history | 0 |
| started_at | NULL |
| is_blocked | 0 |
| issue_id | ah-1cx.15 |
| label | milestone:v0.1.0 |
| id | 96d83b9a-524c-5109-bd99-eb556bf2da81 |
| issue_id | ah-1cx.15 |
| type | parent-child |
| created_at | 2026-08-05T02:43:43Z |
| created_by | Eugene Blikh |
| metadata | �{} |
| thread_id | |
| depends_on_issue_id | ah-1cx |
| depends_on_wisp_id | NULL |
| depends_on_external | NULL |
| id | 019fcf29-62e3-78ba-9cb7-2a0f1ebdf966 |
| issue_id | ah-1cx.15 |
| event_type | created |
| actor | Eugene Blikh |
| old_value | |
| new_value | |
| comment | NULL |
| created_at | 2026-08-05T02:43:43Z |
| id | 019fcf33-cdae-741e-8af4-a70dd8c9758c |
| issue_id | ah-1cx.15 |
| event_type | updated |
| actor | Eugene Blikh |
| old_value | {"id":"ah-1cx.15","title":"ahub-run should drop message_update while teeing: 95% of every event stream is unread","description":"Root cause behind the 202 MB event streams (ah-07g) that motivated ah-1cx.1, quantified during the ah-1cx.4 capture.\n\nIn a fresh real pi 0.82.1 run, message_update events were 123 of 143 lines and about 95% of the 166 KB. They exist so an interactive UI can render a partial message as it streams, and each one embeds the WHOLE partial message — so their volume grows quadratically with message length. Nothing in this codebase reads them: ParseEvents only consumes the session header and message_end.\n\nHaving ahub-run filter message_update out while teeing events.jsonl (or rotate/compress the file) would shrink real streams by roughly 20×, which would make even the full parse cheap and would retire the tail of this whole class of bug — ah-1cx.1's asymmetric read path, ah-1cx.9's repeated crash-path parse, and the disk footprint of every archived worktree.","design":"Decide first what the event stream is FOR. If it is only the daemon's fact source, filtering is free. If it is also a human debugging artifact (someone attaching to the pane, or reading an archived tarball to see what the agent was doing), then message_update is the only record of the streaming text and dropping it loses that — in which case rotation or compression is the right answer instead, or filtering with the raw stream kept separately under a size cap. The archive lane (internal/runner/archive.go) is the other consumer to check. Note ahub-run is the only writer, so this is a one-file change plus a decision.","acceptance_criteria":"A real multi-minute run's events.jsonl is an order of magnitude smaller, the daemon's parsed facts are unchanged, and whatever is lost for human debugging is stated explicitly in SPEC section 9.","status":"open","priority":3,"issue_type":"feature","owner":"bigbes@gmail.com","created_at":"2026-08-04T23:43:44Z","created_by":"Eugene Blikh","updated_at":"2026-08-04T23:43:44Z"} |
| new_value | {"design":"EVIDENCE for the design decision, measured on a real pi 0.82.1 capture (the same run that settled ah-1cx.4):\n\nLine-type histogram over 143 lines / 166 KB:\n 123 {\"type\":\"message_update\",... \u003c- 86% of lines, ~95% of bytes\n 4 {\"type\":\"message_start\",...\n 4 {\"type\":\"message_end\",... \u003c- the only ones ParseEvents sums\n 2 {\"type\":\"turn_start\"}\n 2 {\"type\":\"turn_end\",...\n 2 {\"type\":\"tool_execution_update\",...\n 1 {\"type\":\"tool_execution_start\",...\n 1 {\"type\":\"tool_execution_end\",...\n (plus session, agent_start, agent_end, agent_settled)\n\nKEY IMPLEMENTATION FACT: 'type' is the FIRST key on every single line, so a filter can decide from a short fixed-length prefix and never has to buffer a whole line. That matters because message_update embeds the whole partial message, so lines grow with the conversation — the parser's own maxEventLine cap is 10 MB. A filtering writer should therefore be prefix-driven and stateful ('am I inside a line I already decided to drop?'), NOT line-buffering, or it reintroduces the memory problem it exists to solve. The current tee is a raw byte MultiWriter set as cmd.Stdout (cmd/ahub-run/main.go:129-141), so this means inserting a small stateful io.Writer in front of the FILE half only.\n\nRISK NOTE: events.jsonl is the file every completion fact is read from — session id, cost, and since ah-tqc the final-turn verdict. A filter bug corrupts the daemon's entire view of a run. Whatever lands must (a) keep the output a valid JSONL stream, (b) never drop a line whose type it did not positively recognise as message_update (fail OPEN, not closed), and (c) be covered by a test that replays testdata/pi-events-multi-real.jsonl's raw form through the filter and asserts ParseEvents gets byte-identical facts.\n\nOPEN DECISION, needs an operator answer before coding: is events.jsonl only the daemon's fact source, or also a human debugging artifact? message_update is the ONLY record of the streaming assistant text as it was produced; dropping it means a human reading an archived worktree tarball sees the final messages but not the process. If it is only a fact source, filtering is free. If humans read it, prefer rotation/compression, or filter the teed copy while keeping the raw stream separately under a size cap. internal/runner/archive.go is the other consumer to check."} |
| comment | NULL |
| created_at | 2026-08-05T02:55:06Z |
| id | 019fcf3e-89b7-75e3-9b39-5a138205defc |
| issue_id | ah-1cx.15 |
| event_type | closed |
| actor | Eugene Blikh |
| old_value | |
| new_value | Done in c956724. DECISION MADE AND RECORDED: filter the FILE half of the tee only, leave stdout raw. The evidence that this loses nothing is that the final message_end carries the COMPLETE content array (verified on the pi 0.82.1 capture: thinking + text/toolCall, whole), so every message survives in full and only the superseded redraw increments are dropped; and a human watching LIVE is looking at the pane, which is untouched. That made the 'is the stream a human debugging artifact?' question answerable without an operator: it is, and filtering does not damage it. Implementation (cmd/ahub-run/eventfilter.go): a stateful prefix-driven io.Writer wrapping the file, inserted into the MultiWriter's file half. Prefix-driven rather than line-buffering because a single message_update can reach megabytes and buffering one would reintroduce the memory problem this exists to solve — pi writes 'type' as the FIRST key on every event, which is what makes a fixed 24-byte decision window possible. FAILS OPEN: a line is dropped only when its opening bytes positively match the marker, so anything unrecognized, malformed, split oddly or truncated passes through — events.jsonl is where every completion fact comes from (session id, cost, and since ah-tqc the final-turn verdict), so dropping too much costs correctness while dropping too little only costs disk. Write() reports the full input consumed even though fewer bytes reach the sink, because io.MultiWriter treats a short write as io.ErrShortWrite and would abort the tee. Close() flushes an undecided trailing partial line (a SIGKILLed child mid-write) rather than discarding evidence of how the run died. The load-bearing test is chunk-independence: cmd.Stdout hands the filter whatever a pipe read returns, so the marker can arrive split anywhere inside its 24 bytes. The suite replays each stream through EVERY single split point and one byte at a time, plus the fail-open cases (a space after the key, the marker as a longer type's prefix, the word as a later value, garbage/blank lines, lines shorter than the marker) and a 4 MB update line asserting the buffer never grows past the marker length. MEASURED end to end on the real capture, out of band: 166814 → 8212 bytes (20.3x, 4.9% kept), 143 → 20 lines, byte-identical to the same stream filtered by jq. SPEC §9 step 1 records the filter, the fail-open rule and these numbers. Knock-on: this shrinks real streams enough that ah-1cx.14 (the crash-confirmed full parse repeating every poll) stops being a starvation risk in practice, though the O(stream) call is still there. |
| comment | NULL |
| created_at | 2026-08-05T03:06:50Z |
| id | 019fcf42-0bde-7d65-a928-9791e2df1688 |
| issue_id | ah-1cx.15 |
| event_type | label_added |
| actor | Eugene Blikh |
| old_value | NULL |
| new_value | NULL |
| comment | Added label: milestone:v0.1.0 |
| created_at | 2026-08-05T03:10:39Z |
No comments.
Close reason