Skip to content
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

fix: tasks loop infinitely when tzinfo is neither None nor UTC #2196

Merged
merged 17 commits into from
Nov 26, 2023

Conversation

SorameHato
Copy link
Contributor

@SorameHato SorameHato commented Aug 5, 2023

Summary

Please see issue #2187

If task's tzinfo is not UTC and task's time is between UTC 00:00 and destination timezone's 00:00, it loop infinitely until UTC 00:00(countries in east of UTC timezone like Eastern Europe, Korea, Japan, Australia) or destination timezone's 00:00(countries in west of UTC timezone like USA, Canada) comes.

Test Log (KST 08:47 = UTC 23:47)

# logged in as : 하늘봇(PyCord 2.5 테스트)
# logged in at : 2023-08-05 08:47:11.900681+0900 (spent 0:00:03.079106)
# repo : Pycord-Development/pycord

# TEST A1 (Single time whose tzinfo is UTC)
# Task's time : 23:47:12.321575+00:00
# First Run : 2023-08-05 08:47:12.321575+09:00
time : 2023-08-05 08:47:12.321516+09:00, count : 0, next loop : 2023-08-06 08:47:12.321575+09:00
# Current loop : 0 | It works properly.

# TEST A2 (Single time whose tzinfo is KST)
# Task's time : 08:47:12.571575+09:00
# First Run : 2023-08-05 08:47:12.571575+09:00
time : 2023-08-05 08:47:12.572462+09:00, count : 0, next loop : 2023-08-05 08:47:12.571575+09:00
time : 2023-08-05 08:47:12.572462+09:00, count : 1, next loop : 2023-08-05 08:47:12.571575+09:00
time : 2023-08-05 08:47:12.572462+09:00, count : 2, next loop : 2023-08-05 08:47:12.571575+09:00
time : 2023-08-05 08:47:12.572462+09:00, count : 3, next loop : 2023-08-05 08:47:12.571575+09:00
# Current loop : 7086 | Infinity Loop has occured.

# TEST A3 (Single time which is naive)
# Task's time : 23:47:12.821575
# First Run : 2023-08-05 08:47:12.821575+09:00
time : 2023-08-05 08:47:12.816994+09:00, count : 0, next loop : 2023-08-06 08:47:12.821575+09:00
# Current loop : 0 | It works properly.

# TEST B1 (Multiple time whose tzinfo is UTC)
# Task's time : [datetime.time(23, 47, 13, 71575, tzinfo=datetime.timezone.utc), datetime.time(23, 47, 13, 321575, tzinfo=datetime.timezone.utc)]
# First Run : 2023-08-05 08:47:13.071575+09:00
time : 2023-08-05 08:47:13.069588+09:00, count : 0, next loop : 2023-08-05 08:47:13.321575+09:00
time : 2023-08-05 08:47:13.322405+09:00, count : 1, next loop : 2023-08-06 08:47:13.071575+09:00
# Current loop : 1 | It works properly.

# TEST B2 (Multiple time whose tzinfo is KST)
# Task's time : [datetime.time(8, 47, 13, 571575, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400))), datetime.time(8, 47, 13, 821575, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400)))]
# First Run : 2023-08-05 08:47:13.571575+09:00
time : 2023-08-05 08:47:13.571558+09:00, count : 0, next loop : 2023-08-05 08:47:13.821575+09:00
time : 2023-08-05 08:47:13.829117+09:00, count : 1, next loop : 2023-08-05 08:47:13.571575+09:00
time : 2023-08-05 08:47:13.829117+09:00, count : 2, next loop : 2023-08-05 08:47:13.571575+09:00
time : 2023-08-05 08:47:13.829117+09:00, count : 3, next loop : 2023-08-05 08:47:13.571575+09:00
# Current loop : 6755 | Infinity Loop has occured.

# TEST B3 (Multiple time which is naive)
# Task's time : [datetime.time(23, 47, 14, 71575), datetime.time(23, 47, 14, 321575)]
# First Run : 2023-08-05 08:47:14.071575+09:00
time : 2023-08-05 08:47:14.066043+09:00, count : 0, next loop : 2023-08-05 08:47:14.321575+09:00
time : 2023-08-05 08:47:14.322804+09:00, count : 1, next loop : 2023-08-06 08:47:14.071575+09:00
# Current loop : 1 | It works properly.

