Preserve sensor start_date when scheduler advances reschedule to queued#66790
Open
1fanwang wants to merge 1 commit into
Open
Preserve sensor start_date when scheduler advances reschedule to queued#667901fanwang wants to merge 1 commit into
1fanwang wants to merge 1 commit into
Conversation
d89cd36 to
7ac3847
Compare
1 task
When a sensor runs in mode="reschedule", the supervisor sends start_date=utcnow() on every poke. The ti_run execution-API endpoint wrote that value through unconditionally, so ti.start_date drifted forward on each re-execution. dagrun.first_task_scheduling_delay (computed from start_date - queued_at) collapsed to ~0 for any DAG fronted by a reschedule-mode sensor. Add a reschedule guard in ti_run that mirrors the existing deferral guard: when start_date is present in the payload and the task has prior TaskReschedule rows, restore start_date from the first row instead of accepting the supervisor's utcnow(). The lookup is scoped by ti_id, and prepare_db_for_next_try clears TaskReschedule rows and rotates ti.id on each retry, so try-number scoping is implicit and no stale rows leak across tries. Also mirror context.start_date in the response so the supervisor pins context["ti"].start_date to the first poke as well. Also drop the unreliable state guard on the same path in _check_and_change_state_before_execution. In the normal multi-scheduler flow the scheduler advances UP_FOR_RESCHEDULE -> QUEUED before the worker calls this method, so refresh_from_db returns QUEUED and the guard never fires. The TaskReschedule lookup is harmless for non-rescheduled tasks (returns no rows), so the guard can go. Closes apache#66784 Co-authored-by: peachchen0716 <peachchen0716@users.noreply.github.com> Signed-off-by: 1fanwang <1fannnw@gmail.com>
7ac3847 to
c9e4c09
Compare
1 task
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fix for the metric skew called out in #66784. On our LinkedIn DI cluster every poke of a reschedule-mode sensor resets
start_datetoutcnow(), which inflatesfirst_task_scheduling_delayby the cumulative wait of all reschedules. Our scheduling-delay dashboards skew high enough that they mask real scheduling delay. This PR preserves the originalstart_dateacross reschedule → queued transitions.Problem
A sensor in
mode="reschedule"loses its first-pokestart_dateon every re-execution. The supervisor sendsstart_date=utcnow()as part of theti_runexecution-API payload on each poke, and the endpoint writes that value through unconditionally. Net effect:dagrun.first_task_scheduling_delay(computed fromstart_date - queued_at) collapses to ~0 for any DAG fronted by a reschedule-mode sensor, even when the sensor waited minutes or hours.A guard already exists for deferred tasks at
airflow-core/src/airflow/api_fastapi/execution_api/routes/task_instances.py:180-182:There is no equivalent for rescheduled tasks. A legacy guard exists in
_check_and_change_state_before_execution(airflow-core/src/airflow/models/taskinstance.py:1315) but is gated onti.state == UP_FOR_RESCHEDULE, which never holds at the time the worker runs the check: the scheduler transitionsUP_FOR_RESCHEDULE -> QUEUEDbefore the worker picks up the task, sorefresh_from_dbreturnsQUEUEDand the lookup is skipped.Fix
Two changes:
task_instances.py::ti_run(production path) — Whenstart_dateis present in the payload and the task has priorTaskReschedulerows, restorestart_datefrom the first row instead of acceptingutcnow(). Mirror the same value intocontext.start_dateon the response so the supervisor pinscontext["ti"].start_dateto the first poke as well.taskinstance.py::_check_and_change_state_before_execution(legacy / test-utility path) — Drop theti.state == UP_FOR_RESCHEDULEgate. The lookup is scoped byti.id, andprepare_db_for_next_tryclearsTaskReschedulerows and rotatesti.idon each retry, so try-number scoping is implicit and the query is harmless for non-rescheduled tasks.Why try_number scoping is implicit
prepare_db_for_next_try(airflow-core/src/airflow/models/taskinstance.py:973-979):On every retry, all
TaskReschedulerows for the previous try'sti.idare deleted and the TI gets a fresh UUID. So rows withti_id == current task_instance_idalways belong to the current try. No additionaltry_numberfilter is needed.Reproducer
Before the fix,
ti.start_dateadvances by ~poke_intervalon every reschedule. After the fix,ti.start_datestays pinned at the first-poke value anddagrun.first_task_scheduling_delayreflects the actual wait.Tests
airflow-core/tests/unit/api_fastapi/execution_api/versions/head/test_task_instances.py::TestTIRunState::test_ti_run_restores_start_date_for_rescheduled_task-- the API path restoresstart_datefromTaskRescheduleon a subsequent pokeairflow-core/tests/unit/api_fastapi/execution_api/versions/head/test_task_instances.py::TestTIRunState::test_ti_run_uses_payload_start_date_when_no_reschedule_rows-- non-rescheduled tasks preserve the payload valueairflow-core/tests/unit/models/test_taskinstance.py::TestTaskInstance::test_check_and_change_state_before_execution_restores_reschedule_start_date-- the legacy method restoresstart_dateeven when the scheduler has already advanced state toQUEUEDPrior effort
Same fix was attempted earlier in #64816 by @peachchen0716 — converged on the same two changes (reschedule guard in
ti_run+ drop theUP_FOR_RESCHEDULEgate in_check_and_change_state_before_execution). That PR was converted to draft on 2026-04-22 over merge conflicts and unresolved review comments, and auto-closed on 2026-05-05 after author inactivity. This PR uses the existingTR.stmt_for_task_instancehelper in place of the hand-rolledselectthere, and mirrors the restored value intocontext.start_dateon the response so the supervisor pinscontext["ti"].start_dateto the first poke as well. peachchen0716 is credited as co-author on the commit.Closes #66784