Enabling a cron schedule task will run it immediately if it should have ran while it was disabled

[mitom]

Summary:

This is a duplicate of #383 with an extended scope. The issues was closed with inactivity without resolution.

If the beat is stopped or a cron scheduled task is disabled, when the action is undone (i.e. beat started again, or task re-enabled) the task will be scheduled to run immediately AND then scheduled to run when the next execution is due too.

• Celery Version: 4.4.7
• Celery-Beat Version: 2.2.0

Exact steps to reproduce the issue:

1. Create a crontab based task that runs every hour (the frequency doesn't really matter)
2. Stop the beat between the 1st and 2nd execution
3. Start the beat a few minutes before the 3rd execution
4. The task will run twice in a few minutes (once when the beat is started, once when the 3rd execution is scheduled)

Detailed information

If I interpret https://github.com/celery/django-celery-beat/blob/master/django_celery_beat/tzcrontab.py#L45-L50, if we have a cron schedule like 0 * * * * (run at minute 0 of every hour), if we stop the beat at 00:55 (or at any point between 00:00 and 01:00) and then start it again at 01:55, the behaviour will be (sorry for this being so wordy, I'm writing it out to see if there is something I missed):

• check remaining estimate since last run (last run will be 00:00, it should have ran at 01:00, so the delta is -00:55)
• check if the delta is in the past (max of -00:55 and 0, is 0, then 0 == 0)
• if the delta was in the past, re-calculate when the next execution should be (in our case it'd be 02:00)
• schedule the task as due now with the next execution in 5 minutes

This would mean the task is scheduled at 01:55 and also at 02:00.
I tried to see if disabling and enabling the task behaves differently but it seems to be the same. https://github.com/celery/django-celery-beat/blob/master/django_celery_beat/schedulers.py#L109 Includes some logic around the start date, but even if we set the start date to the time when the next execution should be, it looks like it'd still schedule the task immediately on start with a delay until the start date.

What I'm looking for is a way to have scheduled tasks which simply skip executions if the beat is down (i.e. in the above example if the beat is stopped at 02:00, the 2nd execution is simply skipped, rather than scheduled at a different time when the beat comes back).

[baijiangjie]

You can try it.

#660

[auvipy]

You can try it.

#660

I hope this fixes the issue. let us know if not

[mark-at-kluster]

This does not fix it and is unrelated to this PR. The reason this occurs is that tasks are evaluated wether they should be run using the last_run_at field. The current time is not taken into consideration in determining wether a task 'is_due' or not. A long term solution to this would be to use the current time when initialising the ModelEntry class and only use last_run_at as a logging field. If you want to replicate this functionality immediately, you can extend the DatabaseSchedulerclass and rewrite the all_as_schedule method, setting last_run_at to the current time. This whole thing is more of a design change than a bug and should probably be offered as a feature flag.

[baijiangjie]

You may not understand the core reason. The fundamental problem is that the last_run_at field is temporarily set. When all_as_schedule is called, the old field value is pulled from the database again, overwriting the temporarily set field value, causing the subsequent logical judgment to be inaccurate. , thus executing repeatedly.
@mark-at-kluster

[mark-at-kluster]

This may be the case for the issue you fixed in your PR, however I don't believe this is the case for this issue. This is because you say all_as_schedule overwrites the old field value, but all_as_schedule only loops over enabled tasks. In this case, the task was previously disabled so wouldn't be included in the previous all_as_schedule and thus the schedule. This means it couldn't have been 'overwitten'.

This is the fix I came up with to solve this issue and #667 and have never had this issue since.

As mentioned, ideally setting last_run_at to now would be within ModelEntry and enabled by flag (RUN_RETROSPECTIVE = False maybe?) as seems like a design change.

class ModifiedDatabaseScheduler(DatabaseScheduler):

    def all_as_schedule(self):
        debug('DatabaseScheduler: Fetching database schedule')
        s = {}
        now = datetime.now(self.app.timezone)
        for model in self.Model.objects.enabled():
            try:
                entry = self.Entry(model, app=self.app)
                if entry.model.start_time and entry.model.start_time < now:
                    entry.last_run_at = now
                s[model.name] = entry
            except ValueError:
                pass
        return s

[ohperhaps]

What I have personally done to fix this is extend the DatabaseScheduler class and set the last run at value to the current time.

@mark-at-kluster thanks, bro.you saved my day!

[gggeek]

I have possibly the same problem, albeit in a slightly different context, which is:

I often seed staging/dev environments with an copy of production data, using a database backup which is generally older than 24 hours.
The seeding process does run django migrations, as well as anonymize any PII.
As part of the same process, I also flush all Redis instances, including the one used by Celery, and run the cli command celery purge -f. I do not disable tasks or change their scheduling.

Still, as soon as I restart celery after the re-seeding, a slew of periodic tasks get run, even though they are, imho, not meant to.

Example:

• task is set to run weekly, at 10AM on Sat
• it does have expire_seconds set to the equivalent of '1week - 1minute'
• today, a Wed, I import a db backup from 11 days ago
• when starting celery, the task is run immediately, instead of waiting for next Sat

I think this is related to the celery code taking into account the last_run_at value, even though I did not dig into the code to validate that hypothesis. It also seems not to take into account expire_seconds in this context.

@mark-at-kluster do you think that your fix above would also apply in my case? Or could I just ste to NULL the value of django_celery_beat_periodictask.last_run_at? Thx

ps: on celery-beat 2.5.0, celery 5.2.7

[gggeek]

Answering to my own question above: it seems that setting to NULL the value of django_celery_beat_periodictask.last_run_at does fix the problem for my case. Not the cleanest of solutions, possibly, but easy to implement via a custom cli command

from django.core.management.base import BaseCommand
from django.db import connection

class Command(BaseCommand):
    help = "Prevent Celery from executing past-due tasks upon startup"

    # @todo allow the user to pass in the name of a single task
    def add_arguments(self, parser):
        pass
    
    def handle(self, *args, **options):
        with connection.cursor() as cursor:
            cursor.execute("UPDATE django_celery_beat_periodictask SET last_run_at = NULL")

        # note: to return a non-0 exit code, use sys.exit(exit_code)
        return

[auvipy]

i would love to see a draft pr on this...