feat(worker-logs): parser leert het run-log van agent-harness #273

Merged
janpeter merged 5 commits from feat/harness-run-logs into main 2026-09-29 19:30:23 +02:00
Owner

M4 (agent-harness run-logging), Taak 9 / T-40: Worker Logs en Worker Insights leren het run-log van agent-harness lezen, zodat een harness-job er net zo uitziet als een Claude- of Codex-job.

Wat verandert

  • lib/parse-worker-log.ts
    • META_RE herkent naast [run-one-job] ook [harness]; de done-regel accepteert harness done.
    • Nieuwe pushHarnessEvent (vóór pushCodexEvent) zet elk harness.*-type om naar bestaande LogEvent-soorten volgens de mapping in plan §Taak 9: run_start → system-init, turn → thinking/assistant-text/meetregel, tool_call/tool_result → tool-call/tool-result, container → tool-call + tool-result (prepare/gate) of meetregel (run_tests), run_end → result, onbekend harness.* → raw.
    • Een harness-log is pas terminaal bij exit code=; een groeiend bestand blijft running.
    • matchMeta: een JSON-regel is nooit een meta-regel (dicht ook de oudere [run-one-job]-variant van die bug).
    • Container-stappen krijgen een start-tijd (timestamp − durationMs), zodat Worker Insights hun echte duur toont in plaats van 0 ms.
  • test/parse-worker-log.test.ts + fixture test/fixtures/worker-logs/harness-idea-chat.log: de fixture is het echte run-log van een idea-chat-job op max2 (Taak 8, sha256 3db769d9…), met tool-calls, één TOOL_ERROR en een op 8192 tekens afgekapt resultaat. Elke rij van de mapping heeft een test.

Geen wijziging aan ingest, schema, triage of UI; summarizeRunLog en parseRunLog houden hun handtekening.

Verificatie

  • npm run typecheck groen; npm test: alleen de twee bekende macOS-platformbestanden falen (caddy-write-wrapper, db-access-policy-bundle-flow), zoals op main.
  • Claude- en Codex-uitvoer is ongewijzigd: de reviewer vergeleek de parser van main en deze branch op elk prefix van de Claude- en Codex-logs plus randgevallen (2.796 vergelijkingen, 0 verschillen).
  • Elk prefix van de echte fixture leest als running (of idle vóór de job-id) tot het cijfer van exit code= landt; niets gooit.
  • Review: taakreview (1 Important gefixt: JSON-regel als meta-regel gelezen), daarna een whole-branch review op Opus: klaar voor merge, geen Critical/Important. Eén Minor opgewaardeerd en gefixt (container-stappen toonden 0 ms in Worker Insights; 1 test + 7 terugvalrijen), plus twee kleine correcties; scoped re-review schoon.

Uitgesteld (bewust)

  • Een losse CR of U+2028/U+2029 in een foutmelding verbergt de ERROR-regel (errorSummary wordt result: failed). Fix hoort in de writer van agent-harness, mee met de volgende harness-uitrol.
  • UI-cosmetica voor harness-runs (system-init-kaart toont "claude vagent-harness@0.1.0", het "afgekapt"-label bij een tail-afkapping): UI valt buiten M4.

Uitrol

Niet vanzelf: Taak 10 rolt de parser uit op max2 via de ops-agent-flow redeploy_ops_dashboard, op JP's go.

🤖 Generated with Claude Code