# TEST C (Interval = 0.25 sec)
# First Run : 2023-08-05 08:47:14.447889+09:00
time : 2023-08-05 08:47:14.447889+09:00, count : 0, next loop : 2023-08-05 08:47:14.697889+09:00
time : 2023-08-05 08:47:14.697978+09:00, count : 1, next loop : 2023-08-05 08:47:14.947978+09:00
time : 2023-08-05 08:47:14.948891+09:00, count : 2, next loop : 2023-08-05 08:47:15.198891+09:00
# Current loop : 2 | It works properly.

# Total Result = OXOOXOO

I resolved that bug by making datetime.datetime.now in _get_next_sleep_time of discord.ext.tasks to represents timezone of task's time.

Test Log (KST 08:48 = UTC 23:48)

# logged in as : 하늘봇(PyCord 2.5 테스트)
# logged in at : 2023-08-05 08:48:22.247804+0900 (spent 0:00:03.069594)
# repo : SorameHato/pycord-task-bug-resolve

# TEST A1 (Single time whose tzinfo is UTC)
# Task's time : 23:48:22.678210+00:00
# First Run : 2023-08-05 08:48:22.678210+09:00
time : 2023-08-05 08:48:22.672608+09:00, count : 0, next loop : 2023-08-06 08:48:22.678210+09:00
# Current loop : 0 | It works properly.

# TEST A2 (Single time whose tzinfo is KST)
# Task's time : 08:48:22.928210+09:00
# First Run : 2023-08-05 08:48:22.928210+09:00
time : 2023-08-05 08:48:22.933934+09:00, count : 0, next loop : 2023-08-06 08:48:22.928210+09:00
# Current loop : 0 | It works properly.

# TEST A3 (Single time which is naive)
# Task's time : 23:48:23.178210
# First Run : 2023-08-05 08:48:23.178210+09:00
time : 2023-08-05 08:48:23.176116+09:00, count : 0, next loop : 2023-08-06 08:48:23.178210+09:00
# Current loop : 0 | It works properly.

# TEST B1 (Multiple time whose tzinfo is UTC)
# Task's time : [datetime.time(23, 48, 23, 428210, tzinfo=datetime.timezone.utc), datetime.time(23, 48, 23, 678210, tzinfo=datetime.timezone.utc)]
# First Run : 2023-08-05 08:48:23.428210+09:00
time : 2023-08-05 08:48:23.421220+09:00, count : 0, next loop : 2023-08-05 08:48:23.678210+09:00
time : 2023-08-05 08:48:23.679066+09:00, count : 1, next loop : 2023-08-06 08:48:23.428210+09:00
# Current loop : 1 | It works properly.

# TEST B2 (Multiple time whose tzinfo is KST)
# Task's time : [datetime.time(8, 48, 23, 928210, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400))), datetime.time(8, 48, 24, 178210, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400)))]
# First Run : 2023-08-05 08:48:23.928210+09:00
time : 2023-08-05 08:48:23.925176+09:00, count : 0, next loop : 2023-08-05 08:48:24.178210+09:00
time : 2023-08-05 08:48:24.179965+09:00, count : 1, next loop : 2023-08-06 08:48:23.928210+09:00
# Current loop : 1 | It works properly.

# TEST B3 (Multiple time which is naive)
# Task's time : [datetime.time(23, 48, 24, 428210), datetime.time(23, 48, 24, 678210)]
# First Run : 2023-08-05 08:48:24.428210+09:00
time : 2023-08-05 08:48:24.426130+09:00, count : 0, next loop : 2023-08-05 08:48:24.678210+09:00
time : 2023-08-05 08:48:24.679571+09:00, count : 1, next loop : 2023-08-06 08:48:24.428210+09:00
# Current loop : 1 | It works properly.

# TEST C (Interval = 0.25 sec)
# First Run : 2023-08-05 08:48:24.822163+09:00
time : 2023-08-05 08:48:24.822163+09:00, count : 0, next loop : 2023-08-05 08:48:25.072163+09:00
time : 2023-08-05 08:48:25.073133+09:00, count : 1, next loop : 2023-08-05 08:48:25.323133+09:00
time : 2023-08-05 08:48:25.324065+09:00, count : 2, next loop : 2023-08-05 08:48:25.574065+09:00
# Current loop : 2 | It works properly.

