Skip to content

Fix execution_timeout not interrupting a hung virtualenv subprocess - #71345

Open
roshanprabu wants to merge 1 commit into
apache:mainfrom
roshanprabu:fix-virtualenv-timeout-orphaned-subprocess
Open

Fix execution_timeout not interrupting a hung virtualenv subprocess#71345
roshanprabu wants to merge 1 commit into
apache:mainfrom
roshanprabu:fix-virtualenv-timeout-orphaned-subprocess

Conversation

@roshanprabu

Copy link
Copy Markdown

Summary

Fixes #57712.

@task.virtualenv / @task.external_python run the user's callable in a subprocess via _execute_in_subprocess (providers/standard/src/airflow/providers/standard/utils/python_virtualenv.py):

with subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, ...) as proc:
    for line in iter(proc.stdout.readline, b""):
        log.info(...)
    exit_code = proc.wait()

execution_timeout is enforced by TimeoutPosix (task-sdk/.../timeout.py), which sets a SIGALRM that raises AirflowTaskTimeout from inside whatever's currently running -- here, that's the blocking readline()/wait() call above.

The bug: subprocess.Popen.__exit__ only closes the pipes and calls proc.wait() again on its way out -- it does not kill the child. If the child is still running when the exception fires (e.g. blocked on an open HTTP connection, per the linked issue's repro), that second wait() blocks until the child exits on its own, silently absorbing the timeout for however long that takes. This matches the reported symptom exactly: "shows in the logs as timeout, but the task keeps in running state" -- the log line comes from the signal handler firing correctly, but the task doesn't actually finish timing out until the child process happens to exit.

I verified this precisely with a standalone repro before touching any code (with subprocess.Popen(...), SIGALRM at 1s, child sleep(8)): the exception was only actually caught after the full 8 seconds, not the 1 second the alarm was set for.

Fix

Catch the exception around the read/wait, explicitly proc.kill() + proc.wait() to reap the child, then re-raise:

try:
    ...
    exit_code = proc.wait()
except BaseException:
    proc.kill()
    proc.wait()
    raise

Test plan

  • Reproduced standalone against the actual (pre-fix) _execute_in_subprocess: caught the timeout exception only after the full child runtime (8s), not the 1s alarm.
  • Re-verified against the fixed version: exception caught at ~1.0s, and confirmed via a subprocess.Popen spy that the child process is actually dead (not orphaned) ~0.5s after.
  • Added TestExecuteInSubprocess with 4 tests: prompt interruption timing, no orphaned child process, happy-path success, and non-zero exit still raises CalledProcessError as before.
  • Verified the new timing test actually catches the regression: reverted the source fix, ran it, and confirmed it fails (32.31s vs the asserted < 10s) with the exact same log line from the report ("Executing cmd... Output:" followed by the full sleep duration before the assertion fires); re-applied the fix and confirmed it passes.
  • Ran the full test file: pytest tests/unit/standard/utils/test_python_virtualenv.py -- 23 passed.
  • ruff check and ruff format --check pass on both changed files.

_execute_in_subprocess used `with subprocess.Popen(...) as proc:` and
relied on the timeout signal handler's exception propagating out of the
block. But Popen's __exit__ only closes the pipes and calls proc.wait()
again on the way out -- it does not kill the child. If the child is
still running (blocked on something long, like an open network
connection inside a @task.virtualenv/@task.external_python callable),
that wait() blocks until the child exits on its own, silently absorbing
the timeout for however long that takes -- observed as the task instance
staying in "running" state indefinitely despite the timeout being logged.

Verified this precisely with a standalone repro (SIGALRM firing at 1s,
child sleeping 8s): the exception was only actually caught after the
full 8s, not the 1s the alarm was set for.

Fix: catch any exception around the read/wait, explicitly proc.kill()
and proc.wait() to reap it, then re-raise -- so the timeout is honored
promptly and the child doesn't linger as an orphan holding resources.

Closes: apache#57712
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Task execution_timeout parameter not respected for virtualenv operator

1 participant