buhuipao opened a new pull request, #76423:
URL: https://github.com/apache/airflow/pull/76423
The triggerer supervisor reads the runner's sockets once per loop pass: one
4 KiB `recv` on the log socket and at most one request frame. The rest of the
pass is database work. The runner writes its logs with a blocking write from
inside its event loop. When triggers log faster than about 4 KiB times the loop
passes per second, the log socket fills up and the runner's event loop stops
inside that write. No trigger runs, no state sync reaches the supervisor, and
after `runner_health_check_threshold` the supervisor skips its heartbeat
("TriggerRunner subprocess event loop appears deadlocked"). The triggers then
move to the other triggerers, which pushes the same load onto them.
It can also deadlock. The supervisor sends each reply with a blocking
`sendall()`. A `TriggerStateSync` that carries many new triggers, for example
right after a reassignment, is larger than the socket buffer. If the runner is
blocked in a log write at that moment, it never reads the reply, and the
supervisor never reads the logs. Both processes wait until something kills the
triggerer. Stack dumps from both sides of a stuck run:
```
supervisor: run_once -> _handle_request -> send_msg -> sendall
runner: run_trigger -> DateTimeTrigger.run -> log.info ->
BytesLogger.msg -> write
```
This change:
* drains all runner output that is already waiting on each loop pass, up to
one second, instead of a single 4 KiB read;
* sends replies to the runner without blocking, and reads the runner's
output sockets while a reply cannot be written yet.
I reproduced this on Linux with the real `TriggerRunnerSupervisor` and
runner, with only the database calls replaced by 20 ms sleeps: 1,000
`DateTimeTrigger`s at INFO level, each re-armed 60 s after it fires.
| | Before (5 runs) | After (5 runs) |
|---|---|---|
| Runs with a runner silence over 30 s | 5 (longest 52–128 s) | 0 (longest
1.4 s) |
| Runs that deadlocked | 2 | 0 |
| Trigger fire latency p50 / p99 | 16–20 s / ~51 s | 0.9–1.2 s / 1.7–1.9 s |
With the fix, two more runs that also assigned 1,000 extra triggers at once
60 s in (like a reassignment) stayed healthy: longest silence 5.1–5.3 s, p99
fire latency 4.1–4.9 s.
Reading the output sockets during a send means an event from the caller's
earlier `select()` can point at a socket that is already empty. The triggerer's
output sockets are therefore switched to non-blocking, and
`_service_subprocess` treats `BlockingIOError` from a handler as "nothing to
read yet". For the same reason `make_buffered_socket_reader` now forgets the
trailing fragment after sending it at EOF, so a second EOF does not send it
again. The test fixtures that captured replies through `stdin.sendall` now
capture them through `stdin.send`.
The synchronous remote log upload for finished triggers in `_handle_request`
also slows the loop down. It is left out of this PR, because moving it to the
background changes when a trigger's log file can be reused by the next deferral
of the same task try.
---
##### Was generative AI tooling used to co-author this PR?
- [X] Yes — Claude Code (Opus 5.5)
Generated-by: Claude Code (Opus 5.5) following [the
guidelines](https://github.com/apache/airflow/blob/main/contributing-docs/05_pull_requests.rst#gen-ai-assisted-contributions)
--
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]
