Skip to content

fix(execution): bound the output a docker command can buffer - #383

Merged
sudoTomas merged 1 commit into
mainfrom
fix/exec-output-bounded
Nov 6, 2026
Merged

sudoTomas merged 1 commit into
mainfrom
fix/exec-output-bounded

Conversation

@sudoTomas

@sudoTomas sudoTomas commented Nov 5, 2026 •

Copy link
Copy Markdown
Owner

Summary

Bound the output a docker command can make the orchestrator hold. DockerClient.run_cmd read a command's stdout and stderr whole; it now reads them through the same chunked reader run_cmd_bytes uses, with a default stdout cap of 4 MiB, a named larger cap where a caller legitimately reads more, and a tail-only mode for commands whose output is a log. A command that prints without end is stopped. stdout is also decoded leniently, so a log read with tail -c that starts inside a multi-byte character is read instead of failing (#394).

Motivation — Intent + Problem

run_cmd used proc.communicate(), which buffers all of stdout and stderr with no limit. Most of its ~97 call sites are a docker exec into a job's sandbox (git steps, file staging, QA boot and result reads, the test gate), where processes started during the job can still be running and writing into the exec's output. Whatever such a command printed, the orchestrator held in full, and stderr was unbounded too. exec_with_stdin (the write direction) and the runtime's compose service listing had the same communicate(). Only run_cmd_bytes read in bounded chunks.

