Deployment runner can deadlock on subprocess output and time out during OpenTofu apply #460

Open
opened 2026-09-28 17:53:47 +00:00 by vkobel · 1 comment
vkobel commented 2026-09-28 17:53:47 +00:00 (Migrated from codeberg.org)

Platform's deployment process runner pipes stdout and stderr but does not read either stream until the child exits or is killed. A sufficiently verbose command can fill a pipe and block while the parent waits for it to exit, eventually producing a misleading deployment timeout.

Observed behavior

On dev on 2026-09-28, with Platform commit bfe75a71f87e2b912fc6ed3fcf771789dee0517b, deploying a new disposable app using git push caution HEAD:main produced:

  • Successful application-container and enclave-image builds.
  • Successful EIF upload and fully managed capacity selection.
  • Successful tofu init in approximately 1.5 seconds.
  • tofu apply starting at 17:20:41 UTC and timing out at 17:30:41 UTC.
  • A generic Nitro deployment failed response, followed by a failed app record with no public IP.

The API log reports:

command timed out after 600s [src/api/src/deployment.rs:285:43]

Captured stdout contains 9,804 bytes and ends during the printed plan, after the aws_instance.enclave block. It contains no plan summary or resource-creation progress; stderr is empty. Automatic rollback subsequently reported success.

The application did not reach a usable endpoint

Implementation defect

In src/api/src/deployment.rs, run_with_timeout (lines 249-300 at the commit above):

  1. Starts the child with stdout and stderr set to Stdio::piped().
  2. Polls child.try_wait() without draining either pipe.
  3. Calls child.wait_with_output() only after exit or timeout-triggered termination.

If either pipe fills, the child can block writing output and never reach exit. Increasing the deadline does not resolve that condition. The helper is shared by multiple OpenTofu operations, so this is not specific to secret-enabled apps.

Reproduction evidence and confidence

A local diagnostic using the same wait-before-drain sequence launched a child writing 128 KiB to stdout. After one second, the child was still blocked; killing it yielded 65,536 bytes. A control that drained output while waiting completed successfully with all 131,072 bytes in approximately 0.028 seconds.

This reproduces the subprocess I/O defect. The alpha log is consistent with the same failure, but the terminated alpha process was not traced, so pipe backpressure remains the likely explanation for that particular deployment timeout rather than a directly observed process wait state.

Expected behavior / rewrite acceptance criteria

  • Consume stdout and stderr while commands run, or redirect them to suitable files, independently of exit polling.
  • Retain bounded execution time, child termination/reaping, nonzero-exit handling, and useful failure diagnostics.
  • Ensure output collection itself cannot make timeout handling wait indefinitely.
  • Cover large stdout, large stderr, simultaneous output, successful completion, nonzero exit, and a genuinely hung child in regression tests.
  • Surface the failing deployment stage and actionable cause to the CLI/UI.
Platform's deployment process runner pipes stdout and stderr but does not read either stream until the child exits or is killed. A sufficiently verbose command can fill a pipe and block while the parent waits for it to exit, eventually producing a misleading deployment timeout. ## Observed behavior On dev on 2026-09-28, with Platform commit `bfe75a71f87e2b912fc6ed3fcf771789dee0517b`, deploying a new disposable app using `git push caution HEAD:main` produced: - Successful application-container and enclave-image builds. - Successful EIF upload and fully managed capacity selection. - Successful `tofu init` in approximately 1.5 seconds. - `tofu apply` starting at 17:20:41 UTC and timing out at 17:30:41 UTC. - A generic `Nitro deployment failed` response, followed by a failed app record with no public IP. The API log reports: ```text command timed out after 600s [src/api/src/deployment.rs:285:43] ``` Captured stdout contains 9,804 bytes and ends during the printed plan, after the `aws_instance.enclave` block. It contains no plan summary or resource-creation progress; stderr is empty. Automatic rollback subsequently reported success. The application did not reach a usable endpoint ## Implementation defect In `src/api/src/deployment.rs`, `run_with_timeout` (lines 249-300 at the commit above): 1. Starts the child with stdout and stderr set to `Stdio::piped()`. 2. Polls `child.try_wait()` without draining either pipe. 3. Calls `child.wait_with_output()` only after exit or timeout-triggered termination. If either pipe fills, the child can block writing output and never reach exit. Increasing the deadline does not resolve that condition. The helper is shared by multiple OpenTofu operations, so this is not specific to secret-enabled apps. ## Reproduction evidence and confidence A local diagnostic using the same wait-before-drain sequence launched a child writing 128 KiB to stdout. After one second, the child was still blocked; killing it yielded 65,536 bytes. A control that drained output while waiting completed successfully with all 131,072 bytes in approximately 0.028 seconds. This reproduces the subprocess I/O defect. The alpha log is consistent with the same failure, but the terminated alpha process was not traced, so pipe backpressure remains the likely explanation for that particular deployment timeout rather than a directly observed process wait state. ## Expected behavior / rewrite acceptance criteria - Consume stdout and stderr while commands run, or redirect them to suitable files, independently of exit polling. - Retain bounded execution time, child termination/reaping, nonzero-exit handling, and useful failure diagnostics. - Ensure output collection itself cannot make timeout handling wait indefinitely. - Cover large stdout, large stderr, simultaneous output, successful completion, nonzero exit, and a genuinely hung child in regression tests. - Surface the failing deployment stage and actionable cause to the CLI/UI.
vkobel commented 2026-09-28 17:58:51 +00:00 (Migrated from codeberg.org)

Related to #376 (run_with_timeout is sync, should be async).

These concern the same helper but document distinct failure modes:

  • #376: synchronous execution blocks API responses/updates.
  • #460: stdout/stderr are not drained while the child runs, so a full pipe can block the child until the timeout.

I suggest keeping #460 linked to #376. One implementation change may resolve both, but making the runner async alone does not guarantee correct output handling. Regression coverage should include large stdout/stderr, simultaneous output, and a genuinely hung child.

The observed deployment timeout is consistent with pipe backpressure; it is not yet a confirmed diagnosis of that individual failure.

Related to #376 (`run_with_timeout is sync, should be async`). These concern the same helper but document distinct failure modes: - #376: synchronous execution blocks API responses/updates. - #460: stdout/stderr are not drained while the child runs, so a full pipe can block the child until the timeout. I suggest keeping #460 linked to #376. One implementation change may resolve both, but making the runner async alone does not guarantee correct output handling. Regression coverage should include large stdout/stderr, simultaneous output, and a genuinely hung child. The observed deployment timeout is consistent with pipe backpressure; it is not yet a confirmed diagnosis of that individual failure.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
public/platform#460
No description provided.