M4 (agent-harness run-logging), Taak 9 / T-40: Worker Logs en Worker Insights leren het run-log van agent-harness lezen, zodat een harness-job er net zo uitziet als een Claude- of Codex-job. ## Wat verandert - `lib/parse-worker-log.ts` - `META_RE` herkent naast `[run-one-job]` ook `[harness]`; de done-regel accepteert `harness done`. - Nieuwe `pushHarnessEvent` (vóór `pushCodexEvent`) zet elk `harness.*`-type om naar bestaande LogEvent-soorten volgens de mapping in plan §Taak 9: `run_start` → system-init, `turn` → thinking/assistant-text/meetregel, `tool_call`/`tool_result` → tool-call/tool-result, `container` → tool-call + tool-result (prepare/gate) of meetregel (run_tests), `run_end` → result, onbekend `harness.*` → raw. - Een harness-log is pas terminaal bij `exit code=`; een groeiend bestand blijft `running`. - `matchMeta`: een JSON-regel is nooit een meta-regel (dicht ook de oudere `[run-one-job]`-variant van die bug). - Container-stappen krijgen een start-tijd (`timestamp − durationMs`), zodat Worker Insights hun echte duur toont in plaats van 0 ms. - `test/parse-worker-log.test.ts` + fixture `test/fixtures/worker-logs/harness-idea-chat.log`: de fixture is het echte run-log van een idea-chat-job op max2 (Taak 8, sha256 `3db769d9…`), met tool-calls, één TOOL_ERROR en een op 8192 tekens afgekapt resultaat. Elke rij van de mapping heeft een test. Geen wijziging aan ingest, schema, triage of UI; `summarizeRunLog` en `parseRunLog` houden hun handtekening. ## Verificatie - `npm run typecheck` groen; `npm test`: alleen de twee bekende macOS-platformbestanden falen (`caddy-write-wrapper`, `db-access-policy-bundle-flow`), zoals op main. - Claude- en Codex-uitvoer is ongewijzigd: de reviewer vergeleek de parser van main en deze branch op elk prefix van de Claude- en Codex-logs plus randgevallen (2.796 vergelijkingen, 0 verschillen). - Elk prefix van de echte fixture leest als `running` (of `idle` vóór de job-id) tot het cijfer van `exit code=` landt; niets gooit. - Review: taakreview (1 Important gefixt: JSON-regel als meta-regel gelezen), daarna een whole-branch review op Opus: klaar voor merge, geen Critical/Important. Eén Minor opgewaardeerd en gefixt (container-stappen toonden 0 ms in Worker Insights; 1 test + 7 terugvalrijen), plus twee kleine correcties; scoped re-review schoon. ## Uitgesteld (bewust) - Een losse CR of U+2028/U+2029 in een foutmelding verbergt de ERROR-regel (`errorSummary` wordt `result: failed`). Fix hoort in de writer van agent-harness, mee met de volgende harness-uitrol. - UI-cosmetica voor harness-runs (system-init-kaart toont "claude vagent-harness@0.1.0", het "afgekapt"-label bij een tail-afkapping): UI valt buiten M4. ## Uitrol Niet vanzelf: Taak 10 rolt de parser uit op max2 via de ops-agent-flow `redeploy_ops_dashboard`, op JP's go. 🤖 Generated with [Claude Code](https://claude.com/claude-code)
Derde logformaat naast Claude en Codex (agent-harness M4, spec §5 en §7):
- META_RE kent naast [run-one-job] ook [harness]; de tag markeert een harness-log
- `harness done` telt als claude-done, in classifyMeta en summarizeRunLog
- een harness-log is alleen afgesloten bij `exit code=`: harness.run_end en de
  ERROR-regel sluiten hem niet af; de regel voor Claude en Codex blijft gelden
- pushHarnessEvent zet de harness.*-regels om naar dezelfde eventsoorten als
  Claude en Codex; toolargumenten die geen JSON-object zijn worden
  {"arguments": ...}, zodat de ingest ze als JSON-waarde kan opslaan
- fixture: echte idee-chat-run op max2 (test/fixtures/worker-logs)

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
META_RE draait over de ruwe regel en `\S+` stopt bij de eerste witruimte, die in
compacte JSON binnen een stringwaarde ligt. Een tool-result dat met een
run-log-regel begint (`<tijd> [harness] claimed job_id=...`) werd daardoor als
meta-regel gelezen: jobId werd de rest van de JSON-regel, een Claude-log werd een
harness-log (en bleef `running` zonder `exit code=`), en het tool-result verdween.

matchMeta() weigert een eerste token dat met `{` begint (een meta-regel begint
altijd met een tijd) en wordt op beide plekken gebruikt, in summarizeRunLog en
parseRunLog. META_RE zelf is ongewijzigd.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
De schrijver (agent-harness src/run.ts) traceert eerst het container-event van de
gate en pas daarna after_answer. TASK_JOB_OPEN had die twee regels omgekeerd, bij
beide gates; de volgorde is nu die van de schrijver en de tijdstippen lopen niet
terug. De parser is volgorde-onafhankelijk, dus geen verwachting verandert.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
De harness.container-regel wordt geschreven als de container klaar is, dus zijn
timestamp is het einde van de stap. Tool-call en tool-result kregen daardoor
dezelfde tijd, en Worker Insights (tool-result ts - tool-call ts) toonde voor
container:verify/gate en container:prepare/prepare 0 ms, ook bij een gate van 42 s.

De tool-call krijgt nu timestamp - durationMs; het tool-result houdt de regeltijd.
Zonder bruikbare duur (ontbreekt, niet eindig, negatief of van voor 1970) of met
een timestamp die geen datum is blijft de regeltijd staan en gooit niets.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
docs(worker-logs): bestandskop en samenvattingscommentaar van de parser bijgewerkt
All checks were successful
CI / Select checks (pull_request) Successful in 38s
CI / Ops-agent checks (pull_request) Successful in 39s
CI / DB access operator (pull_request) Successful in 1m20s
CI / Deploy artifact checks (pull_request) Successful in 38s
CI / Docker image build (pull_request) Successful in 1m22s
CI / Mac foundation hermetic checks (pull_request) Successful in 2m21s
CI / Root app checks (pull_request) Successful in 8m41s
CI / Required checks (pull_request) Successful in 39s
6a1a1b7ed6
De kop noemde alleen Claude stream-json; de parser leest ook Codex en agent-harness.
De doc-comment van summarizeRunLog beloofde hooguit een JSON.parse (de result-regel);
het is de regel die een run afsluit: de eerste Claude-result of harness.run_end.
Alleen commentaar, geen gedragswijziging.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
s4m-codex-reviewer left a comment

