Django-celery-beat: troubleshooting a database scheduler which does nothing at all

[superandrew]

Summary:

Include a brief descrioption of the problem here, and fill out the version info below.

• Celery Version:
  4.4.0
• Celery-Beat Version:
  1.4,1.5,1.6
  

  Exact steps to reproduce the issue:

1. Setup celery by reading the docs
2. setup some periodic task using cron, clocked schedule, periodi task
3. launch a beat and a worker instance

Detailed information

I setup celery on heroku by using a dino for worker and one for beat (and one for web, obviously). I know that beat and worker are connected to redis and to postgres for task results.

Every periodic task I run from django admin by selecting a task and “run selected task” gets executed.

However, it is about two days that I’m trying to figure out why there isn’t a way for beat/worker to find that I scheduled a task to execute every 10 seconds, or using a cron (even restarting beat and remot doesn’t change it).

I’m kind of desperate, and my next move would be to give redbeat a try.

Any help on how to how to troubleshoot this particular problem would be greatly appreciated. I suspect the problem is in the is_due method. I am using UTC (in celery and django), all cron are UTC based. All I see in the beat log is “writing entries..” every on and then.

I’ve tried changing celery version from 4.3 to 4.4 and django celery beat from 1.4.0 to 1.5.0 to 1.6.0
Ideas?

[superandrew]

it seems that beats stops processing data when there are dynamically created periodic tasks that in some ways interfere. Printing logs on the is_due function to debug reveals that only the next task is inspected, so if that task isn’t due any of the other tasks are inspected (for example my cron task). Is that correct?

[superandrew]

In case it helps someone who's having or will have a similar trouble as ours: to recreate this issue, it is possible to create a task as simple as:

@app.task(bind=True)
def test(self, arg):
    # f = open("testfile.txt", "w+")
    # f.write(arg)
    # f.close()
    print(kwargs.get("notification_id"))

then, in django admin, enter the task editing and put something in the extra args field. Or, viceversa, the task could be

@app.task(bind=True)
def test(self, **kwargs):
    # f = open("testfile.txt", "w+")
    # f.write(arg)
    # f.close()
    print(kwargs.get("notification_id"))

And try to pass a positional argument. While locally this breaks, on Heroku's beat and worker dyno, this somehow slips away unnoticed, and django_celery_beats stop processing _any_ task whatsoever in the future. The scheduler is completely broken by a "wrong" task.

[superandrew]

I noticed that whenever a clocked schedule has its clocked schedule enabled=False, django_celery_beat and / or the worker process stops processing every other scheduled task.

Does that make sense to anyone?

[arbazkiraak]

I had a similar problem,

I did try with the development version which is django-celery-beat 2.0

Django==2.2.4
Python 3.7.6

pip install -U https://github.com/celery/django-celery-beat/zipball/master#egg=django-celery-beat
and looks like tasks are started getting executed intervally.

[theodoulos]

Experiencing same issue as superandrew and upgrade of celery-beat from 1.5 to 2.0 does not seem to fix it

I've tried periodic tasks with interval and clocked schedules

All my tasks have expiration date, start_time and one_off = True

On celery-beat 1.5 some short term interval tasks seemed to be triggered occasionally

lib versions:
python 3.6.10
celery 4.4.0
redis 3.3.11
django 2.2.4
kombu 4.6.7

[cr4zyd3v]

I have tried everything, looked at lots of answers on stack overflow with no success..
The worker does not pick up tasks scheduled by celery beat.. It register the models though.

[2020-03-12 22:41:24,995: INFO/MainProcess] Writing entries...

[2020-03-12 22:44:25,234: INFO/MainProcess] Writing entries... 

[2020-03-12 22:47:25,483: INFO/MainProcess] Writing entries...

This is the only thing I see in the beat console
Nothing happens on celery worker

Celery is 4.4
Beat is 1.6.. Have tried 1.5 and 2.0 already.

Another thing is that it works if embed with the celery worker with the --beat flag

[cr4zyd3v]

I feel very embarrassed right now lol... but my problem is that my task had an error and that was the reason why it was not working.
My celery beat console did not show anything because in my Django logging config I had this:

LOGGING = {
    "version": 1,
    "disable_existing_loggers": True,
    ....

This logging configuration was suppressing all errors messages of the celery beat console which lead me to think that my tasks were not running...
Changing it to False solved my "problem" lol

[bob-r]

I'm afraid this was closed by mistake. I confirm the same problem with 1.6. Interval schedule randomly missing in our CI. I see no errors in logs, with loggers enabled.

[superandrew]

@bob-r it seems no one is reading these issues, apparently, so it doesn't change much I guess :/

[bob-r]

Let's fix it together then. More details about my case:

• observed for one interval schedule randomly, other interval schedules are fine
• in contrast to other schedules, the task of the problematic one has a priority, which I forgot to save in the corresponding schedule (now experimenting with this and update tomorrow)
• in contrast to other schedules, the problematic one shares the interval schedule object (every 5 min) with another schedule (in the beat log, I see that it reacts on any changes in PeriodicTask and IntervalSchedule models) - I'll experiment with separate interval schedule records tomorrow and let you know

it is difficult to reproduce/test because the issue is random and observed only in our CI

[bob-r]

@auvipy, this issue is not resolved

[auvipy]

really sorry. mistakenly closed

[bob-r]

When fails, celery beat log (with debug level) says that out of 12 perdiodic tasks only 8 were fetched during "DatabaseScheduler: initial read". Tasks priority can be excluded because only one of the 4 missing had priority. Even the standard celery.backend_cleanup not fetched. Despite regular "Synchronizing schedule", the missing 4 have never been scheduled. All 12 tasks are "enabled" in DB.

[bob-r]

Another case: clocked one-off periodic task randomly stops working. When it happens, the periodic task remains enabled in DB, but its clocked schedule somehow gets disabled. When the task is created, the beat logs (in debug mode) that the schedule has been changed but does not send the task to workers (whereas normally sending follows the updated schedule dump).

It looks like https://github.com/celery/django-celery-beat/pull/341 is a good change.

[bob-r]

I migrated one-off schedules to apply_async with ETA in future but it didn't help. Then I found another issue. There was a syntax error in one of crontab schedules, which was created programmatically (without any validation errors though). Namely, I put '7/12' for hours, which is a legitimate crontab syntax (but not supported by django-celery-beat). The schedule has never been shown up in the beat.log, nor executed. I accidentally found the wrong syntax by modifying the schedule manually via django admin, which does validate the string. After rewriting the hours to '7,19', the schedule was accepted by beat and the task was successfully executed. For a few days, there have been no missing schedules!!!

FYI @superandrew

[superandrew]

I think my particular problem is pretty much related to #341 alone. So very good to hear it's about to be merged, looking forward to test it.

[superandrew]

I can confirm that my scheduled tasks run, thanks to @yywing 💪🏿

[superandrew]

I am so happy right.. it is the first time I can see celery working consistently for days, thanks to #341, probably when that is in master we could close this issue as well.

[marcelolima]

@cr4zyd3v thanks for pointing out your issue, it helped me since I was also messing out with logging

[auvipy]

closing in favor of #341