Repository navigation
fix(opensandbox): report a command that hit its timeout as a timeout - #5157
Conversation
execd kills a command that reaches the timeout the provider passes it and reports the kill like any signal death: exit code -1 and "signal: killed", with no timeout flag. exec therefore returned -1 with no error_type, so callers that look for error_type="timeout" (sandbox_session.py, the Terminal-Bench-Science oracle) saw a failed command instead. Docker and the provider's own session path already report rc 124 with error_type="timeout". A signal death now counts as a timeout when the command ran for its whole timeout: by execd's started_at/finished_at on the background path, and by the client's clock for the attempt that ran on the foreground path, whose execution carries no start time. A command killed before its deadline, e.g. by the OOM killer, keeps -1. Signed-off-by: gwarmstrong <gwarmstrong@users.noreply.github.com>
Signed-off-by: gwarmstrong <gwarmstrong@users.noreply.github.com>
Signed-off-by: gwarmstrong <gwarmstrong@users.noreply.github.com>
|
/ok to test 0f9053e |
svcnvidia-nemo-ci
added
area:sandbox
|
🌿 Preview your docs: https://nvidia-preview-pr-5157-8101c4c85c30.docs.buildwithfern.com/nemo/gym |
svcnvidia-nemo-ci
left a comment
svcnvidia-nemo-ci
left a comment
There was a problem hiding this comment.
SHIP WITH CARE — three RISK findings in timeout classification.
Reviewed all three changed files and traced submission retries, transport behavior, result consumers, and neighboring timeout paths. The findings concern early signal deaths being incorrectly reported as timeouts.
Static inspection only; tests were not executed. The consumer/documentation topic was checked directly after its delegated report was unavailable.
Review generated by codex. This was a full review. Request a full review with /review reset=true.
| if note is not None: | ||
| stderr_parts.append(note) | ||
| # The execution carries no start time, so the client's clock times it. | ||
| if _killed_at_timeout(return_code, loop.time() - started, timeout_s): |
There was a problem hiding this comment.
RISK — foreground request latency is not command runtime
Failure: With timeout_s=3, a buffered submission can receive HTTP 429 with Retry-After: 3, then successfully submit a command that immediately kills itself. The default transport sleeps and retries internally, without re-entering run_command() to reset started. This branch therefore observes at least three seconds and changes the immediate signal death from (-1, None) to (124, "timeout"). Connection-pool waiting likewise contributes to this clock. The expected classification depends on time the command ran, not time awaiting submission. This affects foreground executions encountering submission delays; consumers such as SandboxSession.execute distinguish these outcomes.
Correction: Could the foreground branch obtain execution-side duration/status, or separate pre-execution waits and post-exit response draining before invoking _killed_at_timeout? Resetting the provider-level factory alone cannot exclude retries inside the transport. Preserve transport retries and their existing submission eligibility. The mounted tree does not contain the SDK implementation, so the exact lifecycle-timing integration needs verification rather than a speculative patch. The invariant is that unrelated request latency cannot establish that execd reached the command deadline.
Acceptance — proposed, not executed: Add a foreground case with a three-second pre-execution 429 retry followed by an immediate signal death; expect return_code=-1, error_type=None, and unchanged partial output/error text. The same retry followed by a command genuinely running to its three-second deadline must return 124/timeout. Retain the existing foreground assertions: deadline kill becomes timeout, early kill stays -1, exit 7 stays 7, unset timeout stays unclassified, and partial stdout/stderr survive. Also preserve zero-timeout behavior and recovery after provider-level 502 retries.
There was a problem hiding this comment.
Fixed in 8101c4c. The foreground path no longer times from the submit. It passes ExecutionHandlers and times the command from execd's init stamp to its error stamp (ms, both execd's). Without the stamps it uses the times those two events reached the client, so a transport retry or pool wait before init never counts. On a live cell, init to error was 2999 ms for sleep 30 under a 3 s timeout and 0 ms for kill -9 $$.
Tests: each live case runs with and without a 0.35 s wait inside commands.run before init (the 429 Retry-After case). An immediate kill stays (-1, None) with its output and error text, and a run to the deadline is 124/timeout. The existing foreground assertions, zero and unset timeouts, and the 502 retry tests pass.
| if started_at is not None and finished_at is not None: | ||
| elapsed_s = (finished_at - started_at).total_seconds() | ||
| else: | ||
| elapsed_s = loop.time() - submitted |
There was a problem hiding this comment.
RISK — exclude known non-execution work from the background fallback
Failure: When either server timestamp is absent, this clock includes log retrieval after the process is already known to have finished. For example, use background_exec=True, timeout_s=3, and request_timeout_s=5; return an immediate terminal status with exit_code=-1, then delay the logs response by three seconds. The new branch returns 124/timeout although the process died immediately; it should retain -1 with no error type. It also includes 502 submission backoffs, because submitted is initialized outside the retried factory. These are false timeout classifications in the explicitly supported missing-timestamp fallback.
Correction: Could _exec_background reset the start for each provider-level submission attempt and freeze the terminal-status observation before reading logs? A suggested patch for these known extraneous intervals is:
submitted = loop.time()
+
+ def run_command() -> Awaitable[Any]:
+ nonlocal submitted
+ submitted = loop.time()
+ return handle.raw.commands.run(command, opts=RunCommandOpts(**background_opts))
+
execution = await self._submit_command(
- lambda: handle.raw.commands.run(command, opts=RunCommandOpts(**background_opts)),
+ run_command,At the terminal-status branch:
if not status.running:
+ observed_finished = loop.time()
breakThen replace the fallback with:
elapsed_s = observed_finished - submittedThis restores the invariant that known pre-submission retry waits and post-completion log work cannot trigger classification. Server timestamps must remain authoritative; local submission/poll timing remains an estimate. Please verify the suggestion before adoption.
Acceptance — proposed, not executed: An immediate timestamp-less -1 status followed by delayed or retried logs must remain (-1, None) with original output/diagnostics. Three backend-connect 502s followed by an immediate killed command under a one-second timeout must also remain (-1, None). A timestamp-less execution observed running through its deadline must still return 124/timeout. Retain the timestamped cases: deadline kill → timeout, early kill → -1, ordinary exit → 7, zero timeout → unclassified, with stdout="partial output". Preserve bounded read retries and deleted-output diagnostics without resubmitting the command.
There was a problem hiding this comment.
Applied in 8101c4c as suggested: submitted resets in the submit factory, and the fallback stops at the status read that showed the command finished, before the logs are read. execd's started_at and finished_at stay authoritative.
Tests, without timestamps: two 0.15 s 502 submits and a 0.3 s log read leave an immediate kill at (-1, None), with partial output and signal: killed (it was 124/timeout before). A command still running at its 0.25 s deadline is 124/timeout. The timestamped cases are unchanged.
| bool(timeout_s) | ||
| and return_code == -1 | ||
| and elapsed_s is not None | ||
| and elapsed_s >= float(timeout_s) - EXEC_TIMEOUT_SLACK_S |
There was a problem hiding this comment.
RISK — fixed slack consumes short deadlines entirely
Failure: _killed_at_timeout(-1, 0.001, 0.1) returns true because the threshold is 0.1 - 0.25 = -0.15. Consequently, every nonnegative-duration signal death under a deadline of at most 250 ms is labeled 124/timeout, including a process killed after only 1 ms. Expected: this far-before-deadline failure remains (-1, None). Fractional timeouts are accepted by the public provider contract, and both execution paths use this predicate.
Correction: Could the allowance be bounded relative to a positive timeout so it cannot consume the whole deadline? The invariant is that near-immediate signal deaths remain ordinary failures even for short supported timeouts. Simply clamping the threshold to zero does not fix this: all nonnegative durations would still match. The precise fractional allowance needs validation against execd's timestamp skew, so no arbitrary replacement constant is proposed.
Preservation and acceptance — proposed, not executed: Add deterministic public-path cases for timeout_s=0.1: a -1 result after 0.001 seconds must retain (-1, None) and its original output/diagnostics, while a genuine 0.1-second deadline kill must return (124, "timeout"). Retain the long-deadline allowance: a 30-second deadline measured at 29.8 seconds should still classify as timeout, while a one-second kill under that deadline stays -1. Preserve the existing background and foreground assertions that ordinary exit 7 is unchanged and zero/None timeouts remain unclassified.
There was a problem hiding this comment.
Fixed in 8101c4c: the allowance is 0.25 s or a tenth of the timeout, whichever is smaller. On a live cell, a kill at the deadline read at most 1 ms short in execd's stamps (2999 ms of 3 s, 499 of 0.5 s and 201 of 0.2 s in the foreground; 3000.7, 500.1 and 200.1 ms in the background). Before the fix, kill -9 $$ under a 0.5 s or 0.2 s timeout came back 124/timeout live; it now returns -1 on both paths.
Tests: 1 ms under a 0.1 s timeout stays -1; 0.1 s and 0.095 s are timeouts; under 30 s, 29.8 s is a timeout while 29.7 s and 1 s are not.
Foreground commands are timed from execd's init event to its error event, so submit retries, pool waits and request latency no longer count. Without timestamps, the background path times the submit that ran up to the status that showed the command finished. The timeout allowance is at most a tenth of the timeout, so an early death under a short timeout keeps exit code -1. Signed-off-by: gwarmstrong <gwarmstrong@users.noreply.github.com>
|
/ok to test 8101c4c |
|
🔄 Merge queue validation started! You can track the progress here: https://github.com/NVIDIA-NeMo/Gym/actions/runs/40971943120 |
5c86a65
What does this PR do?
execpassestimeout_sto execd, which kills the command when it is reached. execd reports that kill like any other signal death: exit code -1 andsignal: killed, with no timeout flag, on both the foreground and thebackground_execpath. The provider passed that through, so a timed-out command came back as exit code -1 with noerror_type. Callers that checkerror_type == "timeout", such assandbox_session.pyand the Terminal-Bench-Science oracle (#4879), saw a failed command instead of a timeout. This provider's own session path (exec_with_background_services) already returns 124 witherror_type="timeout", and Docker returns 125 witherror_type="timeout".The provider now returns 124 with
error_type="timeout"for a signal death that ran for its whole timeout. It keeps execd's stderr and adds a note: "Command timed out after {timeout_s}s; OpenSandbox execd killed it". The command is timed by execd's own stamps: theinitanderrorevents of a foreground run, andstarted_atandfinished_atof a background one. Without them the client times it, from theinitevent's arrival to theerrorevent's in the foreground, and from the submit that ran to the status that showed it finished in the background. Submit retries, connection waits, request latency and log reads therefore never count. The allowance for execd's timer starting a moment before its stamps is 0.25 s or a tenth of the timeout, whichever is smaller; on a live cell a kill at the deadline read at most 1 ms short.The elapsed time is the only way to tell the two cases apart. A command that SIGKILLs itself one second in returns exactly the same exit code and message as one killed at its timeout. So a command killed before its deadline, for example by the OOM killer, keeps exit code -1, and so does a signal death when no timeout was set (0 enforces none). Exit codes other than -1 are unchanged.
No issue: found while validating #4879's oracle fix; the repro is below.
Validation
tests/unit_tests/test_opensandbox_provider.py: 187 passed. The foreground cases replay execd's stamps from live runs (3, 0.5 and 0.2 s timeouts), each with and without a 0.35 s wait before execd starts the command, as when the transport waits out a 429. In the background, two slow 502 submits and a slow log read leave an immediate kill at -1, and a command without stamps that is still running at its deadline is a timeout. Further cases cover the allowance: 1 ms under a 0.1 s timeout stays -1, 29.8 s under 30 s is a timeout.test_sandbox.py,test_opensandbox_compose.pyandtest_sandbox_session.pypass; their fakes ofcommands.runnow accept thehandlersthe provider passes.Live on an OpenSandbox cell, with a 3 s
timeout_s:background_execmainsleep 30error_typeNonetimeoutsleep 30error_typeNonetimeoutsleep 1; kill -9 $$exit 7Live at short timeouts, after the bot's review (2026-10-28). The previous head (0f9053e) reported a command that killed itself at once as a timeout; execd's stamps put its run at 0 to 1 ms:
kill -9 $$timeout_stimeouttimeouttimeoutsleep 30at the same timeouts stays 124,timeouton both paths (execd's stamps: 499 and 201 ms in the foreground, 500.1 and 200.1 ms in the background), and the 3 s rows above are unchanged.Rollouts
N/A (provider error handling).
Compatibility and benchmark impact
No settings change. A command killed at its
timeout_snow returns 124 witherror_type="timeout"instead of -1, the same code as the session path. Callers that treat anyerror_typeas a failed command still count it as failed, and callers that check for timeouts now see them.