heroku Celery Beat将所有周期性任务发送为在重新启动时到期,即使它们刚刚运行

ngynwnxp  于 2022-11-13  发布在  其他
关注(0)|答案(1)|浏览(117)

我正在运行一个celery 工人和celery 节拍与数据库调度程序。
我在Heroku上运行这些和一个Django网络应用程序。它们被用来定期发送电子邮件和短信,每天午夜一次发送电子邮件,早上730发送短信。
我已经在Periodic Tasks表中使用一个chrontab手动定义了任务,但是我也尝试过在代码库中使用celeryapp.conf.beat_schedule定义它们,两者的行为是一样的。
任务如下所示
periodic tasks in django admin
我遇到的问题是,Heroku每天重新启动一次dynos,这是一个策略,当这种情况发生时,celery 节拍dyno出于某种原因运行我的周期性任务。发送到期任务”好像是正常的,不管他们是到期还是不到期。我不知道为什么会发生这种情况。
我有celery 结果运行以及postgres支持的任务结果,这看起来像这样,我有任务运行在正确的时间(午夜和730 am),但也在一些随机的时间,当heroku重新启动dynos。
如何在重新启动时停止任务的运行?为什么在重新启动后它们仍在运行?
task results in django admin
编辑:我可以用heroku ps:restart beat手动重启,并观察它的发生,仍然不知道为什么,但这里是它发生的调试日志。请记住,任务已经成功运行了这一天,最后一次运行是正确的之前重新启动。而且,再次重新启动不会再次运行任务。我想知道是否有时不知何故重新启动没有看到最后一次运行的日期?仍然试图找出这个问题。

