Django Celery Beat with Database scheduler not running tasks

Question

Ive been searching wide and far and everything i've come across thus far suggests my configuration is correct.... I can see my tasks are being registered in my celery worker container. I don't see them registered in my beat container (but I don think I should? I should just see the tasks, which I do) but the tasks are not being run.

celery.py

from __future__ import absolute_import, unicode_literals
import os
from celery import Celery

# set the default Django settings module for the 'celery' program.
os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'itapp.settings')

app = Celery("itapp")
app.config_from_object('django.conf:settings', namespace='CELERY')

# Load task modules from all registered Django app configs.
app.autodiscover_tasks()

if __name__ == '__main__':
    app.start()

@app.task(bind=True)
def debug_task(self):
    print('Request: {0!r}'.format(self.request))

init.py

from __future__ import absolute_import, unicode_literals

# This will make sure the app is always imported when
# Django starts so that shared_task will use this app.
from .celery import app as celery_app

__all__ = ('celery_app',)

settings.py

LANGUAGE_CODE = 'en-gb'
TIME_ZONE = 'Europe/London'
USE_TZ = True
USE_I18N = True
USE_L10N = True

# CELERY SETTINGS
CELERY_TIMEZONE = 'Europe/London'
ENABLE_UTC = True
CELERY_BROKER_URL = 'amqp://rabbitmq:5672'
CELERY_RESULT_BACKEND = 'redis://redis:6379'
CELERY_BEAT_SCHEDULER = 'django_celery_beat.schedulers:DatabaseScheduler'
CELERY_TASK_TIME_LIMIT = 540

docker-compose.yml

  celery:
    image: "app:latest"
    env_file: 
      - /Users/a/app/config/en_vars.txt
    volumes:
      - /Users/a/app/app:/app/app
    command: celery -A app worker -l INFO --concurrency 30
    depends_on:
      - rabbitmq
      - redis
  celery_beat:
    image: "app:latest"
    env_file: 
      - /Users/a/app/config/en_vars.txt
    volumes:
      - /Users/a/app/app:/app/app
    command: celery -A app beat -l DEBUG --pidfile= 
    depends_on:
      - rabbitmq
      - redis

periodic schedule

celery logs

 -------------- celery@a05cfcda833f v4.4.7 (cliffs)
--- ***** -----
-- ******* ---- Linux-5.4.39-linuxkit-x86_64-with-debian-9.7 2020-11-26 14:57:55
- *** --- * ---
- ** ---------- [config]
- ** ---------- .> app:         itapp:0x7fb8d9e80518
- ** ---------- .> transport:   amqp://guest:**@rabbitmq:5672//
- ** ---------- .> results:     redis://redis:6379/
- *** --- * --- .> concurrency: 30 (prefork)
-- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
--- ***** -----
 -------------- [queues]
                .> celery           exchange=celery(direct) key=celery


[tasks]
  . monitoring.tasks.monitoring_devices

[2020-11-26 14:58:09,160: INFO/MainProcess] Connected to amqp://guest:**@rabbitmq:5672//
[2020-11-26 14:58:09,201: INFO/MainProcess] mingle: searching for neighbors
[2020-11-26 14:58:10,266: INFO/MainProcess] mingle: all alone
[2020-11-26 14:58:10,333: INFO/MainProcess] celery@a05cfcda833f ready.
[2020-11-26 14:58:10,417: INFO/MainProcess] Events of group {task} enabled by remote.

beat logs

celery beat v4.4.7 (cliffs) is starting.
__    -    ... __   -        _
LocalTime -> 2020-11-26 14:57:55
Configuration ->
    . broker -> amqp://guest:**@rabbitmq:5672//
    . loader -> celery.loaders.app.AppLoader
    . scheduler -> django_celery_beat.schedulers.DatabaseScheduler

    . logfile -> [stderr]@%DEBUG
    . maxinterval -> 5.00 seconds (5s)
