GitHub user manucorujo created a discussion: Task starts time out on PUT /rtif
after the 3.3.2 to 3.4.0 upgrade
After we upgraded from 3.3.2 to 3.4.0, most tasks failed for about 10 minutes
when they started, before user code ran. We cannot reproduce it on demand, so
we ask here before we open an issue.
**Setup**
- Official Helm chart 1.22.0, KubernetesExecutor, 2 API server replicas,
task-sdk 1.4.0, `[workers] execution_api_timeout` = 5 s,
`execution_api_retries` = 5.
- Metadata DB: PostgreSQL 18.6 behind PgBouncer, `shared_buffers` 128 MB,
`work_mem` 4 MB. `task_instance` has 1.18M rows (2.8 GB). One `(dag_id,
task_id)` has 442k rows. `dag_run` has 1.02M rows. We did not run `airflow db
clean`.
**What happened (UTC)**
- 16:38 to about 16:53: the migration ran. No task ran in that time.
- 16:55 to 17:02: tasks failed with `ReadTimeout` after the Task SDK retried
`PUT /execution/task-instances/{id}/rtif`. Per minute, 21 to 39 `PUT /rtif`
requests took more than 5 s on the server, and the maximum was 299 s. `PATCH
/run` took at most 8 s. 126 task starts sent 309 `PUT /rtif` requests.
- At the same time, `pg_stat_activity` showed about 20 active statements from
`RenderedTaskInstanceFields.delete_old_records`, which `ti_put_rtif` calls on
every task start (via `TaskInstance.update_rtif`):
```sql
-- 1 to 13 s each, wait_event DataFileRead / AioIoCompletion
DELETE FROM rtif_v2 WHERE EXISTS (SELECT 1 FROM task_instance
WHERE task_instance.id = rtif_v2.task_instance_id
AND task_instance.dag_id = $1 AND task_instance.task_id = $2
AND (task_instance.run_id NOT IN (SELECT dag_run.run_id FROM dag_run
WHERE dag_run.dag_id = $3 ORDER BY dag_run.run_after DESC LIMIT $4)))
RETURNING rtif_v2.id
-- wait_event Lock / transactionid
DELETE FROM rtif_v1 WHERE rtif_v1.dag_id = $1 AND rtif_v1.task_id = $2 AND
(rtif_v1.run_id NOT IN (...))
-- wait_event Lock / transactionid or tuple, up to 44 s
INSERT INTO rtif_v2 (id, task_instance_id, rendered_fields, k8s_pod_yaml)
VALUES (...)
ON CONFLICT (task_instance_id) DO UPDATE ...
```
- 17:03: it recovered without any change from us. The `PUT /rtif` maximum fell
from 155 s (17:02) to 24 s (17:03), then 7 s (17:05). The first autovacuum of
`rtif_v2` ran at 17:03:11. The first autoanalyze ran at 17:07:11. The burst of
task starts after the migration also ended at about that time.
- Later we set `[core] num_dag_runs_to_retain_rendered_fields = 0` (the new
pods were up at 17:07). `delete_old_records` now returns at once. It did not
end the incident, because the recovery started before it.
**What we think happened**
The `rtif_v2` DELETE in 3.4.0 (from #74222) joins `task_instance`. In 3.3.2 the
cleanup was a DELETE on `rendered_task_instance_fields` that its primary key
covered. Now the `EXPLAIN` of the `rtif_v2` DELETE is cheap: a seq scan of
`rtif_v2` and one `task_instance_pkey` lookup per row. We did not capture the
plan during the incident, so we see two possible causes:
1. `rtif_v2` had no statistics after the migration, and the planner started
from `task_instance` through `ti_state_lkp (dag_id, task_id, run_id, state)`.
That reads every run of the task (up to 442k rows) with a cold cache.
2. The burst after the migration and the client retries: the client gave up
after 5 s and sent the same `PUT /rtif` again while the API server still ran
the first request. Requests for the same task instance then waited on the same
row locks.
**Questions**
1. Is it expected that the `rtif_v1` cleanup still runs on every task start
after the migration to `rtif_v2`?
2. The migration creates `rtif_v2`, `xcom_v2` and `legacy_task_data_owner` and
does not run `ANALYZE` on them. Our first autoanalyze of `rtif_v2` came 14
minutes after the migration. Should the migration run `ANALYZE`, or should
deployments do it after the upgrade?
3. Is `num_dag_runs_to_retain_rendered_fields = 0` with a scheduled `airflow db
clean` a good long-term setting? Or is there a better way to keep this cleanup
out of the task start path?
If this looks like a bug, we can open an issue with this data.
---
Drafted-by: Claude Code (Opus 5.5); reviewed by @manucorujo before posting
GitHub link: https://github.com/apache/airflow/discussions/76774
----
This is an automatically sent email for [email protected].
To unsubscribe, please send an email to: [email protected]