2022-10-15T16:22:33.824655+00:00 app[beat.1]: [2022-10-15 12:22:33,824: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:22:38.828379+00:00 app[beat.1]: [2022-10-15 12:22:38,828: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:22:43.832789+00:00 app[beat.1]: [2022-10-15 12:22:43,832: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:22:46.627485+00:00 heroku[beat.1]: Restarting
2022-10-15T16:22:46.630753+00:00 heroku[beat.1]: State changed from up to starting
2022-10-15T16:22:48.836424+00:00 app[beat.1]: [2022-10-15 12:22:48,836: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:22:48.894489+00:00 heroku[beat.1]: Stopping all processes with SIGTERM
2022-10-15T16:22:48.956144+00:00 app[beat.1]: [2022-10-15 12:22:48,956: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:48.956272+00:00 app[beat.1]: [2022-10-15 12:22:48,956: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:48.956533+00:00 app[beat.1]: [2022-10-15 12:22:48,956: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:48.956585+00:00 app[beat.1]: [2022-10-15 12:22:48,956: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:49.225748+00:00 heroku[beat.1]: Process exited with status 0
2022-10-15T16:22:50.122842+00:00 heroku[beat.1]: Starting process with command `celery -A hello beat -l debug --scheduler django_celery_beat.schedulers:DatabaseScheduler`
2022-10-15T16:22:50.807227+00:00 heroku[beat.1]: State changed from starting to up
2022-10-15T16:22:51.834963+00:00 app[beat.1]: celery beat v5.2.7 (dawn-chorus) is starting.
2022-10-15T16:22:52.276824+00:00 app[beat.1]: __    -    ... __   -        _
2022-10-15T16:22:52.276844+00:00 app[beat.1]: LocalTime -> 2022-10-15 12:22:52
2022-10-15T16:22:52.276845+00:00 app[beat.1]: Configuration ->
2022-10-15T16:22:52.276845+00:00 app[beat.1]: . broker -> redis://:**@ec2-54-165-246-156.compute-1.amazonaws.com:31259//
2022-10-15T16:22:52.276846+00:00 app[beat.1]: . loader -> celery.loaders.app.AppLoader
2022-10-15T16:22:52.276846+00:00 app[beat.1]: . scheduler -> django_celery_beat.schedulers.DatabaseScheduler
2022-10-15T16:22:52.276846+00:00 app[beat.1]:
2022-10-15T16:22:52.276846+00:00 app[beat.1]: . logfile -> [stderr]@%DEBUG
2022-10-15T16:22:52.276851+00:00 app[beat.1]: . maxinterval -> 5.00 seconds (5s)
2022-10-15T16:22:52.277418+00:00 app[beat.1]: [2022-10-15 12:22:52,277: DEBUG/MainProcess] Setting default socket timeout to 30
2022-10-15T16:22:52.277510+00:00 app[beat.1]: [2022-10-15 12:22:52,277: INFO/MainProcess] beat: Starting...
2022-10-15T16:22:52.280410+00:00 app[beat.1]: [2022-10-15 12:22:52,280: DEBUG/MainProcess] DatabaseScheduler: initial read
2022-10-15T16:22:52.280449+00:00 app[beat.1]: [2022-10-15 12:22:52,280: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:52.280522+00:00 app[beat.1]: [2022-10-15 12:22:52,280: DEBUG/MainProcess] DatabaseScheduler: Fetching database schedule
2022-10-15T16:22:52.312792+00:00 app[beat.1]: [2022-10-15 12:22:52,312: DEBUG/MainProcess] Current schedule:
2022-10-15T16:22:52.312794+00:00 app[beat.1]: <ModelEntry: email-reminders hello.celery_tasks.email_reminders(*[], **{}) <crontab: 0 0
2022-10-15T16:22:52.312796+00:00 app[beat.1]: * *
2022-10-15T16:22:52.312797+00:00 app[beat.1]: * (m/h/d/dM/MY), America/New_York>
2022-10-15T16:22:52.312797+00:00 app[beat.1]: >
2022-10-15T16:22:52.312798+00:00 app[beat.1]: <ModelEntry: celery.backend_cleanup celery.backend_cleanup(*[], **{}) <crontab: 0 4
2022-10-15T16:22:52.312798+00:00 app[beat.1]: * *
2022-10-15T16:22:52.312798+00:00 app[beat.1]: * (m/h/d/dM/MY), America/New_York>
2022-10-15T16:22:52.312798+00:00 app[beat.1]: >
2022-10-15T16:22:52.312798+00:00 app[beat.1]: <ModelEntry: text-reminders hello.celery_tasks.text_reminders(*[], **{}) <crontab: 30 7
2022-10-15T16:22:52.312799+00:00 app[beat.1]: * *
2022-10-15T16:22:52.312799+00:00 app[beat.1]: * (m/h/d/dM/MY), America/New_York>
2022-10-15T16:22:52.312799+00:00 app[beat.1]: >
2022-10-15T16:22:52.328971+00:00 app[beat.1]: [2022-10-15 12:22:52,328: DEBUG/MainProcess] beat: Ticking with max interval->5.00 seconds
2022-10-15T16:22:52.336205+00:00 app[beat.1]: [2022-10-15 12:22:52,336: INFO/MainProcess] Scheduler: Sending due task email-reminders (hello.celery_tasks.email_reminders)
2022-10-15T16:22:52.363919+00:00 app[beat.1]: [2022-10-15 12:22:52,363: DEBUG/MainProcess] beat: Synchronizing schedule...
2022-10-15T16:22:52.363924+00:00 app[beat.1]: [2022-10-15 12:22:52,363: DEBUG/MainProcess] Writing entries...
2022-10-15T16:22:52.365247+00:00 app[worker.1]: [2022-10-15 12:22:52,365: INFO/MainProcess] Task hello.celery_tasks.email_reminders[9f9c958f-b62d-4078-ac87-9b76d255f427] received
2022-10-15T16:22:52.371464+00:00 app[beat.1]: [2022-10-15 12:22:52,371: DEBUG/MainProcess] hello.celery_tasks.email_reminders sent. id->9f9c958f-b62d-4078-ac87-9b76d255f427
2022-10-15T16:22:52.373084+00:00 app[beat.1]: [2022-10-15 12:22:52,373: INFO/MainProcess] Scheduler: Sending due task celery.backend_cleanup (celery.backend_cleanup)
2022-10-15T16:22:52.374784+00:00 app[beat.1]: [2022-10-15 12:22:52,374: DEBUG/MainProcess] celery.backend_cleanup sent. id->5b2b1962-af5e-4ec8-8b64-2078beabeaa3
2022-10-15T16:22:52.375157+00:00 app[worker.1]: [2022-10-15 12:22:52,374: INFO/MainProcess] Task celery.backend_cleanup[5b2b1962-af5e-4ec8-8b64-2078beabeaa3] received
2022-10-15T16:22:52.376237+00:00 app[beat.1]: [2022-10-15 12:22:52,376: INFO/MainProcess] Scheduler: Sending due task text-reminders (hello.celery_tasks.text_reminders)
2022-10-15T16:22:52.377725+00:00 app[beat.1]: [2022-10-15 12:22:52,377: DEBUG/MainProcess] hello.celery_tasks.text_reminders sent. id->d2f0cce8-e036-4d21-880e-435f2ea514a5
2022-10-15T16:22:52.377945+00:00 app[worker.1]: [2022-10-15 12:22:52,377: INFO/MainProcess] Task hello.celery_tasks.text_reminders[d2f0cce8-e036-4d21-880e-435f2ea514a5] received
2022-10-15T16:22:52.378998+00:00 app[beat.1]: [2022-10-15 12:22:52,378: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:22:52.393541+00:00 app[worker.1]: [2022-10-15 12:22:52,393: INFO/ForkPoolWorker-8] Task hello.celery_tasks.email_reminders[9f9c958f-b62d-4078-ac87-9b76d255f427] succeeded in 0.02742149494588375s: None
2022-10-15T16:22:52.413622+00:00 app[worker.1]: [2022-10-15 12:22:52,413: INFO/ForkPoolWorker-2] Task hello.celery_tasks.text_reminders[d2f0cce8-e036-4d21-880e-435f2ea514a5] succeeded in 0.03441403107717633s: None
2022-10-15T16:22:52.421015+00:00 app[worker.1]: [2022-10-15 12:22:52,420: INFO/ForkPoolWorker-1] Task celery.backend_cleanup[5b2b1962-af5e-4ec8-8b64-2078beabeaa3] succeeded in 0.04107004823163152s: None
2022-10-15T16:22:57.385878+00:00 app[beat.1]: [2022-10-15 12:22:57,385: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.
2022-10-15T16:23:02.391952+00:00 app[beat.1]: [2022-10-15 12:23:02,391: DEBUG/MainProcess] beat: Waking up in 5.00 seconds.

编辑2:
已尝试手动清除last_run

from django_celery_beat.models import PeriodicTask, PeriodicTasks
PeriodicTask.objects.update(last_run_at=None)
PeriodicTasks.changed()

重启机器人,但我似乎无法复制它。然而,到目前为止,每一次Heroku机器人重启都会发生这种情况。
编辑3:
我把一个调试器连接到celery beat,费力地逐步调试tick代码,观察它如何初始化并开始使用周期性任务。(特别是因为我没能看到它实际发生,只是浏览代码,希望找到答案)。启动过程中的一切都是有意义的。我担心它最终会成为与我的时区有关的东西,或者是决定任务是否到期的计算功能的更深层次的部分。如果我解决了它,我会继续寻找和更新。
编辑4:
我检查了很多次,仍然没有找到原因。我看到,在根源上,如果一个任务的last_run_at值+计算出的下一次应该运行的时间- now的差值为零或负值,那么它就会运行。所以我必须假设last_run_at日期或在计算过程中出现了问题。在populate_heap()函数期间的on beat restart。现在我不得不实现一个创可贴来忽略在预定时间之外对我的任务的重复调用,直到我可以完全解决这个问题。

ss2ws0br

ss2ws0br1#

虽然我没有验证确切的原因,我想我找到了解决方案,因为它今天没有再次发生,将更新,如果它没有修复虽然。如果节拍没有看到last_run_at它使用datetime.now()。我相信不知何故(last run + delta - now)的计算返回负值,导致它在开始运行。
我注意到beat的代码中有一个名为“DJANGO_CELERY_BEAT_TZ_AWARE”的设置,我没有设置。我还认为我的设置中有一个错误,USE_TZ也为false。
我将celery 设置Map到“CELERY_",这是我在www.example.com中的前后设置settings.py:
之前:

CELERY_ENABLE_UTC = False
CELERY_TIMEZONE = "America/New_York"
TIME_ZONE = "America/New_York"
USE_TZ = False

之后(不再发生):

CELERY_ENABLE_UTC = False
CELERY_TIMEZONE = "America/New_York"
DJANGO_CELERY_BEAT_TZ_AWARE = True
TIME_ZONE = "America/New_York"
USE_TZ = True

相关问题