roshanprabu opened a new pull request, #71345:
URL: https://github.com/apache/airflow/pull/71345
## 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`):
```python
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:
```python
try:
...
exit_code = proc.wait()
except BaseException:
proc.kill()
proc.wait()
raise
```
## Test plan
- [x] 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.
- [x] 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.
- [x] Added `TestExecuteInSubprocess` with 4 tests: prompt interruption
timing, no orphaned child process, happy-path success, and non-zero exit still
raises `CalledProcessError` as before.
- [x] 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.
- [x] Ran the full test file: `pytest
tests/unit/standard/utils/test_python_virtualenv.py` -- **23 passed**.
- [x] `ruff check` and `ruff format --check` pass on both changed files.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
