[AIRFLOW-6175] fixes scheduler queue bug #6732

dimberman · 2019-12-05T00:00:45Z

Make sure you have checked all steps below.

Jira

My PR addresses the following Airflow Jira issues and references them in the PR title. For example, "[AIRFLOW-XXX] My Airflow PR"
- https://issues.apache.org/jira/browse/AIRFLOW-6175
- In case you are fixing a typo in the documentation you can prepend your commit with [AIRFLOW-XXX], code changes always need a Jira issue.
- In case you are proposing a fundamental code change, you need to create an Airflow Improvement Proposal (AIP).
- In case you are adding a dependency, check if the license complies with the ASF 3rd Party License Policy.

Description

Here are some details about my PR, including screenshots of any UI changes:

There is a bug caused by scheduler_jobs refactor which leads to task failure and scheduler locking.

Essentially when a there is an overflow of tasks going into the scheduler, the tasks are set back to scheduled, but are not removed from the executor's queued_tasks queue.

This means that the executor will attempt to run tasks that are in the scheduled state, but those tasks will fail dependency checks. Eventually the queue is filled with scheduled tasks, and the scheduler can no longer run.

Tests

My PR adds the following unit tests OR does not need testing for this extremely good reason:

Commits

My commits all reference Jira issues in their subject lines, and I have squashed multiple commits if they address the same issue. In addition, my commits follow the guidelines from "How to write a good git commit message":
1. Subject is separated from body by a blank line
2. Subject is limited to 50 characters (not including Jira issue reference)
3. Subject does not end with a period
4. Subject uses the imperative mood ("add", not "adding")
5. Body wraps at 72 characters
6. Body explains "what" and "why", not "how"

Documentation

In case of new functionality, my PR adds documentation that describes how to use it.
- All the public functions and the classes in the PR contain docstrings that explain what it does
- If you implement backwards incompatible changes, please leave a note in the Updating.md so we can assign it to a appropriate release

ashb · 2019-12-05T10:50:10Z

Need a jira for this please @dimberman

tests/executors/test_executor.py

tests/jobs/test_scheduler_job.py

ashb · 2019-12-05T11:00:58Z

tests/jobs/test_scheduler_job.py

+                                 executor=executor,
+                                 subdir=os.path.join(settings.DAGS_FOLDER,
+                                                     "no_dags.py"))
+        mock.patch.object(scheduler, '_change_state_for_tis_without_dagrun').start()


Do we need to patch this?

Yes. Otherwise the tasks won't run because they don't have an associated DagRun.

tests/jobs/test_scheduler_job.py

dimberman · 2019-12-05T18:24:31Z

@ashb this bug has a jira https://issues.apache.org/jira/browse/AIRFLOW-6175

kaxil · 2019-12-05T18:25:28Z

We have merge conflicts :( - can you fix that please

dimberman · 2019-12-05T18:35:33Z

@kaxil fixed conflicts. @ashb addressed comments.

KevinYang21

Thanks for fixing this! I'm wondering why the executor starts to run task in the scheduled state. Thought any task sent to the executor would be removed from queue_tasks and be moved to running_tasks and thus the state won't be set back to scheduled.

tests/jobs/test_scheduler_job.py

Co-Authored-By: Kaxil Naik <[email protected]>

kaxil · 2019-12-05T19:31:25Z

tests/jobs/test_scheduler_job.py

+                ti.state = State.SCHEDULED
+                tis.append(ti)
+                session.merge(ti)
+            session.commit()


Suggested change

session.commit()

create_session would commit the session when exiting the contextmanager

kaxil · 2019-12-05T19:35:35Z

tests/jobs/test_scheduler_job.py

+                                                         "no_dags.py"))
+            mock.patch.object(scheduler, '_change_state_for_tis_without_dagrun').start()
+            scheduler._process_dags(simple_dag_bag)
+            [ti.refresh_from_db() for ti in tis]


Suggested change

[ti.refresh_from_db() for ti in tis]

for ti in tis:

ti.refresh_from_db()

as we don't need to create list

kaxil

Minor suggestion, otherwise LGTM

KevinYang21 · 2019-12-05T21:02:47Z

Let me answer my own question... Since we change from SCHEDULED to QUEUED only when the dag is in the simple_dagbag, thus those left over tasks in queued_tasks won't be set back to QUEUED until the next parse but stlll gonna be picked up by the executor, then cause the deps check to fail.

Thanks again for fixing my bad 🙏

And to understand the impact completely, the bug was causing scheduler/executor to slow down quite a lot when traffic >> executor capacity, but not completely blocked right? As those SCHEDULED tasks in queued_tasks would be slowly moved out by _execute_task_instances.

kaxil · 2019-12-06T17:53:00Z

Following tests are failing:

FAILED tests/jobs/test_backfill_job.py::TestBackfillJob::test_backfill_examples_0_example_branch_operator
FAILED tests/jobs/test_backfill_job.py::TestBackfillJob::test_backfill_examples_1_example_bash_operator
FAILED tests/jobs/test_backfill_job.py::TestBackfillJob::test_backfill_examples_2_example_skip_dag
FAILED tests/jobs/test_backfill_job.py::TestBackfillJob::test_backfill_multi_dates
FAILED tests/jobs/test_scheduler_job.py::TestSchedulerJob::test_retry_still_in_executor
FAILED tests/jobs/test_scheduler_job.py::TestSchedulerJob::test_scheduler_executor_overflow
FAILED tests/jobs/test_scheduler_job.py::TestSchedulerJob::test_scheduler_reschedule
==== 7 failed, 3999 passed, 117 skipped, 16 warnings in 1481.02s (0:24:41) =====

codecov-io · 2019-12-07T02:36:03Z

Codecov Report

Merging #6732 into master will decrease coverage by 0.22%.
The diff coverage is 78.26%.

@@            Coverage Diff             @@
##           master    #6732      +/-   ##
==========================================
- Coverage   84.45%   84.23%   -0.23%     
==========================================
  Files         672      672              
  Lines       38081    38089       +8     
==========================================
- Hits        32163    32084      -79     
- Misses       5918     6005      +87

Impacted Files	Coverage Δ
airflow/jobs/scheduler_job.py	`89.24% <78.26%> (-0.32%)`	⬇️
airflow/kubernetes/volume_mount.py	`44.44% <0%> (-55.56%)`	⬇️
airflow/kubernetes/volume.py	`52.94% <0%> (-47.06%)`	⬇️
airflow/kubernetes/pod_launcher.py	`45.25% <0%> (-46.72%)`	⬇️
airflow/kubernetes/refresh_config.py	`50.98% <0%> (-23.53%)`	⬇️
...rflow/contrib/operators/kubernetes_pod_operator.py	`78.2% <0%> (-20.52%)`	⬇️
airflow/models/taskinstance.py	`94.39% <0%> (-0.16%)`	⬇️
airflow/jobs/backfill_job.py	`90.72% <0%> (+0.28%)`	⬆️
airflow/hooks/postgres_hook.py	`94.36% <0%> (+1.4%)`	⬆️
... and 3 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 69629a5...db3c0f4. Read the comment docs.

potiuk

Nice one! Let's get it merged. We have some other "global" updates to this code which aim to increase readability (pylint + type annotations) so we should - I think - merge those fairly quickly.

dimberman · 2019-12-09T23:30:01Z

@potiuk @KevinYang21 wanna give a final lookover before merging?

KevinYang21 · 2019-12-10T02:44:50Z

oops, just found a debug line that I forgot to remove c0ea272#diff-d7e6d11bfaeca087149ad577dd7704daR68. Otherwise LGTM. Will push a small commit to fix it. If we all good I can merge it after the CI passes.

…pache#6732)

…6732) (cherry-picked from commit f3bb4c3) Co-Authored-By: Kaxil Naik <[email protected]> Co-Authored-By: Kevin Yang <[email protected]>

…pache#6732) There is a bug caused by scheduler_jobs refactor which leads to task failure and scheduler locking. Essentially when a there is an overflow of tasks going into the scheduler, the tasks are set back to scheduled, but are not removed from the executor's queued_tasks queue. This means that the executor will attempt to run tasks that are in the scheduled state, but those tasks will fail dependency checks. Eventually the queue is filled with scheduled tasks, and the scheduler can no longer run. Co-Authored-By: Kaxil Naik <[email protected]>, Kevin Yang <[email protected]>

Original PR: apache/airflow#6732 Change-Id: I1f8d8c277c54a9b1e2546cf1b37502b64f6c0b5f GitOrigin-RevId: 2651459c7994aae7dd3ef4808f00bb39293ea8a3

dimberman requested review from ashb, kaxil, potiuk and KevinYang21 December 5, 2019 00:01

ashb mentioned this pull request Dec 5, 2019

[AIRFLOW-4285] Update task dependency context defination and usage #5079

Merged

6 tasks

ashb reviewed Dec 5, 2019

View reviewed changes

tests/executors/test_executor.py Outdated Show resolved Hide resolved

ashb reviewed Dec 5, 2019

View reviewed changes

tests/jobs/test_scheduler_job.py Outdated Show resolved Hide resolved

ashb reviewed Dec 5, 2019

View reviewed changes

dimberman changed the title ~~fixes scheduler queue bug~~ [AIRFLOW-6175] fixes scheduler queue bug Dec 5, 2019

astro-sql-decorator added 3 commits December 5, 2019 10:26

fixes scheduler queue bug

8189734

doc change

aaf7d0c

PR fixes

eb42612

dimberman force-pushed the AIRFLOW-6175_scheduler-queue-bug branch from 96c24aa to eb42612 Compare December 5, 2019 18:35

KevinYang21 approved these changes Dec 5, 2019

View reviewed changes

kaxil reviewed Dec 5, 2019

View reviewed changes