# Total Result = OOOOOOO

Source Code of Test File

# coding: utf-8
import discord
import os
import asyncio
import sys
from discord.ext import commands, tasks
from datetime import datetime as dt
from datetime import timezone as tz
from datetime import timedelta as td
from datetime import time
from time import time as epochtime
import pathlib
intents = discord.Intents.all()
bot = discord.Bot(intents=intents)
hanul_ver = "0.0 rev 128 (2023-08-03 10:42)"
bot.hanul_ver = hanul_ver
result = ''
delay = 3.5 #Please set this time to delay of logging in to discord
now1 = dt.now(tz.utc) # aware (tz = UTC)
now2 = now1.astimezone(tz=tz(td(hours=9))) # aware (tz = KST)
now3 = now1.replace(tzinfo=None) # naive (UTC)
time_a1 = (now1 + td(seconds = delay)).timetz()
time_a2 = (now2 + td(seconds = delay, microseconds = 250000)).timetz()
time_a3 = (now3 + td(seconds = delay, microseconds = 500000)).timetz()
time_b1 = [(now1 + td(seconds = delay, microseconds = 750000)).timetz(), (now1 + td(seconds = delay+1)).timetz()]
time_b2 = [(now2 + td(seconds = delay+1, microseconds = 250000)).timetz(), (now2 + td(seconds = delay+1, microseconds = 500000)).timetz()]
time_b3 = [(now3 + td(seconds = delay+1, microseconds = 750000)).timetz(), (now3 + td(seconds = delay+2)).timetz()]

def printInfo(task):
    if task.current_loop <= 3:
        now = dt.now(tz(td(hours=9)))
        print(f'time : {now}, count : {task.current_loop}, next loop : {task.next_iteration.astimezone(tz=tz(td(hours=9))) if task.next_iteration is not None else task.next_iteration}')

async def printInfo2(time, task, sleepTime, properCount):
    global result
    if time is not None:
        print(f'# Task\'s time : {time}')
    print(f'# First Run : {task.next_iteration.astimezone(tz=tz(td(hours=9))) if task.next_iteration is not None else task.next_iteration}')
    await asyncio.sleep(sleepTime)
    if task.current_loop == properCount:
        print(f'# Current loop : {task.current_loop} | It works properly.\n')
        result += 'O'
    else:
        print(f'# Current loop : {task.current_loop} | Infinity Loop has occured.\n')
        result += 'X'
    task.stop()

async def async_until(arg):
    """
    From Pause Module of Jeremy Gillick / MIT License / Modified by Sorame Hato
    Original : https://github.com/jgillick/python-pause
    License : https://github.com/jgillick/python-pause/blob/master/LICENSE.txt
    Pause your program until a specific end time.
    'time' is either a valid datetime object or unix timestamp in seconds (i.e. seconds since Unix epoch)
    """
    end = arg

    # Convert datetime to unix timestamp and adjust for locality
    if isinstance(arg, dt):
        # If we're on Python 3 and the user specified a timezone, convert to UTC and get tje timestamp.
        end = arg.astimezone(tz.utc).timestamp()

    # Type check
    if not isinstance(end, (int, float)):
        raise Exception('The time parameter is not a number or datetime object')

    # Now we wait
    while True:
        now = epochtime()
        diff = end - now

        #
        # Time is up!
        #
        if diff <= 0:
            break
        else:
            # 'logarithmic' sleeping to minimize loop iterations
            await asyncio.sleep(diff / 2)

@tasks.loop(time=time_a1)
async def test_a1():
    printInfo(test_a1)

@tasks.loop(time=time_a2)
async def test_a2():
    printInfo(test_a2)

@tasks.loop(time=time_a3)
async def test_a3():
    printInfo(test_a3)

@tasks.loop(seconds=0.25)
async def test_c():
    printInfo(test_c)

@tasks.loop(time=time_b1)
async def test_b1():
    printInfo(test_b1)

@tasks.loop(time=time_b2)
async def test_b2():
    printInfo(test_b2)

@tasks.loop(time=time_b3)
async def test_b3():
    printInfo(test_b3)

