Skip to content

[BUG] CronTrigger may fire multiple times at once #1717

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
4 tasks done
mifuyutsuki opened this issue Jul 16, 2024 · 0 comments
Closed
4 tasks done

[BUG] CronTrigger may fire multiple times at once #1717

mifuyutsuki opened this issue Jul 16, 2024 · 0 comments

Comments

@mifuyutsuki
Copy link
Contributor

Library Version

5.13.1

Describe the Bug

On some occasions, a Task using CronTrigger would fire multiple times "at once". As illustrated by my bot log while developing a feature, for cron * * * * *, i.e. minutely:

2024-07-15 22:50:00,002 [INFO] mitsuki.modules.schedule.daemon:60: Fired schedule 'Daily Questions'
2024-07-15 22:51:00,025 [INFO] mitsuki.modules.schedule.daemon:60: Fired schedule 'Daily Questions'
2024-07-15 22:51:59,996 [INFO] mitsuki.modules.schedule.daemon:60: Fired schedule 'Daily Questions'
2024-07-15 22:51:59,999 [INFO] mitsuki.modules.schedule.daemon:60: Fired schedule 'Daily Questions'
2024-07-15 22:52:00,001 [INFO] mitsuki.modules.schedule.daemon:60: Fired schedule 'Daily Questions'

Note the latter three fires occuring mere miliseconds apart instead of about 60 seconds, and the "duplicated" fires all happening miliseconds earlier than it should be.

Investigation showed that CronTrigger used datetime.now() to find the next fire time, which can cause issues when now() is less than the previously set next fire time, hence the issue. Let's imagine an hourly cron task (0 * * * *):

Action Normal Bug
Task start 23:59:31,000 23:59:31,000
Next fire 00:00:00,000 00:00:00,000
Task fire 00:00:00,005 23:59:59,995
Next fire 01:00:00,000 00:00:00,000

In summary, if for some reason the task fires moments before the supposed firing time of XX:00:00,000, CronTrigger's next firing time would fail to advance as it should due to using now() as reference time. This manifests in the task firing multiple times "at once".

Steps to Reproduce

Create and start a interactions.py Task using trigger CronTrigger.

For illustration purposes, the cron in use is * * * * * (every minute when the second ticks zero) and the task just prints the current time.

Expected Results

Task fires once every minute (or as specified by cron) and not more at once.

With said example task, this is shown by the printed current time being always about 60 seconds after the previous.

Minimal Reproducible Code

from interactions import Client, Intents, Task, listen, CronTrigger
from datetime import datetime
bot = Client(intents=Intents.DEFAULT)

@listen()
async def on_startup():
  test_task.start()

@Task.create(CronTrigger("* * * * *"))
async def test_task():
  print(datetime.now().isoformat())

bot.start("token")

Traceback

No response

Checklist

  • I have searched the open issues for duplicates.
  • I have shown the entire traceback, if possible.
  • I have removed my token from display, if visible.
  • I have attempted to debug this myself, and I believe this issue is with the library

Additional Information

A pull request is being made to fix this issue.

mifuyutsuki added a commit to mifuyutsuki/interactions.py that referenced this issue Jul 16, 2024
Replaces the croniter start_time in CronTrigger from `datetime.now()` to `self.last_call_time.astimezone()` to fix a bug causing possible multiple firing.

Fixes interactions-py#1717
mifuyutsuki added a commit to mifuyutsuki/mitsuki that referenced this issue Jul 16, 2024
Multiple firing is found to be caused by library bug interactions-py/interactions.py#1717. This fix uses a subclassed CronTrigger, pending library bugfix.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant