Airflow scheduler stopped working

[stijndehaes]

Apache Airflow version

2.7.2

What happened

When running a DAG with a timezone set to Europe/Brussels we noticed it stopped being scheduled around the 29th, this is right around summer/winter time change. The scheduled logs show:

test-airflow-scheduler-1  | [2023-10-30T12:49:52.330+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:53.474+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:54.569+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:55.665+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:56.031+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:57.133+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:57.454+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:49:58.584+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | <jemalloc>: MADV_DONTNEED does not work (memset will be used instead)
test-airflow-scheduler-1  | <jemalloc>: (This is the expected behaviour if you are running under QEMU)
test-airflow-scheduler-1  | [2023-10-30T12:49:59.553+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:00.667+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:01.774+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:02.580+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:02.956+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-webserver-1  | 127.0.0.1 - - [30/Oct/2023:12:50:03 +0000] "GET /health HTTP/1.1" 200 318 "-" "curl/7.74.0"
test-airflow-scheduler-1  | [2023-10-30T12:50:04.063+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:05.167+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:06.271+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:07.382+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:07.702+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:08.811+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:09.671+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:10.793+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:11.894+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-28T21:45:00+00:00, run_after=2023-10-29T04:00:00+00:00
test-airflow-scheduler-1  | [2023-10-30T12:50:12.813+0000] {dag.py:3722} INFO - Setting next_dagrun for time-zone-issue to 2023-10-29T04:00:00+00:00, run_after=2023-10-29T05:00:00+00:00

What you think should happen instead

The dag should continue to be scheduled

How to reproduce

Run the DAG attached below, I reproduced this case using the docker-compose setup from the docs.

from airflow.decorators import task

import pendulum
from airflow.models import DAG
from datetime import timedelta

default_args = {
    "depends_on_past": False,
    "start_date": pendulum.datetime(year=2023, month=10, day=28, tz="Europe/Brussels"),
    "email": [],
    "email_on_failure": False,
    "email_on_retry": False,
    "retries": 3,
    "retry_delay": timedelta(minutes=5),
}

with DAG(
        "time-zone-issue",
        default_args=default_args,
        max_active_runs=1,
        schedule_interval="0,15,30,45 6-22 * * *",
) as dag:
    @task(task_id="print_the_context")
    def print_context(ds=None, **kwargs):
        """Print the Airflow context and ds variable from the context."""
        print(ds)
        return "finished!"

    run_this = print_context()

Operating System

MAC OS, also linux

Versions of Apache Airflow Providers

Default ones included in docker-compose setup

Deployment

Docker-Compose

Deployment details

It also happens on a kubernetes cluster, the installation does not matter

Anything else

At one point the DAG started scheduling again, but I can still reproduce the case.

I am willing to create a PR but don't know where to start looking for this

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

[erplus]

I met this problem as well. Airflow version 2.5.1.
I have a second cluster with airflow 2.3.4. Everything seems are working properly though there are other dags and slightly different versions of python packages than in the first airflow cluster.

[pspeter]

We've also run into this problem. It only affects DAGs which have a start_time with a timezone, which have not gotten a new dag_run since the weekend. Our scheduler logs also look similar to OP.

The schedule for our affected DAGs is "15 7,8,13,19 * * *". Might be related since OP also uses a complex schedule.

[stijndehaes]

I have created a drawing of what the current state is.
The schedule for this DAG is a bit complex: 50 5-11,13-23 * * *

So basically there is one dag run created (the middle one), that is questionable if it should ever be created.
The left and right one have either a questionable start of the interval or questionable end.

Also after creating these the scheduler stops, in the logs I can see the next dag run is calculated as 2023-10-28T22:50:00+00:00 which in CET is equal to 2023-10-28T23:50:00+01:00, this dag run already exists so it then calculated the next dag run from that one to: 2023-10-29T03:50:00+00:00 in CET: 2023-10-29T04:50:00+01:00 which also already exists, and it continues like this.

This test reproduces the calculation:

def test_new_calculate_next_time():
    timezone = "Europe/Brussels"
    tz = pendulum.tz.timezone(timezone)
    start = pendulum.DateTime(2023, 10, 29, hour=4, minute=50, tzinfo=tz)
    end = pendulum.DateTime(2023, 10, 29, hour=5, minute=50, tzinfo=tz)
    interval = DataInterval(start=start, end=end)
    table = CronDataIntervalTimetable("50 5-11,13-23 * * *", timezone)
    next_info = table.next_dagrun_info(last_automated_data_interval=interval, restriction=TimeRestriction(earliest=None, latest=None, catchup=True))
    expected_start = end
    expected_end = pendulum.DateTime(2023, 10, 29, hour=6, minute=50, tzinfo=tz)
    assert next_info == DagRunInfo.interval(start=expected_start, end=expected_end)

And fails to succeed. I would love some advice from someone at Airflow what would be the best behavior. @potiuk can you help me find someone I can discuss solutions with?

I believe it should never have created these 3 dag runs but instead should have created a dagrun with:

• start: 23:50 CEST
• end: 5:50 CET

Any thoughts?

As for a workardound I have two for people:

• Set the start_date to after the issue
• Update the next_dagrun, next_dagrun_data_interval_start, next_dagrun_data_interval_end manually to the correct next dag run

[potiuk]

You've done all you could hopefully someone will take a look and help you. I am individual contributor and I have no power over telling other volunteers to do with their free time. But you described it well enough and I hope someone here will be able to help you. I keep fingers crossed.

[ivan-afonichkin]

@potiuk I'm happy to take a look :)

[ivan-afonichkin]

@potiuk I've created a PR #35445, would be great if you can take a look and give some feedback as it's my first PR in the scheduler and I might be missing something. Thanks!

[timkpaine]

this issue is a duplicate of #7999 and can be closed

[pspeter]

I am not sure if this is really a duplicate of #7999. It‘s related, but at least in our case the scheduler completely stopped executing that DAG until we removed the timezone from the start_date.