Skip to content

Bridge recorder response-path fix: worker evidence

Task: d5f04d8e-81cc-4f93-8885-82b8429b4bfa, frozen version 9. Execution: 6a0f5f92-0dc3-458d-8b31-6c5e0b54cb80, 2026-10-12. Repository: h8v6/heyaira; branch: heyaira/d5f04d8e. Source and starting base: 2f7eaf98fe3dedbefaba6e5b6ed5898f83c26923. The result commit SHA is recorded in the execution's RESULT/receipt. Lead model: gpt-6.1-sol; subagents: none. This is worker evidence; independent acceptance belongs to Bridge's verifier.

Cause and implementation

The original observer awaited wait_for(record(), timeout=1) in its ASGI finally. Although the response body had already been sent, the application call waited for cancellation and the pool's connection release. ASGITransport therefore did not return the response until cleanup finished.

Recording now runs in a module-held task set, limited to 32 admitted records. Admission is synchronous; overflow and closed admission log only a type. Acquisition and queries have one-second asyncpg timeouts. A shared two-second deadline starts before acquisition and identity lookup. The recorder retains its admission slot through the pool's shielded release, even if the deadline fires during release. Lifespan stops admission and cancels/drains the set with asyncio.wait(..., timeout=2) before pool closure, warning on unfinished work. Existing observer tests explicitly drain before checking records and before patches/fixtures are torn down. Pickup logic, schema and retention are unchanged.

The migration rename applies to fresh databases only; the earlier Bridge failure migration was never deployed. No history transition was added.

Execution environment

Commands ran in the supplied worker worktree unless the baseline snapshot is specified below. Tests used Python 3.12, asyncpg 0.31.0, real ASGI calls and the prepared local PostgreSQL Unix socket. The harness created and dropped only its randomly named disposable databases. No DSN or credentials are recorded. TMPDIR="$PWD/.task-tmp" kept harness temporary files inside the workspace. No installation, push, PR, merge, deployment or production mutation was run.

Initial Git reads found a clean tree, origin [email protected]:h8v6/heyaira.git, branch heyaira/d5f04d8e, and HEAD equal to the source above, whose parent was 7b4efed323e84558279ad67f14257eaa7bab5938. Login-shell startup initially hit Xcode cache permission errors; non-login shells used the supplied Bridge Git executable. Git also warned that the optional user ignore file was unreadable; the scoped Git operations completed. No unresolved execution blocker remains.

K1: ASGI completion, including delayed cancellation cleanup

The test simulates a stalled INSERT and a two-second cancellation reset on the real asyncpg PoolConnectionHolder.release -> Connection.reset path. It measures response-body emission separately from ASGITransport return, asserts unchanged 401/body, and drains outside the timing measurement.

First, before implementation, on the source commit with only the new test added:

TMPDIR="$PWD/.task-tmp" python scripts/test_postgres.py tests/test_bridge_failure_background.py::test_asgi_call_finishes_before_delayed_cancellation_cleanup -s -p no:cacheprovider

Actual result: exit 1, 1 failed in 19.65s. response_emission_seconds=0.001 asgi_completion_seconds=3.007. Failure: assert elapsed <= 0.5, actual 3.007064999997965. An earlier collection attempt exited 1 with fixture 'pickup' not found; the explicit fixture import was added before the reproduction above.

After implementation:

TMPDIR="$PWD/.task-tmp" python scripts/test_postgres.py tests/test_bridge_failure_background.py -s -p no:cacheprovider

Actual result: exit 0, 4 passed in 16.03s, zero skipped tests. response_emission_seconds=0.002 asgi_completion_seconds=0.003.

The final version of the test was also copied into an isolated source snapshot, without changing the worker branch or rewriting history:

mkdir -p .task-tmp/base
DEVELOPER_DIR=/Library/Developer/CommandLineTools git archive 2f7eaf98 src migrations tests scripts pyproject.toml | tar -x -C .task-tmp/base
cp tests/test_bridge_failure_background.py .task-tmp/base/tests/test_bridge_failure_background.py
TMPDIR="$PWD/.task-tmp" python .task-tmp/base/scripts/test_postgres.py tests/test_bridge_failure_background.py::test_asgi_call_finishes_before_delayed_cancellation_cleanup -s -p no:cacheprovider

Actual result: exit 1, 1 failed in 29.55s. response_emission_seconds=0.024 asgi_completion_seconds=3.028. Failure: assert elapsed <= 0.5, actual 3.028390125000442. The harness ran pytest in the snapshot root with that snapshot's src on PYTHONPATH. The final worker tree passes this same test in the K4 run below.

criterion_id: K1 outcome: pass evidence_path: docs/reports/d5f04d8e-bridge-recorder-evidence.md feedback: Source T1 exits 1 at 3.028 s; fixed T1 exits 0, with 0.003 s ASGI completion in the focused run and unchanged status/body.

K2 and K3: capacity, release accounting and lifespan

Focused rerun after adapting the existing acquisition-stall test:

TMPDIR="$PWD/.task-tmp" python scripts/test_postgres.py 'tests/test_bridge_request_failures.py::test_record_deadline_preserves_response[acquire-stall]' tests/test_bridge_failure_background.py -s -p no:cacheprovider

Actual result: exit 0, 6 passed in 52.59s; postgres_acceptance=passed: selected tests, zero skipped tests. Output:

response_emission_seconds=0.001 asgi_completion_seconds=0.001
admitted=32 dropped=8 responses_unchanged=40 recovery_admitted=1
shutdown_drain_seconds=2.004 close_after_cancel=True admission_closed=True

T2 uses the database-independent retired endpoint's 410 response and stalls only recorder acquisition. It synchronizes all 32 admitted tasks and checks eight capacity warnings and all 40 response timings/statuses/bodies. After the gate clears, real acquisition/INSERT/release finish and the pool is idle; the next request is admitted. Final assertions additionally verify exactly 32 then 33 durable rows (included in the passing K4 run).

A separate release regression raises a simulated query timeout, holds reset past the shared deadline and asserts the parent recorder remains in the set and the pool connection remains checked out until reset completes. The identity regression delays acquisition and lookup before stalling INSERT, verifying one shared two-second budget and explicit per-operation timeout arguments.

The shutdown regression drives the real MCP lifespan with a synthetic pool and delayed cancellation cleanup. It verifies cancel precedes pool.close, the two-second fallback returns with a warning and retained task reference, and subsequent admission is refused. Its test finally releases/drains cleanup.

criterion_id: K2 outcome: pass evidence_path: tests/test_bridge_failure_background.py feedback: Focused tests and final K4 suite pass; exactly 32 admitted, 8 dropped, 40 unchanged timely responses, pool/slot recovery and the next durable record asserted.

criterion_id: K3 outcome: pass evidence_path: tests/test_bridge_failure_background.py feedback: Lifespan regression passes; admission stops, cancellation starts, bounded drain warns after 2.004 s and precedes pool.close.

K4: original task's test files plus new regressions

TMPDIR="$PWD/.task-tmp" python scripts/test_postgres.py tests/test_bridge_request_failures.py tests/test_bridge_pickup.py tests/test_server_beat.py tests/test_server_beat_timing.py tests/test_bridge_failure_background.py -p no:cacheprovider

First run: exit 1, 1 failed, 44 passed in 72.15s. The existing acquisition stall test's inspect.stack() instrumentation ran in authentication as well as recording and made its response take 0.9407230829965556 s. Replacing that inspection with recorder task-set membership preserved recorder-only stalling. The focused rerun above passed. The identity deadline regression and durable T2 row-count assertions were then included in the final full selection.

Final result: exit 0, 46 passed in 84.10s (0:01:24); postgres_acceptance=passed: selected tests, zero skipped tests.

criterion_id: K4 outcome: pass evidence_path: docs/reports/d5f04d8e-bridge-recorder-evidence.md feedback: Required PostgreSQL selection exits 0 with 46 passed, zero skipped; explicit drain keeps patches and database fixtures alive through recording.

K5: scope and history

Intended changes are restricted to:

  • src/heyaira/bridge_request_failures.py
  • three lifespan-hook lines in src/heyaira/server.py
  • tests/test_bridge_request_failures.py
  • tests/test_bridge_failure_background.py
  • docs/operations/bridge-request-failures.md
  • docs/reports/df574214-bridge-stall-evidence.md (migration references)
  • this evidence file
  • the byte-identical migration rename from 059 to 061

git diff --check exits 0. A byte comparison of the migration from the source commit against migrations/061_bridge_request_failures.sql prints migration_content_unchanged True. A reference search finds no remaining old migration reference in runtime code, tests or operational documentation. Source ancestry is retained; all changes are committed on top of the source. The final git diff --name-only 2f7eaf98..HEAD and git merge-base --is-ancestor 2f7eaf98 HEAD are checked after local commit, with their actual output and result SHA recorded in RESULT/receipt.

criterion_id: K5 outcome: pass evidence_path: docs/reports/d5f04d8e-bridge-recorder-evidence.md feedback: Only the allowed recorder, minimal server hookup, tests, docs and byte-identical migration rename are staged; source ancestry is preserved and rechecked on the result commit.

Unrun checks and next step

tests/test_schema_guard.py is intentionally excluded by frozen K4: numbering becomes contiguous only after main/PR #226 are merged, which the coordinator checks at merge. The repository-wide suite, independent verification and production behavior were not tested by this worker. There were zero skips in the required selected run. Next: Bridge independently verifies this local candidate and handles any authorized publication. No task status or acceptance was changed by the worker.