Deaths Without a Log
Concepts covered: Task instance states
A task's log usually ends with a verdict. A success ends with the task's own last line and a return code of 0; a failure ends with a traceback, the exception's name, and a line from the task runner saying the task failed. Some logs end mid-sentence, with loaded 1,200,000 of 3,400,000 rows as the last line, neither a traceback nor a return code after it, and a state that stays unchanged for 5 minutes. A log that stops without a verdict means the process that would have written the verdict is gone, and Airflow has 3 ways of noticing, each leaving a different trace. The intermediate lesson's execution_timeout belongs with the failures that leave a log: the runner raises AirflowTaskTimeout inside the task, so the traceback is there and the state changes at once.
| Last lines in the log | What happened | Who records the failure, and when |
|---|---|---|
| A traceback, then the runner's line that the task failed | The task's code raised | The task's own runner, at once |
| A single runner line giving a negative return code, -9 for a kill | The kernel killed the task process; the worker is alive | The supervisor on the worker, at once |
| The log stops mid-line; later a line names the instance a zombie | The worker, pod or host died | The scheduler, after the heartbeat timeout |
| A line that the state was externally set, then termination | A person marked it failed or cleared it while running | The supervisor, on its next heartbeat |
The heartbeat
Every running task has 2 processes on its worker: the task process and a supervisor that started it. The supervisor sends a heartbeat to the API server on a short interval, [workers] min_heartbeat_interval, 5 seconds by default, and each heartbeat updates the task instance's last heartbeat time. The scheduler looks for running task instances whose last heartbeat is older than [scheduler] task_instance_heartbeat_timeout, 300 seconds by default. Each one it finds is treated as a failed try: a line naming the instance a zombie goes into its log, and the instance passes through the same failure handling a raised exception gets, so the cell goes to up_for_retry if retries are left and to failed if not. The matching callback, on_retry_callback or on_failure_callback, fires.
| Clock | On the worker | In Airflow |
|---|---|---|
| 02:14:03 | The node loses power; task and supervisor stop | Last heartbeat on record: 02:14:00 |
| 02:14:00 to 02:19:00 | Nothing | Cell stays `running`, log unchanged |
| 02:19:10 | Nothing | Scheduler finds the heartbeat 5 min 10 s old, marks the try failed, cell to `up_for_retry` |
| 02:24:10 | Try 2 starts on another worker | Cell to `running`, `retry_delay` of 5 min served |
The 5 minutes are the price of telling a dead worker from a slow network, and the retry's wait starts after them. The gap applies only when the supervisor dies with the task: a host that loses power, an evicted pod, a container killed whole at its memory limit. A retry treats the cause as transient, which fits an evicted pod and does not fit a task that exceeds its memory limit, because the next try is killed at the same row count. With retries=3 and the default 5 minute retry_delay, one death becomes 4, each noticed 5 minutes after it happened: 20 minutes of detection plus 15 minutes of waits, 35 minutes on top of the running time before anyone is paged. The pattern to read for is a kill at the same point in the log on every try, which names the task's memory as the problem and the retry count as noise. A kill at a different point each time, on different workers, points at the hosts instead.
Killed with the worker still alive
When the kernel's out-of-memory killer takes only the task process, the supervisor survives it, sees the child end on a signal rather than a return code, and reports the try as failed at once with a line giving the negative code, -9 for a kill. The log still has no traceback, because no Python ran after the signal. The worker's own logs, or the pod's events on a container platform, carry the reason: an OOMKilled event with the limit it hit. A termination signal instead of a kill, which is what a worker shutdown sends, lets Python run: the task raises on the signal, the log ends with a traceback naming SIGTERM, and the try fails through the ordinary path with its retries intact.
Killed on purpose
Marking a running task failed in the UI, or clearing it, changes the state in the database first. The supervisor learns of the change on its next heartbeat, because the API server answers a heartbeat for a task whose state is no longer running by telling the supervisor to stop. It terminates the task and writes that the state was set externally. The log therefore carries a verdict, written within about 5 seconds of the click, and the next try number belongs to the clear. A log that ends with that line, next to an audit log entry with a person's name, belongs to a task that someone stopped by hand.
Lowering task_instance_heartbeat_timeout below 300 seconds buys faster detection at the cost of failing healthy tasks during a slow network or a busy API server; raise it only for workers that are known to pause, and change neither without watching the zombie count for a week.
About this lesson
This section is part of the Task Lifecycle: Advanced lesson on DataDriven, the home of data engineering. Lessons cover SQL, Python, Spark, data modeling and pipeline architecture, and each section pairs its explanation with worked examples and practice you run as you go.