Skip to content

fix(test): make httpapi-exercise 500s carry their cause (TKT-372, fb 183) - #60

Open
sepo-eng wants to merge 1 commit into
devfrom
fix/tkt-372-harness-diagnosability
Open

fix(test): make httpapi-exercise 500s carry their cause (TKT-372, fb 183)#60
sepo-eng wants to merge 1 commit into
devfrom
fix/tkt-372-harness-diagnosability

Conversation

@sepo-eng

Copy link
Copy Markdown

First item of TKT-372, which orders 183 first (diagnosability unblocks the rest).

The reported problem is real; its stated cause is not

An effect-mode failure gave you {"name":"UnknownError","ref":"err_xxxxxxxx"} and nothing else, anywhere. Feedback 183 pinned that on backend.ts:79's { disableLogger: true }.

I tested that before implementing it, and it is wrong. disableLogger only controls whether HttpMiddleware.logger — the per-request access log — is composed in. Building the same dying route both ways prints the middleware's Effect.logError in both arms:

ARM disableLogger=true   -> ERROR failed { ref, error, cause: "..." }   <- still logged
ARM disableLogger=false  -> ERROR failed { ref, error, cause: "..." }
                            INFO  Sent HTTP response { ... }            <- the only difference

Had I implemented the suggested fix, it would have merged looking correct and changed nothing.

The actual suppressor

packages/core/src/observability.ts builds logging as Logger.layer([...Logging.loggers()], { mergeWithExisting: false }) — it replaces the console logger — and Logging.loggers() returns the file logger alone unless OPENCODE_PRINT_LOGS === "1". The Cause was never discarded; it was written to opencode.log while the harness printed an opaque ref.

The fix

Default OPENCODE_PRINT_LOGS=1 and OPENCODE_LOG_LEVEL=ERROR in the exerciser's environment.ts, alongside the OPENCODE_DB and XDG isolation that already has to happen before the app modules load. Both are ??=, so an explicit value still wins.

Error level only, so this adds one line per defect and nothing else.

Verified against a real failure

Forcing a route to die (throw in the global.health handler):

  • With the default — the failure prints the full Cause with file and line, and the logged ref=err_a8d0807b matches the ref in the 500 body, so a failure correlates to its cause:
    level=ERROR message=failed ref=err_a8d0807b error="Error: PROBE_DEFECT_MARKER: ..."
      cause="... at GlobalHttpApi.health (handlers/global.ts:75:17)"
    FAIL GET /global/health   global.health
      Error: expected 200, got 500: {"name":"UnknownError",...,"ref":"err_a8d0807b"}
    
  • Control, OPENCODE_PRINT_LOGS=0 — reproduces the reported symptom exactly: the FAIL line, the opaque ref, no cause.

(First attempt at this probe patched /global/health while running the /api/health scenario, so the arm proved nothing and the route passed. Reported here because the corrected pairing is what the evidence above rests on.)

All three modes green: 237/237 pass, 0 fail each for coverage, auth, and effect.

Noise, measured rather than promised

A green effect-mode run adds exactly four ERROR lines, all from integration scenarios that deliberately assert 500:

Scenario Logged error
v2.integration.connect.key Key method not found: missing
v2.integration.connect.oauth OAuth method not found: missing/missing
v2.integration.attempt.status OAuth attempt not found: con_missing
v2.integration.attempt.complete OAuth attempt not found: con_missing

Those four routes raise plain Errors instead of returning a typed 404, which is why they land in the defect path at all. This change makes that visible; it does not cause it, and it is out of scope here.

Not in this PR

The rest of TKT-372 (146, 147, 189, 190, and verifying whether 146/147 explain 145/151) — the ticket stages 183 first deliberately. One finding for whoever takes the next slice: feedback 146's suggested remedy is now known-harmful. It proposes per-scenario fresh memoMaps, but TKT-349 moved runtime.ts the opposite way, onto the shared production MemoMap, because a fresh Layer.makeMemoMapUnsafe() there split a process singleton in two (runtime.ts:25-32 records it first-hand). The masking concern 146 raises is still real; that particular fix for it is not available.

🤖 Generated with Claude Code

https://claude.ai/code/session_01KbNYZHcnxRCknFmhhPHe7L

…183)

An effect-mode failure reported {"name":"UnknownError","ref":"err_xxxxxxxx"} and
nothing else. On TKT-323 that turned a one-glance answer -- Unbound layer node:
@opencode/InstanceBootstrap -- into a dedicated diagnosis assignment.

The cause was never lost. The error middleware already logs it via
Effect.logError, and feedback 183 attributed the loss to backend.ts's
disableLogger:true. That attribution is wrong: disableLogger only skips adding
HttpMiddleware.logger, the per-request access log. Built both ways against the
same dying route, the Cause prints either way.

The actual suppressor is core's observability layer, which builds with
Logger.layer(..., { mergeWithExisting: false }) over Logging.loggers() -- and
loggers() returns the file logger alone unless OPENCODE_PRINT_LOGS is set. So the
Cause went to opencode.log while the harness printed an opaque ref.

The exerciser now defaults OPENCODE_PRINT_LOGS=1 and OPENCODE_LOG_LEVEL=ERROR
where it already isolates OPENCODE_DB and the XDG roots, before the app modules
load. Errors only: a green run adds four lines, from the integration scenarios
that deliberately assert 500, and the logged ref matches the ref in the response
body so a failure correlates to its cause.

Verified against a deliberately broken route: with the default the failure prints
the full Cause with file and line; with OPENCODE_PRINT_LOGS=0 the same failure
reproduces the reported symptom exactly. All three modes stay green, 237/237.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KbNYZHcnxRCknFmhhPHe7L
Copilot AI lite review requested due to automatic review settings August 13, 2026 14:24

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@github-actions

Copy link
Copy Markdown

Thanks for your contribution!

This PR doesn't have a linked issue. All PRs must reference an existing issue.

Please:

  1. Open an issue describing the bug/feature (if one doesn't exist)
  2. Add Fixes #<number> or Closes #<number> to this PR description

See CONTRIBUTING.md for details.

@github-actions

Copy link
Copy Markdown

This PR doesn't fully meet our contributing guidelines and PR template.

What needs to be fixed:

  • PR description is missing required template sections. Please use the PR template.

Please edit this PR description to address the above within 2 hours, or it will be automatically closed.

If you believe this was flagged incorrectly, please let a maintainer know.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants