Skip to content

crontab() schedule executed one hour too late after DST start #9653

@Feuermurmel

Description

@Feuermurmel

Checklist

  • I have verified that the issue exists against the main branch of Celery.
  • This has already been asked to the discussions forum first.
  • I have read the relevant section in the
    contribution guide
    on reporting bugs.
  • I have checked the issues list
    for similar or identical bug reports.
  • I have checked the pull requests list
    for existing proposed fixes.
  • I have checked the commit log
    to find out if the bug was already fixed in the main branch.
  • I have included all related issues and possible duplicate issues
    in this issue (If there are none, check this box anyway).
  • I have tried to reproduce the issue with pytest-celery and added the reproduction script below.

Mandatory Debugging Information

  • I have included the output of celery -A proj report in the issue.
    (if you are not able to do this, then at least specify the Celery
    version affected).
  • I have verified that the issue exists against the main branch of Celery.
  • I have included the contents of pip freeze in the issue.
  • I have included all the versions of all the external dependencies required
    to reproduce this bug.

Optional Debugging Information

  • I have tried reproducing the issue on more than one Python version
    and/or implementation.
  • I have tried reproducing the issue on more than one message broker and/or
    result backend.
  • I have tried reproducing the issue on more than one version of the message
    broker and/or result backend.
  • I have tried reproducing the issue on more than one operating system.
  • I have tried reproducing the issue on more than one workers pool.
  • I have tried reproducing the issue with autoscaling, retries,
    ETA/Countdown & rate limits disabled.
  • I have tried reproducing the issue after downgrading
    and/or upgrading Celery and its dependencies.

Related Issues and Possible Duplicates

Related Issues

A lot of (mostly closed) issues can be found by searching for daylight OR dst, but I couldn't find any that matches my case.

Possible Duplicates

  • None

Environment & Settings

Celery version:

celery report Output:

$ celery -A [...] report

software -> celery:5.4.0 (opalescent) kombu:5.4.2 py:3.12.8
            billiard:4.2.1 py-amqp:5.3.1
platform -> system:Darwin arch:64bit
            kernel version:23.6.0 imp:CPython
loader   -> celery.loaders.app.AppLoader
settings -> transport:amqp results:rpc://guest:**@localhost:5672//

deprecated_settings: None
enable_utc: True
ignore_result: False
accept_content: ['pickle']
task_serializer: 'pickle'
result_serializer: 'pickle'
timezone: 'Europe/Zurich'
worker_redirect_stdouts: False
task_send_sent_event: True
task_acks_late: True
broker_url: 'amqp://guest:********@localhost:5672//'
result_backend: 'rpc://guest:********@localhost:5672//'
broker_connection_retry_on_startup: True
task_default_queue: '[...]'
task_queues: [<unbound Queue [...] -> <unbound Exchange [...](direct)> -> [...]>]
beat_scheduler: 'celery.beat:Scheduler'

Steps to Reproduce

Required Dependencies

  • Minimal Python Version: N/A or Unknown
  • Minimal Celery Version: N/A or Unknown
  • Minimal Kombu Version: N/A or Unknown
  • Minimal Broker Version: N/A or Unknown
  • Minimal Result Backend Version: N/A or Unknown
  • Minimal OS and/or Kernel Version: N/A or Unknown
  • Minimal Broker Client Version: N/A or Unknown
  • Minimal Result Backend Client Version: N/A or Unknown

Python Packages

pip freeze Output:


Other Dependencies

Details

N/A

Minimally Reproducible Test Case

Details

amqp==5.3.1
billiard==4.2.1
celery==5.5.0
click==8.1.8
click-didyoumean==0.3.1
click-plugins==1.1.1
click-repl==0.3.0
kombu==5.5.2
prompt_toolkit==3.0.50
python-dateutil==2.9.0.post0
pytz==2025.2
six==1.17.0
tzdata==2025.2
vine==5.1.0
wcwidth==0.2.13

Expected Behavior

We witnessed this in production on the day after DST came into effect. We are using time zone Europe/Zurich where this year DST began at 2025-03-30 03:00+0200.

We are using the following schedule to perform some task that should happen as close to midnight as possible each day:

current_app.add_periodic_task(
    crontab(hour=0, minute=0),
    do_stuff.s(),
    options=dict(expires=24 * 3600),
)

I would expect this task to be executed in the seconds after midnight in our time zone each day.

Actual Behavior

We noticed that on 2025-03-31 (the day after DST came into effect), the task was executed 1 hour later than expected, i.e. at 2025-03-31 01:00:00+0200. The next day it was executed at the expected time right after midnight. This is an extract of the logs we have, all times are in UTC:

2025-03-26 23:00:00.271	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-03-27 23:00:00.240	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-03-28 23:00:00.255	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-03-29 23:00:00.089	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-03-30 23:00:00.204	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-03-31 22:00:00.001	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)
2025-04-01 22:00:00.339	[celery.beat] Scheduler: Sending due task <task_name>() (<task_name>)

I had a quick look at celery/schedules.py, to figure out whether the error was in Celery or in our setup. Then I did some tests interacting with the crontab instance directly, to understand its behavior. I think I found behavior that points at a bug in crontab's implementation:

import pytz
from datetime import datetime
from datetime import timedelta

from celery.schedules import crontab

timezone = pytz.timezone("Europe/Zurich")

def ts(s: str) -> datetime:
    return timezone.localize(datetime.fromisoformat(s))

now = ts("2025-03-30 00:00:02")
c = crontab(hour=0, minute=0, nowfun=lambda: now)

res = c.is_due(ts("2025-03-30 00:00:01"))
print(res)
# schedstate(is_due=False, next=86398.0)
print((now + timedelta(seconds=res.next)).astimezone(timezone).isoformat())
# 2025-03-31T01:00:00+02:00

The code tries to recreate the situation that lead to the late execution of the task on 2025-03-31. I assumed that is_due() (or a related function) was called right after the task was sent to the queue. So I set nowfun to return the time 2 seconds after midnight and last_run_at to 1 second after midnight. All time stamps use a tzinfo from our time zone, because that's what I believe also happens internally.

is_due() returns a next value of about 24 hours, adding that to the current time leads to 2025-03-31T01:00:00+02:00 (i.e. one hour too late).

Repeating that with timestamps for a day later leads to the correct result. This is also what we witnessed in production:

now = ts("2025-03-31 00:00:02")
res = c.is_due(ts("2025-03-31 00:00:01"))
print(res)
# schedstate(is_due=False, next=86398.0)
print((now + timedelta(seconds=res.next)).astimezone(timezone).isoformat())
# 2025-04-01T00:00:00+02:00

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions