Timeout from UI when deleting a DAG or DagRun

[rotemseekingalpha]

Apache Airflow version

2.3.2 (latest released)

What happened

When deleting Dag Runs or DAGs from the UI, the response is HTTP ERROR 504 (timeout).
I believe it mainly happens because the delete process relies on the foreign key cascade effect.
After investigating the issue in the database (PostgreSQL), I suspect the problem is the locks on the xcom table.
I found that multiple delete operations are performed on the xcom table, regardless of whether the task returns a value.
Could it be that the Airflow code tries to delete the relevant xcom value for every task instance?

What you think should happen instead

UI should not timeout

How to reproduce

Try to delete a DAG or a DagRun from UI in a large deployment of Airflow (hundreds of DAGs, task instances, and xcom values).

Operating System

Ubuntu 20.04.3 LTS

Versions of Apache Airflow Providers

apache-airflow-providers-amazon    @ apache_airflow_providers_amazon-4.0.0-py3-none-any.whl
apache-airflow-providers-ftp       @ apache_airflow_providers_ftp-3.0.0-py3-none-any.whl
apache-airflow-providers-http      @ apache_airflow_providers_http-3.0.0-py3-none-any.whl
apache-airflow-providers-imap      @ apache_airflow_providers_imap-3.0.0-py3-none-any.whl
apache-airflow-providers-mongo     @ apache_airflow_providers_mongo-3.0.0-py3-none-any.whl
apache-airflow-providers-mysql     @ apache_airflow_providers_mysql-3.0.0-py3-none-any.whl
apache-airflow-providers-pagerduty @ apache_airflow_providers_pagerduty-3.0.0-py3-none-any.whl
apache-airflow-providers-postgres  @ apache_airflow_providers_postgres-5.0.0-py3-none-any.whl
apache-airflow-providers-redis     @ apache_airflow_providers_redis-3.0.0-py3-none-any.whl
apache-airflow-providers-sendgrid  @ apache_airflow_providers_sendgrid-3.0.0-py3-none-any.whl
apache-airflow-providers-slack     @ apache_airflow_providers_slack-5.0.0-py3-none-any.whl
apache-airflow-providers-sqlite    @ apache_airflow_providers_sqlite-3.0.0-py3-none-any.whl
apache-airflow-providers-ssh       @ apache_airflow_providers_ssh-3.0.0-py3-none-any.whl
apache-airflow-providers-vertica   @ apache_airflow_providers_vertica-3.0.0-py3-none-any.whl

Deployment

Virtualenv installation

Deployment details

Python 3.8.10

Anything else

No response

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[uranusjr]

It’s likely. Since XCom has run_id and dag_id on it in the first place, we should probably avoid relying on CASCADE and just delete relevant XCom entries directly.

[ashb]

I'd be surprised if doing it ourselves is any quicker than letting postgres handle it itself. Could this be a case of missing indexes or the foreign side (i.e. on XCom). You added some recently didn't you @uranusjr ?

[uranusjr]

From the description

I found that multiple delete operations are performed on the xcom table, regardless of whether the task returns a value.
Could it be that the Airflow code tries to delete the relevant xcom value for every task instance?

it sounds like an N+1 situation. If that’s the case the problem is probably not the db cascading, but SQLAlchemy.

[rotemseekingalpha]

@uranusjr in addition, there are no indexes on foreign keys to task_instance table from xcom table:

explain 
select x.dag_id,   x.task_id
  from task_instance ti
  left join xcom x
    on (    x.dag_id = ti.dag_id
        and x.task_id = ti.task_id
        and x.run_id = ti.run_id
        and x.map_index = ti.map_index)
 where ti.dag_id = 'some_dag' 
   and ti.run_id = 'scheduled__2022-05-29T13:25:00+00:00';

Nested Loop Left Join  (cost=1000.55..61225.51 rows=26 width=41)
  Join Filter: (((x.dag_id)::text = (ti.dag_id)::text) AND ((x.run_id)::text = (ti.run_id)::text) AND ((x.task_id)::text = (ti.task_id)::text) AND (x.map_index = ti.map_index))
  ->  Index Scan using ti_dag_run on task_instance ti  (cost=0.56..107.77 rows=26 width=82)
        Index Cond: (((dag_id)::text = 'some_dag'::text) AND ((run_id)::text = 'scheduled__2022-05-29T13:25:00+00:00'::text))
  ->  Materialize  (cost=1000.00..61108.42 rows=16 width=81)
        ->  Gather  (cost=1000.00..61108.34 rows=16 width=81)
              Workers Planned: 2
              ->  Parallel Seq Scan on xcom x  (cost=0.00..60106.74 rows=7 width=81)
                    Filter: (((dag_id)::text = 'some_dag'::text) AND ((run_id)::text = 'scheduled__2022-05-29T13:25:00+00:00'::text))

[uranusjr]

I believe the index has been added for 2.3.3, via #24488.

[eladkal]

closed as fixed in 2.3.3 since no new reports on this bug since