Verdict: REQUEST_CHANGES

Findings

  • medium — lib/parse-worker-log.ts:559: bij een harness.tool_result met zowel errorCode als contentLength wordt fullLength overgenomen uit contentLength, terwijl body eerst de prefix [<errorCode>] krijgt. Daardoor kan fullLength kleiner zijn dan de weergegeven/opgeslagen body (zoals de fixture met TOOL_ERROR); de UI en ingest tonen dan foutieve lengte-/truncatiemetadata. Tel de prefix bij de gedeclareerde lengte op (of sla de onbewerkte foutcode apart op) en voeg een test toe voor de combinatie errorCode + contentLength.

Geen gekoppeld plan gevonden — beoordeeld op codekwaliteit + product-standaarden.

## Verdict: REQUEST_CHANGES ### Findings - **medium** — `lib/parse-worker-log.ts:559`: bij een `harness.tool_result` met zowel `errorCode` als `contentLength` wordt `fullLength` overgenomen uit `contentLength`, terwijl `body` eerst de prefix `[<errorCode>] ` krijgt. Daardoor kan `fullLength` kleiner zijn dan de weergegeven/opgeslagen body (zoals de fixture met `TOOL_ERROR`); de UI en ingest tonen dan foutieve lengte-/truncatiemetadata. Tel de prefix bij de gedeclareerde lengte op (of sla de onbewerkte foutcode apart op) en voeg een test toe voor de combinatie `errorCode + contentLength`. Geen gekoppeld plan gevonden — beoordeeld op codekwaliteit + product-standaarden.
Author
Owner

Reactie op review 856 (fullLength bij harness.tool_result met errorCode + contentLength):

Niet overgenomen zoals voorgesteld. Spec §5.4 (agent-harness docs/specs/2026-09-28-harness-run-logging-design.md, rij harness.tool_result) legt vast: fullLength = contentLength, de lengte van de volledige tooluitvoer. De tag [<errorCode>] is een annotatie van de parser, geen tooluitvoer. Dat fullLength bij een foutresultaat kleiner is dan de getoonde body, is dus bedoeld: in de fixture 71 tekens uitvoer, 84 met de tag.

  • De truncatie-metadata klopt: truncated vergelijkt contentLength met de content zónder tag.
  • Niets leidt iets af uit fullLength versus de body: beide UI's tonen "N chars" en "afgekapt (N chars totaal)", en ingest slaat de waarde alleen op.
  • De combinatie errorCode + contentLength zat al in de fixture-test (call_uwrob4gs: fullLength 71, body met tag).

Wel gefixt, de omgekeerde inconsistentie (7d1dcceed): zonder contentLength telde de terugval de tag wél mee (17 voor [TOOL_ERROR] boom). De terugval is nu ook de lengte van de content, dus fullLength betekent op beide paden de lengte van de tooluitvoer. Er is ook een inline test bij voor errorCode + contentLength, niet afgekapt en door de writer afgekapt.

🤖 Generated with Claude Code

Reactie op review 856 (`fullLength` bij `harness.tool_result` met `errorCode` + `contentLength`): **Niet overgenomen zoals voorgesteld.** Spec §5.4 (agent-harness `docs/specs/2026-09-28-harness-run-logging-design.md`, rij `harness.tool_result`) legt vast: `fullLength = contentLength`, de lengte van de volledige tooluitvoer. De tag `[<errorCode>] ` is een annotatie van de parser, geen tooluitvoer. Dat `fullLength` bij een foutresultaat kleiner is dan de getoonde body, is dus bedoeld: in de fixture 71 tekens uitvoer, 84 met de tag. - De truncatie-metadata klopt: `truncated` vergelijkt `contentLength` met de content zónder tag. - Niets leidt iets af uit `fullLength` versus de body: beide UI's tonen "N chars" en "afgekapt (N chars totaal)", en ingest slaat de waarde alleen op. - De combinatie `errorCode` + `contentLength` zat al in de fixture-test (`call_uwrob4gs`: `fullLength` 71, body met tag). **Wel gefixt, de omgekeerde inconsistentie** (7d1dcceed): zonder `contentLength` telde de terugval de tag wél mee (17 voor `[TOOL_ERROR] boom`). De terugval is nu ook de lengte van de content, dus `fullLength` betekent op beide paden de lengte van de tooluitvoer. Er is ook een inline test bij voor `errorCode` + `contentLength`, niet afgekapt en door de writer afgekapt. 🤖 Generated with [Claude Code](https://claude.com/claude-code)
Sign in to join this conversation.
No reviewers
No milestone
No project
No assignees
2 participants
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
janpeter/Ops-dashboard!273
No description provided.