Search code examples
pythonpostgresqlpython-asyncio

Postgres NOW() returns incorrect time when called inside asyncio task


My code runs once an hour and logs the time correctly, but for some reason postgres HOW() returns the wrong time.

The code looks something like this:

async def run():
    await before_startup()
    # ...

async def before_startup() -> None:
    loop = asyncio.get_event_loop()
    loop.create_task(interval_handler())

async def interval_handler():
    while True:
        logger.info("Handler:", datetime.datetime.now())
        for data in process_validity():
            pass

        # Wait to the next hour
        delta = datetime.timedelta(hours=1)
        now = datetime.datetime.now()
        next_hour = (now + delta).replace(microsecond=0, second=0, minute=0)
        wait_seconds = (next_hour - now).seconds
        await asyncio.sleep(1)  # Ensure unique per interval
        await asyncio.sleep(wait_seconds)

class Singleton(type):
    _instances = {}

    def __call__(cls, *args, **kwargs):
        if cls not in cls._instances:
            cls._instances[cls] = super(
                Singleton, cls).__call__(*args, **kwargs)
        return cls._instances[cls]

class Database(metaclass=Singleton):
    def __init__(self):
        self.connection = None

    def connect(self):
        self.connection = psycopg2.connect()

    def fetchmany(self, query: str, per: int, params: tuple | dict = None):
        cursor = self.connection.cursor(cursor_factory=RealDictCursor)
        cursor.execute(query, params)
        while True:
            result = cursor.fetchmany(per)
            yield result
            if not result:
                cursor.close()
                break

db = Database()
db.connect()

def process_validity() -> Generator[DataInterface, None, None]:
    db_now: datetime.datetime = db.fetchone("SELECT NOW()")['now'].replace(tzinfo=None)
    logger.info("NOW() is:", db_now)
    for users_set in db.fetchmany("SELECT ...", 100, ()):
        for user in users_set:
            yield user

if __name__ == "__main__":
    asyncio.run(run())

The logs looks like this:

2023-05-20 15:00:00 +0000 INFO     Handler: 2023-05-20 15:00:00.775156
2023-05-20 15:00:00 +0000 INFO     NOW() is: 2023-05-20 13:49:35.873942

Note that the logger and datetime.datetime.now() get the time correctly (15:00), while Postgres returns the wrong one (13:49). What could be the problem? Over time, the gap widens.

Also, I connect via psql to the container and get the correct time; the correct time is obtained by connecting via pycharm too. In addition, after the bot is launched, the task is processed immediately, and at that moment everything is correct. Then the delta increases.

My environment: Ubuntu 20.04.5 LTS (GNU/Linux 5.4.0-137-generic x86_64), Docker version 20.10.23, build 7155243, postgres:15.1-alpine, python 3.11.


Solution

  • Solved the problem with the answers in the comments and the following as a result:

    1. Use psycopg2 connection pool and write a class to create a context with a connection that would close automatically after one or set of transactions or select statements
    2. Use CURRENT_TIMESTAMP function