GitHub user OswaldoRodriguez123 added a comment to the discussion: Task starts
time out on PUT /rtif after the 3.3.2 to 3.4.0 upgrade
## What the code does
`PUT /execution/task-instances/{id}/rtif` → `ti_put_rtif`
(`airflow-core/src/airflow/api_fastapi/execution_api/routes/task_instances.py:1383`)
→ `TaskInstance.update_rtif`
(`airflow-core/src/airflow/models/taskinstance.py:2671`), which does three
things in one transaction:
1. upsert the row into `rtif_v2` (`RenderedTaskInstanceFields.write` →
`set_for_attempt`),
2. `session.flush()`,
3. `RenderedTaskInstanceFields.delete_old_records(...)`
(`renderedtifields.py:296`).
So the cleanup is on the task-start critical path, in the same transaction as
the upsert, and it runs on every task start.
## Why the v2 DELETE is expensive
The v2 statement (`renderedtifields.py:366`) has no predicate on `rtif_v2`
itself:
```python
delete(cls).where(
select(1).where(
TaskInstance.id == cls.task_instance_id,
TaskInstance.dag_id == dag_id,
TaskInstance.task_id == task_id,
TaskInstance.run_id.not_in(run_ids_to_keep),
).exists()
)
```
`dag_id`/`task_id` live inside the correlated `EXISTS`, not on the delete
target. The planner therefore has two options, and both are bad:
- nested loop: seq scan all of `rtif_v2`, one `task_instance_pkey` lookup per
row;
- semi-join driven from `task_instance`: read every TI for `(dag_id, task_id)`
— 442k rows in your case.
Either way the cost is proportional to the total size of `rtif_v2` (or to those
442k TIs), not to the handful of rows actually being deleted. In 3.3.2 the
statement was `DELETE FROM rendered_task_instance_fields WHERE dag_id=$1 AND
task_id=$2 AND run_id NOT IN (...)`, which the PK `(dag_id, task_id, run_id,
map_index)` scoped directly. That scoping is what the 3.4 rewrite lost.
`rtif_v2` is created empty by `0142_3_4_0_unify_task_attempt_ownership.py` and
the migration never runs `ANALYZE` on it. Until autoanalyze fires, the planner
still believes it is empty, so it keeps picking the nested-loop plan while the
real row count grows with every task start. On a cold cache with
`shared_buffers=128MB` against a 2.8GB `task_instance`, each of those pkey
lookups is a random `DataFileRead` — exactly the wait event you captured. That
said, your recovery at 17:03 lines up with the end of the burst and the first
autovacuum, not with autoanalyze (17:07:11), so I would treat the stats angle
as a contributing factor rather than the whole story. The missing scoping is
wrong regardless of stats.
## Why the v1 DELETE shows lock waits
`_do_delete_old_records` (`renderedtifields.py:348`) always issues both
statements, v1 first. The v1 one is scoped by `(dag_id, task_id)`, so every
concurrent — and every retried — `PUT /rtif` for the same task deletes the same
rows and they serialize on row locks (`Lock/transactionid`).
`@retry_db_transaction` (default `[database] max_db_retries = 3`) re-runs the
whole pair on any `DBAPIError`, including lock timeouts, which multiplies the
load.
Also note that after 3.4 nothing writes `rtif_v1` anymore:
`RenderedTaskInstanceFields.write` only calls `set_for_attempt`, which upserts
`rtif_v2`. `rtif_v1` is a frozen compatibility mirror (renamed from
`rendered_task_instance_fields`, FK redirected to `legacy_task_data_owner`),
and the migration only copies v2 → v1 on **downgrade**. So the v1 DELETE is
pure cleanup of pre-upgrade rows and is a no-op forever after the first pass,
yet it still runs on every task start.
## Your three questions
1. **Is the v1 cleanup expected?** It is what the code does, but I would call
it a bug: it is unconditional, it can never find new rows after the upgrade,
and it is the statement that produces the lock waits. Worth reporting.
2. **Should the migration ANALYZE?** It does not, and it should — at least
`rtif_v2`, `xcom_v2`, `legacy_task_data_owner`. But ANALYZE alone would not
have saved you: with correct stats the planner would likely switch to the
semi-join that reads all 442k TIs for the task, which is also slow. The missing
scoping is the real defect. Still, `ANALYZE` after `airflow db migrate` is
cheap insurance and belongs in the chart's migrate job.
3. **Is `num_dag_runs_to_retain_rendered_fields = 0` + `airflow db clean`
sound?** Yes. `delete_old_records` returns before issuing any SQL when
`num_to_keep <= 0` (`renderedtifields.py:316`), so the whole cleanup leaves the
task-start path. And `airflow db clean` does remove RTIF rows indirectly:
`rtif_v2.task_instance_id` has `ON DELETE CASCADE` to `task_instance`, and
`rtif_v1` cascades through `legacy_task_data_owner` → `task_instance`. The
trade-off is that RTIF then lives as long as the TI, so your `db clean`
retention becomes the real bound. Run it with `--batch-size` in a maintenance
window the first time; 1.18M TIs / 2.8GB is a big first pass.
## What I would do now
- Keep `num_dag_runs_to_retain_rendered_fields = 0` and schedule `airflow db
clean`.
- Raise `[workers] execution_api_timeout` above your p99 (5s is below the 8s
you already saw on `PATCH /run`), and consider lowering `execution_api_retries`
so a slow request is not re-sent while the first one still holds the locks.
- Run `ANALYZE rtif_v2, xcom_v2, legacy_task_data_owner;` right after the
migration.
- Open the issue. The actionable finding is the unscoped v2 DELETE: it needs a
`(dag_id, task_id)` predicate on the delete target (denormalize those columns
onto `rtif_v2`, or delete by the `task_instance_id`s of the runs being evicted)
so the statement is O(rows deleted) instead of O(size of `rtif_v2`). Include
`EXPLAIN (ANALYZE, BUFFERS)` of the v2 DELETE on a copy of the DB if you can
reproduce it — that settles hypothesis 1 vs 2 immediately.
One more thing: `num_to_keep` is a **default argument** evaluated at import
time (`num_to_keep: int = conf.getint(...)`), so changing the config requires
an API server restart, not just a config reload. Your new pods at 17:07 covered
that, but it is easy to trip over.
GitHub link:
https://github.com/apache/airflow/discussions/76774#discussioncomment-19549310
----
This is an automatically sent email for [email protected].
To unsubscribe, please send an email to: [email protected]
