fix(log_lib): run_with_log hangs forever when an orphan holds the child's pipe - #7
Open
tigist-far wants to merge 1 commit into
Open
tigist-far wants to merge 1 commit into
tigist-far wants to merge 1 commit into
Conversation
…ld's pipe `process_subprocess_stream` reads the child's output until EOF, and only then does `run_with_log` call `proc.wait()` -- with the comment "Stream processing already waited for process completion". That assumption breaks whenever a grandchild outlives the child: EOF needs EVERY write end of the pipe closed, including the ones the grandchild inherited, so the reader stays blocked, `proc.wait()` is never reached, and `run_with_log` never returns a returncode. The caller hangs with no timeout. Seen in production on a two-node training job: the ranks aborted on an RDMA transport error, torchrun exited, but five orphaned multiprocessing-spawn children kept the stdout pipe open. The Ray task running the command never finished, so the managed-jobs controller reported the job as RUNNING for two hours while 16 GPUs sat idle. `kill_children_processes` cannot help: it walks the process tree, and the orphans are reparented to init, so they are no longer in it. The process group still reaches them -- `start_new_session=True` makes the child a group leader, so the group id is its pid, and neither reparenting nor reaping the leader moves the orphans out of that group. A watchdog thread now waits for the child, then waits a grace period for the readers to drain, and only if they are still blocked kills the leftover process group to force EOF. That trigger matters: an unconditional kill after exit would break commands that deliberately leave daemons in the group, such as `ray start`. When it does fire, the caller was already hung forever, so forcing EOF cannot lose anything that was still working. Test: a child that exits while a background grandchild holds its stdout. Without the fix it hangs (killed at 90 s); with it, `run_with_log` returns the child's exit code after the grace period. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
run_with_logcan hang forever. It reads the child's output until EOF and only then callsproc.wait(), on the assumption — stated in the code — that "Stream processing already waited for process completion". That assumption breaks whenever a grandchild outlives the child: EOF requires every write end of the pipe to be closed, including the ones the grandchild inherited. The reader stays blocked,proc.wait()is never reached, and the function never returns a returncode. There is no timeout on that path.A watchdog thread now waits for the child, gives the readers a grace period to drain, and only if they are still blocked kills the leftover process group to force EOF.
Why it matters
Observed in production on a two-node training job. The ranks aborted on an RDMA transport error and torchrun exited, but five orphaned
multiprocessing.spawnchildren kept the stdout pipe open:The Ray task running the command never finished, so the managed-jobs controller reported
JobStatus.RUNNINGfor two hours —#RECOVERIES 0— while 16 GPUs sat idle. Autorecovery cannot fire on a job that never reports failure.Why the process group
kill_children_processescannot reach these processes: it walks the process tree, and orphans are reparented to init, so they have left it. The group still reaches them —start_new_session=Truemakes the child a session and group leader, so the group id is simply its pid, and neither reparenting nor reaping the leader moves the orphans out of that group.Using
proc.piddirectly also avoids a race: a short-lived child is already a zombie by the time the watchdog starts, andos.getpgid()on it can fail. (My first attempt did exactly that, and silently degraded to a no-op.)Why the trigger is narrow
The kill fires only when the child has exited and the readers are still blocked after the grace period. That distinction is load-bearing: an unconditional group-kill after exit would break commands that deliberately leave daemons in the group,
ray startamong them. When the narrow condition does hold, the caller was already hung forever, so forcing EOF cannot lose anything that was still working.Testing
New test: a child that exits while a background grandchild holds its stdout.
run_with_logreturns the child's exit code after the grace periodtest_log_lib.pyyapf(pinned 0.32.0),isort, whitespace hooks clean.