tests/jobs/test_scheduler_job.py Outdated Show resolved Hide resolved

kaxil reviewed Dec 5, 2019

View reviewed changes

tests/jobs/test_scheduler_job.py Outdated Show resolved Hide resolved

dimberman and others added 2 commits December 5, 2019 11:30

Update tests/jobs/test_scheduler_job.py

59f7618

Co-Authored-By: Kaxil Naik <[email protected]>

Update tests/jobs/test_scheduler_job.py

d20a8be

Co-Authored-By: Kaxil Naik <[email protected]>

kaxil reviewed Dec 5, 2019

View reviewed changes

kaxil approved these changes Dec 5, 2019

View reviewed changes

fix unit tests

c0ea272

potiuk approved these changes Dec 9, 2019

View reviewed changes

potiuk added the area:Scheduler including HA (high availability) scheduler label Dec 9, 2019

merged with master

f438842

Remove extra print

db3c0f4

mik-laj approved these changes Dec 10, 2019

View reviewed changes

ashb merged commit f3bb4c3 into apache:master Dec 10, 2019

kaxil pushed a commit to astronomer/airflow that referenced this pull request Dec 10, 2019

[AIRFLOW-6175] Fixes bug when tasks get stuck in "scheduled" state (a…

32ae563

…pache#6732)

kaxil added a commit that referenced this pull request Dec 17, 2019

[AIRFLOW-6175] Fixes bug when tasks get stuck in "scheduled" state (#…

7837b00

…6732) (cherry-picked from commit f3bb4c3) Co-Authored-By: Kaxil Naik <[email protected]> Co-Authored-By: Kevin Yang <[email protected]>

kaxil added a commit that referenced this pull request Dec 17, 2019

[AIRFLOW-6175] Fixes bug when tasks get stuck in "scheduled" state (#…

39629ad

…6732) (cherry-picked from commit f3bb4c3) Co-Authored-By: Kaxil Naik <[email protected]> Co-Authored-By: Kevin Yang <[email protected]>

ashb pushed a commit that referenced this pull request Dec 19, 2019

[AIRFLOW-6175] Fixes bug when tasks get stuck in "scheduled" state (#…

455d452

…6732) (cherry-picked from commit f3bb4c3) Co-Authored-By: Kaxil Naik <[email protected]> Co-Authored-By: Kevin Yang <[email protected]>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[AIRFLOW-6175] fixes scheduler queue bug #6732

[AIRFLOW-6175] fixes scheduler queue bug #6732

dimberman commented Dec 5, 2019 •

edited by kaxil

Loading

ashb commented Dec 5, 2019

ashb Dec 5, 2019

dimberman Dec 5, 2019

dimberman commented Dec 5, 2019

kaxil commented Dec 5, 2019 •

edited

Loading

dimberman commented Dec 5, 2019

KevinYang21 left a comment •

edited

Loading

kaxil Dec 5, 2019

kaxil Dec 5, 2019

kaxil left a comment

KevinYang21 commented Dec 5, 2019 •

edited

Loading

kaxil commented Dec 6, 2019

codecov-io commented Dec 7, 2019 •

edited

Loading

potiuk left a comment

dimberman commented Dec 9, 2019

KevinYang21 commented Dec 10, 2019 •

edited

Loading

	[ti.refresh_from_db() for ti in tis]
	for ti in tis:
	ti.refresh_from_db()

[AIRFLOW-6175] fixes scheduler queue bug #6732

[AIRFLOW-6175] fixes scheduler queue bug #6732

Conversation

dimberman commented Dec 5, 2019 • edited by kaxil Loading

Jira

Description

Tests

Commits

Documentation

ashb commented Dec 5, 2019

ashb Dec 5, 2019

Choose a reason for hiding this comment

dimberman Dec 5, 2019

Choose a reason for hiding this comment

dimberman commented Dec 5, 2019

kaxil commented Dec 5, 2019 • edited Loading

dimberman commented Dec 5, 2019

KevinYang21 left a comment • edited Loading

Choose a reason for hiding this comment

kaxil Dec 5, 2019

Choose a reason for hiding this comment

kaxil Dec 5, 2019

Choose a reason for hiding this comment

kaxil left a comment

Choose a reason for hiding this comment

KevinYang21 commented Dec 5, 2019 • edited Loading

kaxil commented Dec 6, 2019

codecov-io commented Dec 7, 2019 • edited Loading

Codecov Report

potiuk left a comment

Choose a reason for hiding this comment

dimberman commented Dec 9, 2019

KevinYang21 commented Dec 10, 2019 • edited Loading

dimberman commented Dec 5, 2019 •

edited by kaxil

Loading

kaxil commented Dec 5, 2019 •

edited

Loading

KevinYang21 left a comment •

edited

Loading

KevinYang21 commented Dec 5, 2019 •

edited

Loading

codecov-io commented Dec 7, 2019 •

edited

Loading

KevinYang21 commented Dec 10, 2019 •

edited

Loading