Separately (#394), run_cmd decoded stdout strictly. The test gate reads its run's log back with tail -c 1048576 and the QA boot phase reads tail -c 8192; a cut inside a multi-byte character raised UnicodeDecodeError, so the gate recorded the run as "could not be started" (verdict error) and the boot log tail came back empty.

How it works

  • One reader, collect_output(proc, ...) (embry0/execution/docker_client.py), used by run_cmd, run_cmd_bytes, exec_with_stdin and DockerRuntime.compose_services. It reads stdout in 64 KiB chunks and never asks the pipe for more than max_bytes + 1 bytes in total. Past the cap the command is killed (its whole process group where it runs in its own session), its readers cancelled, its pipes closed and the process reaped; then run_cmd logs docker_cmd_too_large (warning, with the caller's log_context) and raises OutputTooLargeError, still a RuntimeError, so every existing except RuntimeError fails its step as before. stdin is fed concurrently and closed, and a command that exits without reading it is not an error, as with communicate().

  • stderr keeps its first 64 KiB and its last 16 KiB, with a line saying how many bytes between them were dropped; the rest is read and dropped, so a chatty command never blocks and a command that exits 0 still succeeds. The tail is new: a failing build or install prints its cause last.

  • keep_tail=True is for a command whose output is only a log: the oldest bytes are dropped instead of stopping it, and the result is the output's last max_bytes. Such a command is never stopped for its volume: it holds at most its tail and is bounded by its timeout. The empty-stderr error still quotes the last 2000 characters of stdout.

  • Decoding (fix(execution): a log cut mid-character fails the test gate #394). stdout is decoded with errors="replace" everywhere. Only bytes that are not UTF-8 change, each to U+FFFD; replacement never adds or removes an ASCII character, so the markers callers parse (EMBRY0_VERIFY_RESULT, HTTP_CODE=, STATUS=, EMBRY0_VERIFY_HEAD/BASE), JSON structure (daemon inspects, result.json, the storage state), ids and refs decode as they always did. Before, a non-UTF-8 byte raised UnicodeDecodeError, a ValueError that slipped past every except RuntimeError. One visible effect: a lockfile that is not valid UTF-8 is now hashed as its decoded text instead of failing the read; npm, pnpm and yarn write UTF-8.

  • Caps. DEFAULT_MAX_OUTPUT_BYTES (4 MiB) unless the caller names one:

    • GIT_LISTING_MAX_BYTES (64 MiB, sandbox_git) for listings of paths: the changed-files git diff --name-only, the --numstat count, the salvage step's git status --porcelain, and the pull request review's changed-path file. At about 75 bytes a path the default would stop near 55,000 paths; 64 MiB holds about 900,000. sandbox_git.run passes a max_bytes through to run_cmd.
    • LOCKFILE_MAX_BYTES (64 MiB) for the four lockfile reads.
    • DAEMON_LISTING_MAX_BYTES (64 MiB) for listings of the daemon's own objects (containers, images, volumes, networks, system df, the network inspect, the egress helper's iptables -S).
    • STORAGE_STATE_MAX_BYTES (128 MiB) for the Playwright storage state, which with Playwright's indexedDB option carries IndexedDB records, where an app may keep an offline cache of tens of MiB.
    • RUN_OUTPUT_MAX_BYTES (the 1 MiB log tail plus 64 KiB) for a test-gate run.
    • LOG_TAIL_BYTES (64 KiB) with keep_tail for the image builder's install and turbo build, the volume warmer's install, build_image, and the QA seed, login and e2e commands.

    A cap that is missing, zero, negative, a bool, not an int, or above MAX_OUTPUT_CAP_BYTES (256 MiB) raises ValueError before the command starts.

  • Unchanged: strip, stdin_data, log_context, expected_failure, the timeout kill path and its docker command timed out after Ns message, the (stderr empty; stdout tail) message, and the log event names.

  • Fixed on the way, in the code this unifies: the old run_cmd_bytes waited out its 5 s reap timeout on every read past its cap and logged docker_cmd_bytes_kill_stuck for a process that had died. The reader stopped with data in the pipe left it paused short of EOF, and Process.wait() also waits for the pipes; the pipes are now closed before the wait (measured: 5.01 s and a stuck-kill error before, 0.01 s and none after).

  • What an over-cap read does to each caller. Most callers let the exception fail their step: the clone (WorkspaceInitError), QA seed / e2e / login / result.json (a failed or inconclusive sub-task), the onboard qa.yaml (not validated), the pull request checkout (review failed), the image builder's lockfile and install (build failed), the QA sandbox prep steps. The test gate's run now records it as not run with the note "the run printed more than N bytes back, so it was stopped" (verdict error, which asks for a human merge) instead of "could not be started". The callers that catch it already treat any failure as "unknown" or "not done", and each of those readings is the safe one:

    • stricter: the changed-files diff (the gate takes the stricter tier and every test target, the review its unscoped prompt, QA reports the diff unavailable), the forge default-branch probe (not trusted, so a per-job volume), the unpushed-commit count (no rescue push), the salvage commit (not made), the areas and audit deliveries (not pushed), the QA lockfile read (no shared warm volume), the workspace staging reads (the provider then reports the apps missing), a proxy's egress address (left out, so egress stays closed);
    • diagnostic only: the base-branch probe (falls back to main), the diff line counts (none), the branch probe (the derived branch name is kept, as on any probe failure) and its tip detail, the boot log tail, notes.md, the diagnostic screenshot, the image ref in a log, the turbo warm-up;
    • housekeeping: the in-sandbox runner stop, proxy liveness (recreated), the local-model flag, the container-id lookup, sandbox stop/rm and proxy removal (logged), the egress readiness probe (warning), the context-proxy token (the log tool is not granted);
    • _verify_branch_pushed gives an over-cap read the same benefit of the doubt it gives a timeout or any other docker failure, by design.

    An OutputTooLargeError that reaches a job is classified ERR_DOCKER_OUTPUT_TOO_LARGE (infra) rather than ERR_SANDBOX_COPY_OUT_REFUSED, which keeps meaning a refused file read.

  • kill_process_group is folded into the reader's stop step; nothing else used it.

Pattern provenance

N/A — originated in this PR; it generalises the chunked reader run_cmd_bytes already had.

Verification

Automated

  • Full unit suite with a database, -n 4 --timeout=60 --fail-on-warnings, Docker unreachable: 18712 passed, 21 skipped, 0 failed (on a128f159, based on main 65cf0eaf)
  • ruff check . and ruff format --check . on the whole tree: clean; mypy embry0: no issues in 652 source files
  • Fail-first. Round 1: every new test run inside a clean git archive origin/main tree with only the test files copied in; all 22 fail there, each on its own assertion (e.g. "run_cmd must cap the stdout it holds (max_bytes), or keep only its tail (keep_tail)", "run_cmd_bytes: the stopped command was reaped only after 5.0s", "stderr must be read in chunks, never whole", "the error carried 4194360 characters of stderr", "the exec's output must be read in chunks"). Round 2 (review): the fix(execution): a log cut mid-character fails the test gate #394 tests fail on origin/main for the decode ("a log cut inside a character must still be read: 'utf-8' codec can't decode byte 0xa9", the gate run errored "could not be started", "the boot log tail was lost: ''"); the ceiling, git-listing and call-site-table tests fail on the round-1 head f9cb0a8c ("docker_client must define MAX_OUTPUT_CAP_BYTES", "sandbox_git must define GIT_LISTING_MAX_BYTES above the default", "a 90,000-file change read as an unavailable diff: … passed its 4194304-byte cap").
  • The call-site guard (tests/unit/execution/test_run_cmd_caps.py, an AST walk of every run_cmd and sandbox_git.run call) is shown capable of firing: removing the lockfile cap from one site, writing a literal max_bytes=65536, naming a cap equal to the default, splatting **{...} outside the one listed forwarder, run = ctx.docker.run_cmd, functools.partial(ctx.docker.run_cmd), getattr(ctx.docker, "run_cmd") and read = docker.run_cmd_bytes each fail it; restored, it passes.
  • Mutations of the code, each failing its test: _check_cap without the ceiling, the strict decode back, sandbox_git.run dropping max_bytes.
  • Real-process checks: 8 MiB written past a 1 KiB cap is stopped in 0.01 s with no stuck-kill log; an 8 MiB stderr flood with exit 0 returns stdout; a failing 8 MiB stderr keeps its first and last lines in an 82 KB message; keep_tail returns the last bytes of an 8 MiB log; a 4 MiB stdin to a command that never reads it still returns; a timeout with a grandchild holding the pipe raises after the timeout with no stuck-kill log.
  • Name denylist after staging: 0 matches. gitleaks over the changed files: no leaks.

Tests: test_docker_client.py (cap, default cap, refused caps and the ceiling, the cut-character decode, real-process reap, stderr drain, stderr head and tail, keep_tail success and failure, a git step at the default and a git listing at its own cap through sandbox_git.run, exec_with_stdin, the compose listing), test_run_cmd_caps.py (call-site table, named caps, direct calls only), test_workspace_diff.py (a 90,000-file change listed whole), test_runner.py (the gate's over-cap note; a run whose tail starts inside a character passes, through the real client), test_subtask_nodes.py (the boot log tail survives a cut character), test_failure_taxonomy.py (the code). Existing tests that faked communicate() now fake the pipes, with their assertions unchanged, and test fakes of run_cmd accept the new keyword; the old "keeps only the head of a flooded stderr" test became the head-and-tail one.

Out of scope / follow-ups

  • stream_exec itself holds nothing past one line (16 MiB) and its consumer keeps a 256 KiB stderr window, but the triage, developer and review nodes append every event of a run to a list that has no cap of its own. Reported separately; not changed here.
  • Host-side git runs (skills/sync.py, slop_meter/mirror.py) and the operator CLI's compose calls also use communicate(); they are not docker commands into a sandbox and are left as they are.

Deploy notes

  • Orchestrator-side: takes effect on a normal infra/deploy.sh. No migration, env var or dependency.
  • docker_client.py and embry0/safety/error_codes.py are also baked into the sandbox images, where the runner only imports them (no new imports were added, and nothing in a sandbox runs run_cmd), so a stale image is harmless. The next sandbox rebuild (docs/ops/deploy.md, the recipe for the sandbox-baked embry0/execution/ modules) picks the copies up; it is not needed for this fix.
  • New failure code ERR_DOCKER_OUTPUT_TOO_LARGE (infra) and log event docker_cmd_too_large.

Fixes #394

DockerClient.run_cmd read a command's stdout and stderr whole with
communicate(), so the orchestrator held whatever a command printed,
however much that was. Most callers are a docker exec into a job's
sandbox, where processes started during the job can still be running
and writing into the exec's output. Only run_cmd_bytes read in bounded
chunks.

One reader, collect_output, now serves run_cmd, run_cmd_bytes,
exec_with_stdin and the runtime's compose service listing. It reads
stdout in 64 KiB chunks and never asks the pipe for more than the cap
plus one byte; past the cap the command is stopped and reaped, a
warning logged, and OutputTooLargeError (still a RuntimeError) raised.

The default cap is DEFAULT_MAX_OUTPUT_BYTES, 4 MiB. Callers that read
more name one: a git listing of paths (diff --name-only, --numstat,
status --porcelain, a pull request's files; 64 MiB), a lockfile
(64 MiB), a listing of the daemon's own objects (64 MiB), a Playwright
storage state with IndexedDB (128 MiB), and a test-gate run (its 1 MiB
log tail plus a marker line). Commands whose output is only a log
(installs, builds, seed, login and e2e scripts) use keep_tail: the
oldest bytes are dropped, so such a command holds at most its tail and
is bounded by its timeout. stderr keeps its first 64 KiB and its last
16 KiB, where a failing build says why; the rest is read and dropped.

A cap that is missing, not a positive integer or above
MAX_OUTPUT_CAP_BYTES (256 MiB) is refused. A test pins every run_cmd
and sandbox_git.run call site to the default or a named constant
listed with its reason, and fails on any use of run_cmd or
run_cmd_bytes that is not a direct call (an alias, a partial, a
getattr).

Also:
- stdout is decoded with errors="replace". The test gate's log and the
  QA boot log are read with tail -c, which can cut a multi-byte
  character; the strict decode then failed the gate's run as "could
  not be started" and dropped the boot log. Only bytes that are not
  UTF-8 change, so markers, JSON structure and ASCII fields read as
  before.
- A stopped command's pipes are closed before it is waited on. The
  old run_cmd_bytes waited out its 5 s reap timeout on every read past
  its cap and logged a stuck kill that had not happened.
- The test gate records a run past its cap as not run, with a note
  that says so, rather than "could not be started".
- An OutputTooLargeError that reaches a job is now
  ERR_DOCKER_OUTPUT_TOO_LARGE (infra) instead of
  ERR_SANDBOX_COPY_OUT_REFUSED, since it no longer means a file read.

Fixes: #394
@sudoTomas
sudoTomas force-pushed the fix/exec-output-bounded branch from f9cb0a8 to a128f15 Compare November 6, 2026 14:28
@sudoTomas
sudoTomas merged commit 6f695ee into main Nov 6, 2026
13 checks passed
@sudoTomas
sudoTomas deleted the fix/exec-output-bounded branch November 6, 2026 14:50
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.

fix(execution): a log cut mid-character fails the test gate

1 participant