@bot.event
async def on_ready():
    LoadedTime = dt.now(tz(td(hours=9)))
    print(f'# logged in as : {bot.user.name}')
    print(f'# logged in at : {LoadedTime.strftime("%Y-%m-%d %H:%M:%S.%f%z")} (spent {LoadedTime-now1})')
    if discord.version_info.major is None:
        print('# repo : SorameHato/pycord-task-bug-resolve\n')
    else:
        print('# repo : Pycord-Development/pycord\n')
    test_a1.start()
    test_a2.start()
    test_a3.start()
    test_b1.start()
    test_b2.start()
    test_b3.start()
    await async_until(now1 + td(seconds = delay-1, microseconds = 875000))
    print('# TEST A1 (Single time whose tzinfo is UTC)')
    await printInfo2(time_a1, test_a1, 0.25, 0)
    print('# TEST A2 (Single time whose tzinfo is KST)')
    await printInfo2(time_a2, test_a2, 0.25, 0)
    print('# TEST A3 (Single time which is naive)')
    await printInfo2(time_a3, test_a3, 0.25, 0)
    print('# TEST B1 (Multiple time whose tzinfo is UTC)')
    await printInfo2(time_b1, test_b1, 0.5, 1)
    print('# TEST B2 (Multiple time whose tzinfo is KST)')
    await printInfo2(time_b2, test_b2, 0.5, 1)
    print('# TEST B3 (Multiple time which is naive)')
    await printInfo2(time_b3, test_b3, 0.5, 1)
    global result
    print('# TEST C (Interval = 0.25 sec)')
    test_c.start()
    await asyncio.sleep(0.000001)
    await printInfo2(None, test_c, 0.55, 2)
    print(f'# Total Result = {result}',end='')
    await bot.close()
    sys.exit()

with open(pathlib.PurePath(__file__).with_name('token.txt'),'r') as token:
    bot.run(token.readline())

To sum up with table :

Test Timezone Now My Code
Single Time UTC
KST, EST, etc.
Naive
Multiple Time UTC
KST, EST, etc.
Naive
Interval
  • Index
    ✅ : Work properly
    ∞ : Infinity loop is occured
    ❌ : Doesn't work

Information

  • This PR fixes an issue.
  • This PR adds something new (e.g. new method or parameters).
  • This PR is a breaking change (e.g. methods or parameters removed/renamed).
  • This PR is not a code change (e.g. documentation, README, typehinting,
    examples, ...).

