disnake
disnake copied to clipboard
tasks.loop running twice when a specific time is given
Summary
The task is running two times instead of one on the given time.
Reproduction Steps
Have a task with a time specified @tasks.loop(time=time(tzinfo=timezone.utc))
. The second time the task runs it will run twice instead of once. I managed to pinpoint the culprit to the _get_next_sleep_time
function https://github.com/DisnakeDev/disnake/blob/d76c09fca5d50d3fbf1522890f668a6ed8812c21/disnake/ext/tasks/init.py#L556
Specifically these lines https://github.com/DisnakeDev/disnake/blob/d76c09fca5d50d3fbf1522890f668a6ed8812c21/disnake/ext/tasks/init.py#L581-L583
The first time the task runs fine as it does not reach this point in the code but returns earlier. After the task has successfully run once, the problem begins since the problematic code is reached. The reason for this is that after the first successful run, _last_iteration
is set to the last return value of _get_next_sleep_time
. This is problematic, since the time part of _get_next_sleep_time
is the time argument of the task. This causes next_time == next_date.timetz()
to be true, which in turn makes the if condition false which prevents a day being added to the sleep time.
Minimal Reproducible Code
No response
Expected Results
The task to run once each day on the specified time.
Actual Results
The task starts running twice after the first time.
Intents
irrelevant here
System Information
- Python v3.10.1-final
- disnake v2.5.1-final
- disnake pkg_resources: v2.5.1
- aiohttp v3.8.1
- system info: Windows 10 10.0.19042
Checklist
- [X] I have searched the open issues for duplicates.
- [X] I have shown the entire traceback, if possible.
- [X] I have removed my token from display, if visible.
Additional Context
Link to the discord message where I brought this up just in case it's necessary https://discord.com/channels/808030843078836254/913779868985090089/991012140947222538
I've done some more logging and I've come to the conclusion that the explanation I gave above is not quite exactly right.
When the current time is checked after sleeping on this line
https://github.com/DisnakeDev/disnake/blob/d76c09fca5d50d3fbf1522890f668a6ed8812c21/disnake/ext/tasks/init.py#L170
The returned value is sometimes before self._next_iteration
.
With this code snippet placed after the utcnow
logger.info(f'Now after sleep {now} next iteration {self._next_iteration}')
I managed to get this log Now after sleep 2022-07-05 23:59:59.999240+00:00 next iteration 2022-07-06 00:00:00+00:00
. So now I believe this bug is caused by the fact that sleeping operations are not guaranteed to wait at least the given amount of time. The time can be more or less by an amount that depends on the clock resolution. When the loop works correctly utcnow returned a datetime after self._next_iteration
. The instant utcnow was before self._next_iteration
the task ran twice.
I got similar problem. With this code everything that runs after the midnight to 1 am is constantly looped. Other times i detected no problem with my zone. The problem would be propably with time drift because with "UTC" time zone I didn't have problem.
local_tz = datetime.now().astimezone().tzinfo
@tasks.loop(time=time(0, 1, tzinfo=local_tz))
async def send_names(self):
nameday_cz = await self._nameday_cz()
nameday_sk = await self._nameday_sk()
channel = self.bot.get_channel(config.name_day_room)
await channel.send(f"{nameday_cz}\n{nameday_sk}")