Skip to content

.schedule's execution time gets pushed back #282

@MHM5000

Description

@MHM5000

Let's say you scheduler.schedule a job; the interval values on the job or the ./manage.py rqscheduler -i x don't matter.
The time the job gets executed gets pushed back every now and then and over long periods of time, an 18:40:00 would gradually become 20:30:00 and out of nowhere, it becomes 18:40:00, and the cycle repeats.
dependencies:

OS : ubuntu 18.04 and CentOS 7
Redis: 5.0.14
Django: 3.2.16
redis (python): 4.4.0
django-redis: 5.2.0
django-rq: 2.6.0
rq: 1.11.1
rq-scheduler: 0.11.0

as a dev dep: (not available on CentOS)

django-rq-wrapper: 3.1

we have the problem with older versions as well.

Example code:

import django_rq
from django.utils import timezone

report_job_id = "report__prepare_report"

def send_report():
    pass

def init_transaction_report_generation(report_config):
    scheduler = django_rq.get_scheduler("default")
    if report_job_id not in scheduler:
        now = timezone.localtime(timezone.now())
        start_time = now.replace(
            hour=report_config.cut_off_time.hour,
            minute=report_config.cut_off_time.minute,
            second=report_config.cut_off_time.second,
        )
        if now.time() > report_config.cut_off_time:
            start_time += timedelta(days=1)
        start_time.astimezone(pytz.UTC)
        scheduler.schedule(
            start_time,
            func=send_report,
            queue_name="default",
            id=report_job_id,
            interval=10,
        )
    return True

and run these as well:

./manage.py rqscheduler -i 5 -v 3 # both interval and verbosity has no effect at all
./manage.py rqworker default

let's say we start at 18:14:30 and we configure the report_config.cut_off_time to run at 18:15:00. it will run at the said time and rescheduled for 18:15:10 based on the code and so on and so forth...
after an hour I see 3 seconds delay:

19:14:43 Entering run loop

and soon after, 1 more second:

19:22:44 Entering run loop

and this keeps happening.
In production we use -i 60 and the job's interval is 86400. why does the task gets executed at 20:30:00 even though the scheduler runs every minute? does it really lose the sense of what time it is? or are we creating black holes somewhere on earth and time gets distorted? 😟

p.s. I wanted to try cron with crontab, but apparently, you have not released that yet and there is no proper tag on git for 0.11.0

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions