Skip to content

fix(sandbox): keep timeout teardown from erasing the timeout - #1081

Open
tulerfeng wants to merge 1 commit into
benchflow-ai:mainfrom
tulerfeng:fix/1065-guard-process-teardown
Open

fix(sandbox): keep timeout teardown from erasing the timeout#1081
tulerfeng wants to merge 1 commit into
benchflow-ai:mainfrom
tulerfeng:fix/1065-guard-process-teardown

Conversation

@tulerfeng

@tulerfeng tulerfeng commented Aug 31, 2026

Copy link
Copy Markdown

Summary

Fixes #1065.

When a sandbox exec runs out of time, the code kills the child and then raises "Command timed out after N seconds". But killing a child that has already finished raises ProcessLookupError, and that escapes the handler before the timeout message is ever raised. ProcessLookupError carries no text at all, so f"verifier crashed: {e}" renders as verifier crashed: with nothing after the colon — a finished rollout scored rewards: null under a message that names neither the failure nor the fact that it had no detail.

This PR makes teardown tolerate a child that is already gone, in every place that signals one, and stops the verifier error from ever rendering empty.

Why this happens, precisely

The report says the race needs the child to have exited and been reaped. That is the right shape, but the window turned out to be narrower, and finding the exact edge is what made it reproducible.

terminate() only fails if asyncio has cleared its handle on the process. That clearing happens in _call_connection_lost, which asyncio schedules with call_soon — so it runs on the next loop tick after the child exits. The failure therefore needs the timeout to fire in the gap between that callback and communicate() returning. One tick wide.

That detail matters because it says who is affected. On an idle loop those two events land practically on top of each other. On a loop that is busy — many concurrent rollouts, which is exactly the --concurrency 16 setup in the report — callbacks spread out, the gap opens, and the failure stops being occasional.

I measured both ends:

event loop attempts timeouts destroyed
idle 840 0
under load 288 288

Same code, same machine. Under load it is not a rare race; it is the normal outcome. That is consistent with a batch hitting it repeatedly rather than once.

What the fix covers

The issue names two spots in docker.py. Auditing every process-signalling site turned up three more with the same defect, so the PR fixes all of them.

The audit had a clean dividing line. CPython's subprocess.Popen.send_signal already handles this race for us — it polls first, skips a process it knows has died, and swallows ProcessLookupError anyway (bpo-38630, bpo-40550). asyncio.subprocess.Process has no such guard and raises straight out. So every synchronous call site in the repo was already safe, and only the asyncio ones needed anything. That is what bounds this change to five places instead of sixteen.

where what was wrong
docker.py — compose exec the two spots from the report; both teardowns now share one helper
docker.py — pre-compose hook same sequence, duplicated
acp/transport.pyclose() no liveness check at all, while SubprocessLiveProcess.close() next door has one and documents itself as "safe to call after process death"
process/apple.py, apple_container.py kill() replaces the TimeoutError being re-raised
process/_base.pyclose() its returncode check cannot cover the escalation branch, because the grace period is an await and the child can exit across it

The acp/transport.py one is the one I would flag. close() runs during teardown, usually while another exception is already in flight — so an exception raised there replaces the real failure with an empty one.

The empty message

The issue suggests f"verifier crashed: {type(e).__name__}: {e}". I went a slightly different way, because the repo already solved this.

_utils/text.py has describe_exception, written for exactly this problem, and the agent-side error funnel in rollout/__init__.py already uses it with a comment explaining why:

describe_exception, not str(e): this is the funnel every unclassified rollout failure lands in, and some SDK errors stringify to a bare wrapper prefix with no detail behind it. Persisting those raw leaves an artifact that names neither what failed nor that the detail was empty.

That reasoning applies word for word to the verifier path, which was simply missed. So rather than introduce a fourth way of rendering an exception, the three verifier sites now use the existing one. verifier crashed: becomes verifier crashed: ProcessLookupError (no message).

I checked this cannot disturb error classification: classify_verifier_error matches substrings, but every marker contains a space or punctuation, so a CamelCase class name can never match one.

Tests

New file, tests/test_timeout_teardown_reaped_child.py, 11 tests.

They do not mock the failure. Each one spawns a real child, lets it exit, and lets asyncio reap it, so the ProcessLookupError is raised by the operating system through asyncio's own transport rather than by a fixture pretending to. What is controlled is the timing: communicate raises TimeoutError instead of sleeping, which turns a one-tick race into something that reproduces on every run and finishes in two seconds.

Running them against the unmodified tree and against this one:

tree result
main (before) 8 failed, 3 passed
this PR 11 passed

The three that pass on both sides are deliberate controls, and I would rather have them than a suite that is green only because the new code exists:

  • signalling a reaped child raises an error whose args are empty — the premise
  • describe_exception(ProcessLookupError()) names the type — the tool already worked
  • SubprocessLiveProcess.close() survives a dead child — the neighbour that already had the guard, now pinned so it cannot quietly lose it

One test drives the real _verify_rollout with harden_before_verify raising ProcessLookupError — the exact path in the report — and asserts the recorded string is verifier crashed: ProcessLookupError (no message) and does not end at a colon.

End-to-end verification

A real container, both trees. I took a real running container, spawned the same docker compose exec the sandbox builds, and ran each tree's teardown against that live process:

tree what the caller gets what gets recorded
main (before) ProcessLookupError (args=()) 'verifier crashed: '
this PR RuntimeError: Command timed out after 10 seconds 'verifier crashed: Command timed out after 10 seconds'

The main row is the symptom string from the report, reproduced against a real container rather than argued from the source.

Honest limit on that one. In that experiment I forced the one condition the race normally leaves to chance — that the child had already finished. Everything else (container, compose invocation, process, exception) is real, but I want to be clear that I did not sit and wait for a real bench eval run to hit this on its own. I tried: 164 real exec calls with the budget swept across the completion point, zero natural hits, because docker exec's own timing jitter is far wider than the one-tick window. The 288/288 result above is the natural, unforced reproduction, and it is at the asyncio layer.

Normal runs are unaffected. A full bench eval run (hello-world, oracle agent, docker sandbox) passes 1/1 with mean reward 1.00.

No regressions. Full suite: 5931 passed. 11 failures, all in tests/test_cli_live_progress.py, and that file fails identically on main (11 failed / 54 passed on both). ruff check and ruff format --check are clean.

Signalling a child that asyncio has already reaped raises ProcessLookupError,
which escapes the `except TimeoutError` handler before the RuntimeError
describing the timeout is ever raised. That exception carries no args, so
`f"verifier crashed: {e}"` renders with nothing after the colon: a finished
rollout is scored `rewards: null` under a message naming neither the failure
nor the fact that it had no detail.

The window is one loop tick wide — asyncio clears its process handle from a
`call_soon` callback — so it is rare on an idle loop and routine under
concurrency. `subprocess.Popen.send_signal` already absorbs this race
(bpo-38630, bpo-40550), which is why only the asyncio call sites are exposed.

Guard all five of them, and render verifier errors through the existing
`describe_exception` helper that the agent-side funnel already uses.

Fixes benchflow-ai#1065

@devin-ai-integration devin-ai-integration Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

🔍 Devin Review: 1 flag

Not posted on this PR by your GitHub settings — view it in Devin Review. (Configure)

Devin Review

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Docker.exec turns a hardening timeout into a bare ProcessLookupError, so the rollout is recorded as "verifier crashed: " with no message

1 participant