Checklist

  • I have searched the open pull requests for duplicates.
  • If code changes were made then they have been tested.
    • I have updated the documentation to reflect the changes. (Don't needed because it is internal code change)
  • If type: ignore comments were used, a comment is also left explaining why.
  • I have updated the changelog to include these changes.

Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
CHANGELOG.md Outdated Show resolved Hide resolved
SorameHato and others added 2 commits August 15, 2023 13:51
Co-authored-by: JustaSqu1d <89910983+JustaSqu1d@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Copy link
Member

@Dorukyum Dorukyum left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Haven't tested, just making a stylistic review

discord/ext/tasks/__init__.py Outdated Show resolved Hide resolved
discord/ext/tasks/__init__.py Outdated Show resolved Hide resolved
discord/ext/tasks/__init__.py Outdated Show resolved Hide resolved
discord/ext/tasks/__init__.py Outdated Show resolved Hide resolved
SorameHato and others added 5 commits August 16, 2023 00:30
Co-authored-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Co-authored-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Co-authored-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
Co-authored-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Signed-off-by: Jeon Hojin <36477282+SorameHato@users.noreply.github.com>
@SorameHato
Copy link
Contributor Author

SorameHato commented Aug 15, 2023

Haven't tested, just making a stylistic review

It works fine for me. (both tested on Windows 10 Education 22H2, Python 3.11.1/Ubuntu 18.04 LTS, Python 3.11.4, tested at KST 00:34(UTC 15:34))

Test Log

# logged in as : 하늘봇
# logged in at : 2023-08-16 00:34:17.457895+0900 (spent 0:00:03.085099)
# repo : SorameHato/pycord-task-bug-resolve

# TEST A1 (Single time whose tzinfo is UTC)
# Task's time : 15:34:17.872796+00:00
# First Run : 2023-08-16 00:34:17.872796+09:00
time : 2023-08-16 00:34:17.865310+09:00, count : 0, next loop : 2023-08-17 00:34:17.872796+09:00
# Current loop : 0 | It works properly.

# TEST A2 (Single time whose tzinfo is KST)
# Task's time : 00:34:18.122796+09:00
# First Run : 2023-08-16 00:34:18.122796+09:00
time : 2023-08-16 00:34:18.110510+09:00, count : 0, next loop : 2023-08-17 00:34:18.122796+09:00
# Current loop : 0 | It works properly.

# TEST A3 (Single time which is naive)
# Task's time : 15:34:18.372796
# First Run : 2023-08-16 00:34:18.372796+09:00
time : 2023-08-16 00:34:18.371273+09:00, count : 0, next loop : 2023-08-17 00:34:18.372796+09:00
# Current loop : 0 | It works properly.

# TEST B1 (Multiple time whose tzinfo is UTC)
# Task's time : [datetime.time(15, 34, 18, 622796, tzinfo=datetime.timezone.utc), datetime.time(15, 34, 18, 872796, tzinfo=datetime.timezone.utc)]
# First Run : 2023-08-16 00:34:18.622796+09:00
time : 2023-08-16 00:34:18.616334+09:00, count : 0, next loop : 2023-08-16 00:34:18.872796+09:00
time : 2023-08-16 00:34:18.874175+09:00, count : 1, next loop : 2023-08-17 00:34:18.622796+09:00
# Current loop : 1 | It works properly.

# TEST B2 (Multiple time whose tzinfo is KST)
# Task's time : [datetime.time(0, 34, 19, 122796, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400))), datetime.time(0, 34, 19, 372796, tzinfo=datetime.timezone(datetime.timedelta(seconds=32400)))]
# First Run : 2023-08-16 00:34:19.122796+09:00
time : 2023-08-16 00:34:19.117325+09:00, count : 0, next loop : 2023-08-16 00:34:19.372796+09:00
time : 2023-08-16 00:34:19.374145+09:00, count : 1, next loop : 2023-08-17 00:34:19.122796+09:00
# Current loop : 1 | It works properly.

# TEST B3 (Multiple time which is naive)
# Task's time : [datetime.time(15, 34, 19, 622796), datetime.time(15, 34, 19, 872796)]
# First Run : 2023-08-16 00:34:19.622796+09:00
time : 2023-08-16 00:34:19.620181+09:00, count : 0, next loop : 2023-08-16 00:34:19.872796+09:00
time : 2023-08-16 00:34:19.874134+09:00, count : 1, next loop : 2023-08-17 00:34:19.622796+09:00
# Current loop : 1 | It works properly.

# TEST C (Interval = 0.25 sec)
# First Run : 2023-08-16 00:34:20.014772+09:00
time : 2023-08-16 00:34:20.014772+09:00, count : 0, next loop : 2023-08-16 00:34:20.264772+09:00
time : 2023-08-16 00:34:20.265684+09:00, count : 1, next loop : 2023-08-16 00:34:20.515684+09:00
time : 2023-08-16 00:34:20.516649+09:00, count : 2, next loop : 2023-08-16 00:34:20.766649+09:00
# Current loop : 2 | It works properly.

# Total Result = OOOOOOO

@Lulalaby
Copy link
Member

It works fine for me

That's not the point here, We have to test it as well lol.
Everyone can say "works on my machine" lmfao.

Middledot
Middledot previously approved these changes Sep 17, 2023
Copy link
Member

@Middledot Middledot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tested

@JustaSqu1d JustaSqu1d added the bug Something isn't working label Sep 18, 2023
@benjo121ben
Copy link

Hi, been having the same issue.
Not super familiar with github yet, has issue been integrated into a future version?

CHANGELOG.md Outdated Show resolved Hide resolved
Signed-off-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Dorukyum
Dorukyum previously approved these changes Nov 26, 2023
Signed-off-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
Signed-off-by: Dorukyum <53639936+Dorukyum@users.noreply.github.com>
@Dorukyum Dorukyum changed the title fix: when task's tzinfo is not None or UTC, the task loops infinitely fix: tasks loop infinitely when tzinfo is neither None nor UTC Nov 26, 2023
@Dorukyum Dorukyum enabled auto-merge (squash) November 26, 2023 15:36
@Dorukyum Dorukyum merged commit 2437c7e into Pycord-Development:master Nov 26, 2023
28 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working status: awaiting review Awaiting review from a maintainer
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants