fix(witan-code): report a failed bridge write instead of swallowing it - #288
Merged
Conversation
The cross-repo bridge write on production wedged for ~15 hours today and
nothing anywhere said so. Every CI cycle logged the failure, printed
`bindings=0 errors=0`, exited 0, and raised no Sentry issue. It surfaced only
because someone went looking for an unrelated feature and hit the same barrier.
Two independent reasons it was invisible, both fixed here.
THE LEVEL WAS THE MECHANISM. configure_sentry installs
LoggingIntegration(event_level=ERROR) precisely so a call site needs no
capture_exception — its own docstring says the many exc_info=True calls at
DEBUG/INFO/WARNING are "expected, already-handled failures ... breadcrumbs, not
Sentry issues". So logging the bridge failure at warning was a declaration that
a throwing bridge write is expected and handled. It is neither. It logs at
error now, which is all Sentry needs. Proven end to end against a recording
transport rather than argued: warning produces 0 events, error produces 1
carrying the RuntimeError and its stack.
SENTRY WAS NEVER INITIALISED ON THAT PATH ANYWAY. configure_observability() was
called only by `serve`, and the CI indexer runs `witan code index` — so no
amount of level correctness at the call site could have reported anything. It
now runs in the CLI's meta launcher, for every command. instrument=False keeps
the OTel auto-instrumentors out of a short-lived CLI, and everything there
no-ops without its env var, so a developer with no SENTRY_DSN pays nothing.
The failure is also counted (stats.errors) and flagged (stats.bridge_failed,
rendered as `bridge=FAILED`). `bindings=0` meant both "nothing to write" and
"the write threw", and the summary line is the only thing most people read.
Not made fatal: the per-repo half genuinely succeeds and is worth keeping.
"Non-fatal" and "unreported" are different claims and this only ever meant the
first.
── one witan-core fix this forced out ──
Adding configure_observability() to the launcher broke test_github_app.py, and
the cause was a real latent bug rather than a test artifact: configure_logging
built its handler as StreamHandler(sys.stderr), capturing the stream object
once per process. The module already documents this exact hazard for its
unconfigured fallback and solves it there with _LateBoundStderr — the
configured path had the same bug and kept it, because nothing configured
logging early enough for it to show. Anything rebinding sys.stderr afterwards
(capsys, redirect_stderr, a CLI swapping the stream) left every later log line
going somewhere nobody reads. Now late-bound on both paths.
Tests assert the level explicitly, and were verified to FAIL against the old
behaviour ("logged at 'warning'; Sentry's event_level is ERROR") rather than
merely passing against the new one.
2405 tests pass across the workspace.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01RH7kCwSp8TbKQLZ7kbVnY1
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01RH7kCwSp8TbKQLZ7kbVnY1
Contributor
There was a problem hiding this comment.
Pull request overview
This PR aims to make cross-repository bridge-write failures observable without discarding successful per-repository indexing.
Changes:
- Counts and logs bridge failures at error level.
- Adds
bridge=FAILEDto CLI summaries. - Late-binds configured logging to current
sys.stderr.
Reviewed changes
Copilot reviewed 6 out of 6 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
packages/witan-core/witan_core/observability/logging.py |
Late-binds stderr logging. |
packages/witan-core/CHANGELOG.md |
Documents stderr fix. |
mcp/servers/witan-code/witan_code/indexer.py |
Records and reports bridge failures. |
mcp/servers/witan-code/witan_code/cli.py |
Displays bridge status and initializes observability. |
mcp/servers/witan-code/tests/test_indexer.py |
Tests bridge failure reporting. |
mcp/servers/witan-code/CHANGELOG.md |
Documents failure-reporting changes. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
Review catch on #288, and it invalidated the fix as shipped. `witan code …` mounts witan_code's cyclopts App via `app.command(_code_app, name="code")` — the App, not its meta launcher. So dispatch runs through witan's own `_launcher` and witan-code's never executes. The CI indexer runs `witan code index .` (docker/witan-ci-index.sh:197), which means configuring observability only in witan-code's launcher covered the standalone binary nobody deploys and missed the one command the incident actually came from. The output-format forwarding right below the new call is the tell: it exists precisely because witan-code's launcher, which sets that itself, is bypassed. Both launchers configure it now. Idempotent, and no-ops without the env vars. Also adds the two regression tests review asked for, and both were verified to FAIL against the code they guard rather than merely to pass against the fix: test_the_umbrella_launcher_configures_observability - "the umbrella launcher did not configure observability" test_the_configured_handler_follows_a_rebound_stderr - "the handler wrote to the stderr captured at configure time" The second is the one review was right to insist on: the existing observability tests configure logging AFTER capsys is already in place, so they pass against the old StreamHandler(sys.stderr) too. Order is the whole test — configure first, rebind second — and the order-dependent cross-test failure that first surfaced this was never a stable guard. One self-inflicted bug found while checking that: the new test module used `pytest.importorskip` inside a `skipif` decorator, which is evaluated at COLLECTION and skipped the entire module — silently taking the two umbrella tests with it and reporting "1 skipped" as though it had run. Replaced with a plain try/except guard. 2408 tests pass across the workspace. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01RH7kCwSp8TbKQLZ7kbVnY1
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What are the relevant tickets?
tk-ci-indexer-reports-errors-0-while-its-bridge-wri-3e2f7a(p1). Fallout fromtk-production-code-bridge-graph-is-wedged-on-a-pend-8318a4(p0), which is now cleared.Description (What does it do?)
The production cross-repo bridge wedged on 2026-08-25 and nothing anywhere said so. Every CI cycle logged the failure, printed
bindings=0 errors=0, exited 0, and raised no Sentry issue. The binding data was frozen from 04:01 UTC until the barrier cleared at ~19:10 — about 15 hours — and it surfaced only because someone went looking for an unrelated feature and hit the same barrier head-on.Two independent reasons it was invisible. Both had to be fixed; either alone would have kept it silent.
1. The level was the mechanism
configure_sentryinstallsLoggingIntegration(event_level=ERROR)specifically so a call site needs nocapture_exception. Its own docstring is explicit that the manyexc_info=Truecalls at DEBUG/INFO/WARNING are "expected, already-handled failures … breadcrumbs, not Sentry issues".So logging the bridge failure at
warningwas a declaration that a throwing bridge write is expected and handled. It is neither. It logs aterrornow, which is all Sentry needs.Verified end to end rather than argued —
sentry_sdkinitialised with a recording transport, the realconfigure_loggingpipeline, the same integration config:2. Sentry was never initialised on that path anyway
configure_observability()was called only byserve. The CI indexer runswitan code index, so it had no Sentry client at all — no amount of level correctness at the call site could have reported anything.It now runs in the CLI's meta launcher, for every command.
instrument=Falsekeeps the OTel auto-instrumentors out of a short-lived CLI, and everything there no-ops without its env var, so a developer with noSENTRY_DSNpays nothing.3. The summary line stops lying
The failure is counted (
stats.errors) and flagged (stats.bridge_failed, renderedbridge=FAILED).bindings=0previously meant both "nothing to write" and "the write threw", and that one line is the only thing most people read.Deliberately still non-fatal. The per-repo index genuinely succeeds and is worth keeping. But "non-fatal" and "unreported" are different claims, and this only ever meant the first.
How can this be tested?
2405 pass across the workspace (1 / 308 / 580 / 532 / 984).
just check-versions,just check-core-floorand prek all clean — no floor bump needed, since no newwitan_coresymbol is imported.The new tests were verified to fail against the old behaviour, not merely to pass against the new one — I reinstated the
warningcall and re-ran:The level assertion is deliberately explicit rather than incidental, because the level is the Sentry trigger and a future refactor lowering it would otherwise silently re-break this.
Additional Context
One witan-core fix this forced out, and it was a real latent bug rather than a test artifact. Adding
configure_observability()to the launcher broketest_github_app.py— passing in isolation, failing in the full run. Cause:configure_loggingbuiltlogging.StreamHandler(sys.stderr), capturing the stream object once per process. Anything rebindingsys.stderrafterwards (capsys,redirect_stderr, a CLI swapping the stream) left every later log line going somewhere nobody reads.The module already documents this exact hazard for its unconfigured fallback and solves it there with
_LateBoundStderr. The configured path had the same bug and kept it, because nothing configured logging early enough for it to show. Both paths late-bind now.What this does not do: alerting on
bindings=0across a whole cycle, and root-causing the ~3-4 day recurrence of the wedge itself. Both are follow-ups on the p0 task. This change is what makes the next occurrence visible; it does not stop it happening.