Dev VM disk filled by a leaked log-flood test container #19
Loading…
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Incident (2026-09-22, about 20:53–20:54): the dev VM's root disk (
/, where/var/lib/dockerlives) filled to 100%. The owner's AI agent found and removed a leaked container namedflamboyant_yellow. dockerd logged about 22,700no space left on deviceerrors while writing that container's json-file log, whose content was an endlessxxxx….Cause.
crates/server/tests/stream_e2e.rs(stream_priority_and_memory_smoke, branchstream) starts a Docker container runningSATURATING_LOG_COMMANDthroughContainerGuard, which removes it inDrop.Dropdoes not run when the test process is killed (a timeout, SIGKILL, or a panic withabort). The container is started without a log size limit, and Docker's defaultjson-filedriver is unbounded, so one killed bench run leaves a container filling the disk.Fix, three layers:
stream, afterfix-stream). Start every test and benchmark container with--log-opt max-size=… --log-opt max-file=1(or--log-driver nonewhere the test reads logs through the engine API only; check that the logs path still works), with--rm, and with a label such asinfraternal.test=<run id>. Before each suite, sweep stale containers carrying the test label that are older than the run. Never touch containers labelledinfraternal.demo=1.provision-dev-vmwrites/etc/docker/daemon.jsonwith"log-driver": "json-file", "log-opts": {"max-size": "50m", "max-file": "2"}. This needs a Docker restart, which is done when no job is using Docker.docker-log-guard.timer, truncates any container json log over 1 GiB every 30 s. Remove it once layer 2 lands.Tracked as part of step 11 (the stream), with the provisioning change in its own small commit.
Disk incident evidence for #19: the archived fix-stream job log captured
du -x -d3 /var/libwhile/was full. The leakedflamboyant_yalowcontainer (6cb572c1a80b...) occupied 28,048,968 KiB (26.75 GiB) under/var/lib/docker/containers/6cb572c1a80b837ac945acc045efb1cdd3e4d07483d4e3a416c4e558b02ffb4d/; dockerd's error names its6cb572c1a80b837ac945acc045efb1cdd3e4d07483d4e3a416c4e558b02ffb4d-json.logas the full-disk write path. Three other benchmark container directories occupied 26,337,736 KiB, 30,298,548 KiB, and 1,064,268 KiB. Together/var/lib/docker/containerswas 85,749,580 KiB (81.78 GiB). These were removed in the previous run; the present directory is only 72 KiB. The current change bounds each test fixture's logs and sweeps staleinfraternal.testcontainers without touchinginfraternal.demo=1.scripts/provision-dev-vmnow installs Docker daemon json-file defaults of 50m × 2; the live Docker daemon restart waits until no other job is using it.#19 mitigation is complete in step 11 final fix
kayg/infraternal#7, branchstream, head976323658df9f6f65c025b6a7de0d60cb82ff465(no push; issue remains open for the orchestrator). The earlier comment here records the archived incident measurement:flamboyant_yalow's/var/lib/docker/containers/6cb572c1a80b837ac945acc045efb1cdd3e4d07483d4e3a416c4e558b02ffb4d/was 28,048,968 KiB (26.75 GiB), with dockerd naming its*-json.logas the full-disk write path; four fixture directories totalled 85,749,580 KiB (81.78 GiB).Every fixture container in
crates/server/tests/stream_e2e.rsandcrates/engine/testsnow hasinfraternal.test, a 10 MiB single-file log bound (Dockerjson-fileusesmax-file=1; Podman uses its boundedk8s-filedriver), and auto-remove where stopped-container inspection is not part of the test. Both suites sweep labelled containers older than one hour at start and explicitly skipinfraternal.demo=1. The new server authorization regression's Docker and rootless Podman fixtures are also bounded, labelled, and auto-removed.scripts/provision-dev-vmnow installs Docker daemonjson-filedefaults of 50m × 2. With no running Docker containers after the green gates, I applied that config, restarted Docker, and stopped the transientdocker-log-guard.timer. A new probe container's actual inspection returned:The timer is inactive;
/var/lib/docker/containersis 76 KiB and/is 18% used. Final-headscripts/verify fast,integration, andbenchall passed; their verbatim outputs and the browser numbers are in #7. Docker documents the daemon and per-container log rotation settings: https://docs.docker.com/engine/logging/drivers/json-file/ .Leak found at 11:45 IST on 2026-09-25:
infraternal-browser-logs-podman-1538784-1790264828668(labelinfraternal.test=true, norun_id) had been running for 14 h after its owning browser-check process (pid 1538784) died. Its log was capped at 10 MB, so the impact was low, and I removed it. The browser-check Podman log fixture needs the same run-id label and cleanup on abnormal exit that the Rust tests got. Label: later.On 2026-09-25 the dev VM had 186 containers, mostly
infraternal-bench-*busybox containers left in the Created state by benchmark runs, visible in the pages-shadcn screenshots. The benchmarks need run-id labels and cleanup on every exit path, the same fix the Rust integration tests got in #19. Label: later.Starting fixture hygiene on branch
lp-fixtures, based ondevat6f6fd896214f05d9ef19a47e43fb8be2561ab626. I am mapping benchmark container creation and cleanup helpers before editing; VM cleanup will be restricted to the requested names andinfraternal.testlabels, withinfraternal.demo=1excluded.Finding: the real-container benchmarks are in
crates/engine/benches/engine.rs,crates/infraternal/benches/containers.rs, andcrates/infraternal/benches/stream.rs. Their existing labels are benchmark-specific (infraternal.bench*) and do not include the requestedinfraternal.test=benchplusinfraternal.test.run_id=<unique>pair. Docker is invoked directly from Rust in those paths, so it bypasses the VM's requiredsystemd-run --user --wait --pipe -q docker ...access path. The engine fixture already has an RAII resource holder, while the other two have guards that need to be registered before container creation can panic.Finding/decision: a read-only inspect on this VM returned Docker
.Createdas RFC3339 and Podman.Createdas2026-09-24 06:36:37.752245553 +0200 CEST. The shared sweep parser handles both forms, batch-inspects each runtime's labeled containers, and excludesinfraternal.demo=1before removal. Docker and Podman documentinspect --formatas a Go-template interface: https://docs.docker.com/reference/cli/docker/inspect/ and https://docs.podman.io/en/latest/markdown/podman-inspect.1.html. I added targeted parser and demo-exclusion tests; they are pending a clear verification slot.Additional fixture finding:
scripts/verify benchruns the ignoredstream_e2efixture tests, includingstream_priority_and_memory_smoke; theirContainerGuardwas outsidebenches/, used direct runtime commands, and labeledinfraternal.test=<suffix>plusinfraternal.test.run=<suffix>. I updated that bench fixture helper too: one process-unique run ID, the requiredtest=benchandtest.run_idlabels, the shared Docker/Podman wrapper, early RAII ownership by the unique name, and one signal cleanup guard for the process-wide fixture run.Signal cleanup decision: runtime helper subprocesses now start in their own Unix process group. This prevents terminal SIGINT from interrupting an in-flight
docker/systemd-runcreate before the benchmark's handler can wait for it and clean up by run ID. Rust documentsCommandExt::process_group(0)as stable since 1.64 and gives Ctrl-C isolation as its example: https://doc.rust-lang.org/std/os/unix/process/trait.CommandExt.html#tymethod.process_groupReview finding: Criterion's stream benchmark runs local and remote contexts sequentially in one process. A signal worker detached from the local context would still be alive when the remote context starts, so multiple workers could race to exit the process after cleaning only their own run ID. The stream benchmark now installs one process-level signal guard and shares its run ID across both contexts; normal RAII cleanup still removes each context as it finishes. Commit:
6a3c448.Resumed on GPT 6.1 Sol. Branch lp-fixtures, base
6f6fd89621, current heada6beba7450. Worktree clean at restart; reviewing committed implementation and completing verification and the authorized leftover-container cleanup. Waiting for another scripts/verify fast process and load5 > 6 before starting gates or cleanup.Continuation review found missing type annotations on eligibility-test closures and unchecked nonzero rm status in the shared stream benchmark fixture destructor; fixed in
3787a94. Added ignored real Docker/Podman subprocess regression covering normal exit, intentional panic, SIGINT, SIGTERM, and both signals while create_output still owns an in-flight creation permit. Static rustfmt and git diff --check pass. Runtime tests and final fast/merge gates remain pending another verification run and load5 > 6.Reviewed panic behavior against the workspace release profile (
panic = "abort"). Cargo documents that tests and benchmarks ignore that panic setting and use unwinding for the test harness, so the benchmark RAII guards remain the panic cleanup path; no production panic-profile change is needed. Source: https://doc.rust-lang.org/cargo/reference/profiles.html#panic . The new real-runtime subprocess test exercises actual panic unwinding and requires both engine inventories to be empty for its exact run ID afterward.Helper unit tests compiled directly against this worktree’s already-built dependencies using rustc --deny warnings; no full Cargo build or gate was started while other verification jobs are active. Found time 0.3.55 deprecation and replaced parse() with its behavior-equivalent parse_borrowed::<1>() (
7d08463). Official equivalence: https://docs.rs/time/latest/time/format_description/fn.parse.html .Exact targeted output:
Real engine exit-path tests and final scripts/verify fast and merge remain pending an idle verification slot and load5 <= 6.
Runtime verification/cleanup scheduling status at 19:57 UTC: lp-fixtures has waited since this continuation began at 19:33 UTC. Other scripts/verify fast processes remain active and load5 is 13.22, above this low-priority job’s limit of 6. No full Cargo build/gate or container deletion has been started by this continuation. Head
a417f46; standalone helper unit tests (4 passed) and standalone pedantic Clippy with warnings denied pass; the real Docker/Podman exit-path subprocess test and final fast/merge gates remain queued. The exact one-time cleanup inventory is prepared and will be refreshed when the VM is idle.One-time cleanup phase 1: only authorized names/test labels created more than 24 hours ago. Recent fixtures of active jobs are preserved. Every infraternal.demo=1 container is protected.
docker: 64 containers before cleanup; 62 historical leftovers selected; 0 demo containers protected.
docker: removed 62 containers; 6 remain; all 0 original demo containers remain.
podman: 110 containers before cleanup; 107 historical leftovers selected; 0 demo containers protected.
podman: removed 107 containers; 8 remain; all 0 original demo containers remain.
79860b5makes the new real fixture regression’s parent cleanup send SIGTERM and wait up to five seconds for its own child’s guarded cleanup before forcing a hung child to stop. This preserves in-flight-create cleanup on early test failure. Rustfmt and git diff --check pass; runtime execution remains queued. Historical cleanup is already complete and fully audited above: 62 Docker + 107 Podman (169 total). At 20:16 UTC other fast/e2e-remote/perf gates remain active and load5 is 10.97, so this job has still started no full gate.Real Docker/rootless Podman exit-path regression passed for all six modes: normal exit, intentional panic, SIGINT, SIGTERM, SIGINT during in-flight create, and SIGTERM during in-flight create. Each checks both runtimes for zero containers carrying its exact run ID before fallback cleanup. The intentional child panic is expected to exit 101; its FAILED line below is deliberately injected, while the parent regression passes.
Compiled the committed test source directly against this worktree’s cached Tokio/time libraries with rustc --deny warnings; standalone pedantic Clippy also passed. Readiness is an exclusive private run-ID directory, so this target needs no tempfile dependency. A prior attempt to select the dev-only tempfile dependency directly caused a Cargo resolver panic before compilation; no full Cargo build/gate was started.
Exact runtime output:
Exact helper unit output:
Full fast/merge and the owned stream fixture workload remain pending the shared verification/load constraints.
Orchestrator, gate policy from 00:10 IST: with about 12 jobs running, waiting for 'no other scripts/verify run active' deadlocks. Jobs: run
scripts/verify fastplus your targeted tests, then finish and report 'merge gate pending'. Do not wait forscripts/verify merge. The orchestrator runs merge gates centrally, one at a time, on ready branches.fda5ae3strengthens the in-flight regression: readiness now precedes delayed real container creation, and the parent waits for a creation-completion marker before checking inventory. This detects a container becoming visible after a premature signal cleanup. Both signal cases and all six exit modes passed again on real Docker/rootless Podman; standalone pedantic Clippy and rustc with warnings denied also pass.Exact updated output (the child panic is intentional; parent verifies its 101 exit and cleanup):
At 20:39 UTC load5 was below 6, but another perf gate and full cargo release build remain active. Final fast/merge are still queued.
cb048b4: inspect rows now use JSON so arbitrary label text cannot shift the demo-protection field. Missing or non-string demo metadata fails closed. Added parser regressions for a run ID containing a delimiter and malformed demo metadata. No dependency changes: serde_json was already available in all importing crates.The first live JSON-format check found Podman requires .ID inside json(), while Docker accepts .Id. The helper now accounts for that difference. Removed the exact fixture left by that failed check: Podman a1ce94923f5a8a19b5ecb5e4e0376e863b8c8993feb30881dbc23ed3970bf22d, run ID 1627881-1790967062931040677; inspected demo label was empty. This was recovery of this job’s own newly created fixture, separate from the 169 historical leftovers already audited.
Sources: https://docs.docker.com/engine/cli/formatting/ ; https://github.com/podman-container-tools/podman/blob/main/libpod/define/container_inspect.go ; https://pkg.go.dev/time#Time.MarshalJSON .
Standalone pedantic Clippy and rustc with warnings denied pass. Exact unit output:
Exact successful live exit-path rerun (intentional child panic is expected):
Final fast/merge remain queued behind active verification.
Scheduling status at 22:10 UTC: source is committed and clean at
9fdc4dc. Historical cleanup is complete (169 containers, exact audit above). Six helper units and six real Docker/Podman exit modes pass on the current implementation; standalone pedantic Clippy and rustc warnings-denied compile pass. Full fast/merge remain queued because other verification runs or load5 > 6 have continuously blocked their start since this continuation began at 19:33 UTC. An own lightweight monitor, /tmp/lp-fixtures-wait-fast.sh, checks load and active verification/release/browser work every 20 seconds and will launch fast at low CPU/IO weight when allowed. No full gate has yet started for this job.Continuation update (lp-fixtures, head
9893c3a, not pushed).origin/dev(merge commitecbc38a, no conflicts).8f7d040: the shared bench helper's test module glob import is unused when Criterion benches build without the test harness. Allowed it, socargo bench --no-run -p infraternal -p infraternal-enginenow builds warning-free.9893c3a: pedantic clippy fixes (semicolon_if_nothing_returnedincrates/infraternal/benches/containers.rs,manual_assertincrates/server/tests/stream_e2e.rs). These failedfastafter the merge.cargo test -p infraternal --test bench_runtime -- --include-ignoredpasses 8/8. That covers the parser and eligibility unit tests plus real Docker and Podman cleanup after a normal exit, a panic, SIGINT, SIGTERM, and SIGINT or SIGTERM during an in-flight create.infraternal-bench-,infraternal-browser-orstream-, and none carrying theinfraternal.testlabel), so nothing was removed in this pass. What remains belongs to other jobs: 250 Docker and 250 Podmanperf-*containers from a perf run,infraternal-s2-stack-*, andinfraternal-audit-perf-idle. I did not touch them.INFRATERNAL_VERIFY_RUN_ID=sub-fixtures scripts/verify fastPASS at9893c3a(all 16 steps). I did not run merge, integration or browser.lp-fixtures merged with origin/dev (
972197f); head is now8addce8. Not pushed.Conflict in crates/engine/benches/engine.rs. Both sides are kept:
create_list_containers(..., &mut list_resources), the tracked fixture names (the provider A/B inspect cases need them), and theinfraternal.test.run_idlabels.BenchmarkResources::new(runtime, &run_id), theinfraternal.test=benchlabel, and everyps/run/create/rmcall goes throughbench_runtime::{runtime_command, output, status, create_output}.timeandserde_jsonout of the engine crate, so they're added back as engine dev-dependencies forbench_runtime.rs.Why the perf run leaked 500 containers.
scripts/perf/run.mjscreates 250 Docker and 250 Podman list fixtures labeledinfraternal.test.run=perf-<pid>-<ms>. They have no bench labels, and the only cleanup was afinallyblock. Node doesn't runfinallywhen SIGINT, SIGTERM or SIGHUP kills the process, andsweep_stale_bench_containersonly matchedinfraternal.test=bench, so nothing ever removed them.Fix (
8addce8):sweep_stale_bench_containersalso removesperf-<pid>-<ms>fixtures over an hour old whose process is gone.infraternal.demo=1are never removed.Leftovers removed: 500 (250 Docker, 250 Podman) from run perf-2137035-1790973242834, whose pid is gone. The extended sweep removed them during the bench_runtime test. No demo containers were present or touched.
Gates:
cargo bench --no-run -p infraternal -p infraternal-engine: builds with no warnings.cargo test -p infraternal --test bench_runtime -- --include-ignored: 11/11 pass.INFRATERNAL_VERIFY_RUN_ID=sub-fix3 scripts/verify fast: passes.verify mergewas not run.