Skip to content

Commit 976c1d0

Browse files
authored
Fix scheduler crash when retrying a task that timed out or was killed externally (#75472)
The database callback sink committed and closed the scheduler's scoped session when sending a callback, detaching the task instance the scheduler was about to retry. Archiving the attempt then wrote nothing, and inserting the next attempt hit the task_instance_current_key unique constraint, which stopped the scheduler. The sink now adds the request to the caller's session, and the scheduler commits it. The Dag-lookup-failure branch of executor event processing passes its session to set_state for the same reason.
1 parent b9ae12a commit 976c1d0

4 files changed

Lines changed: 131 additions & 6 deletions

File tree

‎airflow-core/src/airflow/callbacks/database_callback_sink.py‎

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -19,9 +19,9 @@
1919

2020
from typing import TYPE_CHECKING
2121

22+
from airflow import settings
2223
from airflow.callbacks.base_callback_sink import BaseCallbackSink
2324
from airflow.models.db_callback_request import DbCallbackRequest
24-
from airflow.utils.session import NEW_SESSION, provide_session
2525

2626
if TYPE_CHECKING:
2727
from sqlalchemy.orm import Session
@@ -32,8 +32,14 @@
3232
class DatabaseCallbackSink(BaseCallbackSink):
3333
"""Sends callbacks to database."""
3434

35-
@provide_session
36-
def send(self, callback: CallbackRequest, *, session: Session = NEW_SESSION) -> None:
37-
"""Send callback for execution."""
35+
def send(self, callback: CallbackRequest, *, session: Session | None = None) -> None:
36+
"""
37+
Send callback for execution.
38+
39+
The request is added to ``session``, or to the thread's scoped session when none is given,
40+
without committing: the caller commits it with the rest of its transaction.
41+
"""
42+
if session is None:
43+
session = settings.get_session()()
3844
db_callback = DbCallbackRequest(callback=callback, priority_weight=1)
3945
session.add(db_callback)

‎airflow-core/src/airflow/executors/base_executor.py‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -836,6 +836,8 @@ def send_callback(self, request: CallbackRequest) -> None:
836836
Send callback for execution.
837837
838838
Provides a default implementation which sends the callback to the `callback_sink` object.
839+
The scheduler's database sink adds the request to the calling thread's scoped session
840+
without committing, so the caller must commit that session.
839841
840842
:param request: Callback request to be executed.
841843
"""

‎airflow-core/src/airflow/jobs/scheduler_job_runner.py‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1740,7 +1740,7 @@ def process_executor_events(
17401740
ti.handle_failure(error=msg, session=session)
17411741
continue
17421742
cls.logger().exception("Marking task instance %s as %s", ti, state)
1743-
ti.set_state(state)
1743+
ti.set_state(state, session=session)
17441744
continue
17451745
ti.task = task
17461746
if task.has_on_retry_callback or task.has_on_failure_callback:
@@ -2212,8 +2212,10 @@ def _do_scheduling(self, session: Session) -> int:
22122212
for dag_run, callback_to_run in callback_tuples:
22132213
dag = cached_get_dag(dag_run)
22142214
if dag:
2215-
# Sending callbacks to the database, so it must be done outside of prohibit_commit.
22162215
self._send_dag_callbacks_to_processor(dag, callback_to_run)
2216+
# The sink only adds the request to this session. Commit each one so a later Dag
2217+
# lookup error, or the critical section below rolling back, can't lose it.
2218+
session.commit()
22172219
else:
22182220
self.log.error("DAG '%s' not found in serialized_dag table", dag_run.dag_id)
22192221

‎airflow-core/tests/unit/jobs/test_scheduler_job.py‎

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -225,6 +225,16 @@ def get_callback_ti(ti):
225225
)
226226

227227

228+
def _attempt_states(ti, session):
229+
attempts = session.scalars(
230+
select(TaskInstance)
231+
.where(TaskInstance.dag_id == ti.dag_id, TaskInstance.task_id == ti.task_id)
232+
.execution_options(include_all_attempts=True)
233+
.order_by(TaskInstance.try_number)
234+
)
235+
return [(attempt.try_number, attempt.state, attempt.working_set) for attempt in attempts]
236+
237+
228238
@pytest.fixture(scope="class")
229239
def disable_load_example():
230240
with conf_vars({("core", "load_examples"): "false"}):
@@ -1247,6 +1257,84 @@ def test_process_executor_events_with_callback(
12471257
},
12481258
)
12491259

1260+
@pytest.mark.parametrize(
1261+
"callback_kwargs",
1262+
[
1263+
pytest.param({"on_failure_callback": lambda context: None}, id="on_failure_callback"),
1264+
pytest.param({"email": "[email protected]"}, id="email"),
1265+
],
1266+
)
1267+
def test_process_executor_events_callback_for_running_ti_with_retries_moves_it_to_retry(
1268+
self, callback_kwargs, dag_maker, session
1269+
):
1270+
"""Sending the callback must not close the session and detach the TI before its retry is set up."""
1271+
with dag_maker(dag_id="executor_event_running_ti_with_retries", fileloc="/test_path1/"):
1272+
EmptyOperator(task_id="task", retries=1, **callback_kwargs)
1273+
dr = dag_maker.create_dagrun()
1274+
ti = dr.task_instances[0]
1275+
executor = MockExecutor(do_update=False)
1276+
executor.callback_sink = DatabaseCallbackSink()
1277+
scheduler_job = Job()
1278+
session.add(scheduler_job)
1279+
session.flush()
1280+
self.job_runner = SchedulerJobRunner(scheduler_job, executors=[executor])
1281+
ti.state = State.RUNNING
1282+
ti.try_number = 1
1283+
ti.queued_by_job_id = scheduler_job.id
1284+
session.merge(ti)
1285+
session.commit()
1286+
executor.event_buffer[TaskInstanceUuid(ti.id)] = State.SUCCESS, None
1287+
1288+
self.job_runner._process_executor_events(executor=executor, session=session)
1289+
session.commit()
1290+
1291+
session.expire_all()
1292+
assert _attempt_states(ti, session) == [
1293+
(1, State.FAILED, None),
1294+
(2, State.UP_FOR_RETRY, True),
1295+
]
1296+
assert session.scalar(select(func.count()).select_from(DbCallbackRequest)) == 1
1297+
1298+
def test_process_executor_events_dag_lookup_failure_keeps_session_for_rest_of_batch(
1299+
self, dag_maker, session
1300+
):
1301+
"""A failed Dag lookup must not close the session and detach the rest of the batch."""
1302+
with dag_maker(dag_id="executor_event_dag_lookup_failure"):
1303+
EmptyOperator(task_id="first", retries=1)
1304+
EmptyOperator(task_id="second", retries=1)
1305+
dr = dag_maker.create_dagrun()
1306+
executor = MockExecutor(do_update=False)
1307+
scheduler_job = Job()
1308+
session.add(scheduler_job)
1309+
session.flush()
1310+
self.job_runner = SchedulerJobRunner(scheduler_job, executors=[executor])
1311+
for ti in dr.task_instances:
1312+
ti.state = State.RUNNING
1313+
ti.try_number = 1
1314+
ti.queued_by_job_id = scheduler_job.id
1315+
session.merge(ti)
1316+
executor.event_buffer[TaskInstanceUuid(ti.id)] = State.SUCCESS, None
1317+
session.commit()
1318+
real_get_dag_for_run = self.job_runner.scheduler_dag_bag.get_dag_for_run
1319+
lookup_errors = [AirflowException("Dag lookup failed")]
1320+
1321+
def get_dag_for_run(*, dag_run, session):
1322+
if lookup_errors:
1323+
raise lookup_errors.pop()
1324+
return real_get_dag_for_run(dag_run=dag_run, session=session)
1325+
1326+
with mock.patch.object(
1327+
self.job_runner.scheduler_dag_bag, "get_dag_for_run", autospec=True, side_effect=get_dag_for_run
1328+
):
1329+
self.job_runner._process_executor_events(executor=executor, session=session)
1330+
session.commit()
1331+
1332+
session.expire_all()
1333+
live_states = sorted(
1334+
session.scalars(select(TaskInstance.state).where(TaskInstance.dag_id == dr.dag_id))
1335+
)
1336+
assert live_states == [State.SUCCESS, State.UP_FOR_RETRY]
1337+
12501338
@mock.patch("airflow.jobs.scheduler_job_runner.TaskCallbackRequest")
12511339
def test_process_executor_events_callback_for_removed_mapped_task(
12521340
self, mock_task_callback, dag_maker, session
@@ -10632,6 +10720,33 @@ def test_heartbeat_timeout_sets_callback_type_by_retry_eligibility(
1063210720
)
1063310721
assert dispatched_callback == expected_dispatched_callback
1063410722

10723+
def test_heartbeat_timeout_with_retries_moves_ti_to_retry(self, dag_maker, session):
10724+
"""Sending the heartbeat-timeout callback must not close the purge's session and detach the TI."""
10725+
with dag_maker(dag_id="hb_timeout_with_retries", session=session):
10726+
EmptyOperator(task_id="test_task", retries=1)
10727+
dag_run = dag_maker.create_dagrun(run_id="test_run", state=DagRunState.RUNNING)
10728+
executor = MockExecutor(do_update=False)
10729+
executor.callback_sink = DatabaseCallbackSink()
10730+
scheduler_job = Job()
10731+
session.add(scheduler_job)
10732+
session.flush()
10733+
self.job_runner = SchedulerJobRunner(scheduler_job, executors=[executor])
10734+
ti = dag_run.get_task_instance(task_id="test_task", session=session)
10735+
ti.state = TaskInstanceState.RUNNING
10736+
ti.try_number = 1
10737+
ti.queued_by_job_id = scheduler_job.id
10738+
ti.last_heartbeat_at = timezone.utcnow() - timedelta(seconds=600)
10739+
session.commit()
10740+
10741+
self.job_runner._find_and_purge_task_instances_without_heartbeats()
10742+
10743+
session.expire_all()
10744+
assert _attempt_states(ti, session) == [
10745+
(1, TaskInstanceState.FAILED, None),
10746+
(2, TaskInstanceState.UP_FOR_RETRY, True),
10747+
]
10748+
assert session.scalar(select(func.count()).select_from(DbCallbackRequest)) == 1
10749+
1063510750
@pytest.mark.parametrize(
1063610751
("retries", "callback_kind", "expected"),
1063710752
[

0 commit comments

Comments
 (0)