[2020-11-26 14:57:55,321: DEBUG/MainProcess] Setting default socket timeout to 30
[2020-11-26 14:57:55,322: INFO/MainProcess] beat: Starting...
[2020-11-26 14:57:55,325: DEBUG/MainProcess] DatabaseScheduler: initial read
[2020-11-26 14:57:55,326: INFO/MainProcess] Writing entries...
[2020-11-26 14:57:55,327: DEBUG/MainProcess] DatabaseScheduler: Fetching database schedule
[2020-11-26 14:57:55,742: DEBUG/MainProcess] Current schedule:
<ModelEntry: celery.backend_cleanup celery.backend_cleanup(*[], **{}) <crontab: 0 4
         * *
          * (m/h/d/dM/MY), Europe/London>
        >
<ModelEntry: Meraki Device Monitor monitoring.tasks.monitoring_devices(*[], **{}) <freq: 2.00 minutes>>
[2020-11-26 14:57:56,537: DEBUG/MainProcess] beat: Ticking with max interval->5.00 seconds
[2020-11-26 14:57:57,094: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
[2020-11-26 14:58:02,101: DEBUG/MainProcess] beat: Synchronizing schedule...
[2020-11-26 14:58:02,102: INFO/MainProcess] Writing entries...
[2020-11-26 14:58:02,365: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
[2020-11-26 14:58:07,663: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
[2020-11-26 14:58:12,897: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.

running the container as a single command "celery -A app worker -l INFO --beat" with debug enabled logs below

[2020-11-26 17:36:42,710: DEBUG/MainProcess] using channel_id: 1
[2020-11-26 17:36:42,725: DEBUG/MainProcess] Channel open
[2020-11-26 17:36:43,791: INFO/MainProcess] mingle: sync with 1 nodes
[2020-11-26 17:36:43,794: DEBUG/MainProcess] mingle: processing reply from celery@a05cfcda833f
[2020-11-26 17:36:43,795: INFO/MainProcess] mingle: sync complete
[2020-11-26 17:36:43,796: DEBUG/MainProcess] ^-- substep ok
[2020-11-26 17:36:43,797: DEBUG/MainProcess] | Consumer: Starting Tasks
[2020-11-26 17:36:43,831: DEBUG/MainProcess] ^-- substep ok
[2020-11-26 17:36:43,832: DEBUG/MainProcess] | Consumer: Starting Control
[2020-11-26 17:36:43,833: DEBUG/MainProcess] using channel_id: 2
[2020-11-26 17:36:43,837: DEBUG/MainProcess] Channel open
[2020-11-26 17:36:43,858: DEBUG/MainProcess] ^-- substep ok
[2020-11-26 17:36:43,859: DEBUG/MainProcess] | Consumer: Starting Gossip
[2020-11-26 17:36:43,860: DEBUG/MainProcess] using channel_id: 3
[2020-11-26 17:36:43,863: DEBUG/MainProcess] Channel open
[2020-11-26 17:36:43,877: DEBUG/MainProcess] ^-- substep ok
[2020-11-26 17:36:43,878: DEBUG/MainProcess] | Consumer: Starting Heart
[2020-11-26 17:36:43,879: DEBUG/MainProcess] using channel_id: 1
[2020-11-26 17:36:43,883: DEBUG/MainProcess] Channel open
[2020-11-26 17:36:43,888: DEBUG/MainProcess] ^-- substep ok
[2020-11-26 17:36:43,889: DEBUG/MainProcess] | Consumer: Starting event loop
[2020-11-26 17:36:43,891: DEBUG/MainProcess] | Worker: Hub.register Pool...
[2020-11-26 17:36:43,898: WARNING/MainProcess] /usr/local/lib/python3.7/site-packages/celery/fixups/django.py:206: UserWarning: Using settings.DEBUG leads to a memory
            leak, never use this setting in production environments!
  leak, never use this setting in production environments!''')
[2020-11-26 17:36:43,899: INFO/MainProcess] celery@123d2a28ed9f ready.
[2020-11-26 17:36:43,900: DEBUG/MainProcess] basic.qos: prefetch_count->12
[2020-11-26 17:36:44,139: DEBUG/MainProcess] celery@a05cfcda833f joined the party
[2020-11-26 17:36:45,832: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:36:45,834: INFO/MainProcess] Events of group {task} enabled by remote.
[2020-11-26 17:36:47,337: INFO/Beat] beat: Starting...
[2020-11-26 17:36:47,345: DEBUG/Beat] DatabaseScheduler: initial read
[2020-11-26 17:36:47,346: INFO/Beat] Writing entries...
[2020-11-26 17:36:47,347: DEBUG/Beat] DatabaseScheduler: Fetching database schedule
[2020-11-26 17:36:47,782: DEBUG/Beat] Current schedule:
<ModelEntry: celery.backend_cleanup celery.backend_cleanup(*[], **{}) <crontab: 0 4
         * *
          * (m/h/d/dM/MY), Europe/London>
        >
<ModelEntry: Meraki Device Monitor monitoring.tasks.monitoring_devices(*[], **{}) <freq: 2.00 minutes>>
[2020-11-26 17:36:48,629: DEBUG/Beat] beat: Ticking with max interval->5.00 seconds
[2020-11-26 17:36:49,125: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:36:50,835: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:36:54,093: DEBUG/Beat] beat: Synchronizing schedule...
[2020-11-26 17:36:54,095: INFO/Beat] Writing entries...
[2020-11-26 17:36:54,336: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:36:55,802: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:36:59,592: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:37:00,834: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:37:03,859: DEBUG/MainProcess] heartbeat_tick : for connection 6d96e75dc3d240809cca3a0aa738e512
[2020-11-26 17:37:03,859: DEBUG/MainProcess] heartbeat_tick : Prev sent/recv: None/None, now - 28/103, monotonic - 33966.588017603, last_heartbeat_sent - 33966.587982103, heartbeat int. - 60 for connection 6d96e75dc3d240809cca3a0aa738e512
[2020-11-26 17:37:04,876: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:37:05,834: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:37:10,131: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:37:10,836: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:37:15,364: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:37:15,833: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:37:20,773: DEBUG/Beat] beat: Waking up in 5.00 seconds.
[2020-11-26 17:37:20,833: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
[2020-11-26 17:37:23,827: DEBUG/MainProcess] heartbeat_tick : for connection 6d96e75dc3d240809cca3a0aa738e512
[2020-11-26 17:37:23,827: DEBUG/MainProcess] heartbeat_tick : Prev sent/recv: 28/103, now - 28/176, monotonic - 33986.590378703, last_heartbeat_sent - 33966.587982103, heartbeat int. - 60 for connection 6d96e75dc3d240809cca3a0aa738e512

Data in the live DB:

>>> PeriodicTask.objects.all()
<ExtendedQuerySet [<PeriodicTask: celery.backend_cleanup: 0 4 * * * (m/h/d/dM/MY) Europe/London>, <PeriodicTask: Device Monitor: every 2 minutes>]>
>>> PeriodicTasks.objects.all()
<ExtendedQuerySet [<PeriodicTasks: PeriodicTasks object (1)>]>
>>> vars(PeriodicTasks.objects.all()[0])
{'_state': <django.db.models.base.ModelState object at 0x7fc0e1f300f0>, 'ident': 1, 'last_update': datetime.datetime(2020, 12, 7, 9, 1, 59, tzinfo=<UTC>)}
>>>

Answer 1

Your docker-compose.yml doesn't have any MySQL links. Is it possible that your application can't reach the database server?

If you suspect that this is the issue, you can list the docker containers with docker ps and then manually try to connect to the required databases from inside the relevant container with docker exec -ti <containerid> bash and then use the mysql or even nc or curl or wget to check whether the database host can be resolved - if not, link to it from the docker-compose.yml which will insert it into the hosts file automatically, or you can do it manually, or just update it in your configuration files.