asyncpg terminate needs a delay

Describe the bug

Greetings, I came across a strange behavior: when you pass command_timeout param to asyncpg driver and the query is long enough to exceed it, there still will be an active session on PostgreSQL side

You may also check it by using select * from pg_stat_activity;

Optional link from https://docs.sqlalchemy.org which documents the behavior that is expected

No response

SQLAlchemy Version in Use

2.0.23

DBAPI (i.e. the database driver)

asyncpg

Database Vendor and Major Version

PostgreSQL 14

Python Version

3.10

Operating system

OSX

To Reproduce

import asyncio

import sqlalchemy as sa
from sqlalchemy import URL
from sqlalchemy.ext.asyncio import create_async_engine


async def test_asyncpg_with_command_timeout():
    engine = create_async_engine(
        URL.create(
            drivername='postgresql+asyncpg',
            host='localhost',
            port=5432,
            database='test',
            username='test',
            password='test',
        ),
        connect_args={
            'command_timeout': 2,
        },
    )

    try:
        async with engine.connect() as conn:
            await conn.execute(sa.text('select pg_sleep(:time)'), parameters={'time': 30})
    except asyncio.TimeoutError:
        print('gotcha')

    finally:
        await engine.dispose(close=True)


asyncio.run(test_asyncpg_with_command_timeout())

Error

2023-11-30 11:21:54.103 UTC [34] STATEMENT:  select pg_sleep($1)
2023-11-30 11:21:54.103 UTC [34] LOG:  execute __asyncpg_stmt_7__: select pg_sleep($1)
2023-11-30 11:21:54.103 UTC [34] DETAIL:  parameters: $1 = '30'
2023-11-30 11:22:24.115 UTC [34] LOG:  disconnection: session time: 0:00:30.126 user=test database=test host=192.168.65.1 port=25931
2023-11-30 11:22:24.115 UTC [34] DEBUG:  exit(0)

Additional context

I made my own investigation and the problem is because here https://github.com/MagicStack/asyncpg/blob/master/asyncpg/connect_utils.py#L1036 CancelledError is thrown, so asyncpg can not send CancelRequest message, but if I add a small delay here https://github.com/sqlalchemy/sqlalchemy/blob/main/lib/sqlalchemy/dialects/postgresql/asyncpg.py#L617 it will succeed. I know that it is not the solution, but maybe it will save some time

hey there -

Running this locally, I can see the statement stays on the PG server side through the timeout, then is cleaned up.

regardless of how much of an issue this is and how it might be fixed, this is the asyncpg driver somehow leaving a session running in the database, after the program exits. if the argument is, "SQLAlchemy should make this impossible" I would argue this is plainly in the realm of asyncpg as something that would be made impossible (if not even the postgresql server).

So far this does not seem to be SQLAlchemy's problem? Did you report this to asyncpg first?

No I didn't, for me it looks like SQLAlchemy doesn't wait for asyncpg to perform a graceful connection cancelling.
If you think I should report to the asyncpg developers, let's try starting with them

let me try to reproduce with the asyncpg driver directly to understand where the interaction is wrong

I dont understand "wait" here. there is no background thread, can you illustrate this "wait" more clearly?

edit: this is asking for a yield, not a "wait" specifically

OK the reproduction case for asyncpg, which I am assuming they would be unwilling to fix, is that for a timeouterror we no longer have a way to await new operations on the connection, so we use terminate.

Here is the reproduction case

import asyncio
import asyncpg


async def test_asyncpg_with_command_timeout():
    conn = await asyncpg.connect(
            host='localhost',
            port=5432,
            database='test',
            user='scott',
            password='tiger',
            command_timeout=2
    )

    trans = conn.transaction()
    try:
        await trans.start()
        prepared = await conn.prepare('select pg_sleep($1)')
        rows = await prepared.fetch(30)

    except asyncio.TimeoutError:
        print('gotcha')
        conn.terminate()
    finally:
        await conn.close()


asyncio.run(test_asyncpg_with_command_timeout())

this patch for terminate specifically can allow this to work, however I would need to review the full terminate use case to understand if we can do awaiting here, and if so why arent we using close

diff --git a/lib/sqlalchemy/dialects/postgresql/asyncpg.py b/lib/sqlalchemy/dialects/postgresql/asyncpg.py
index d57c94a17..6c48bbb06 100644
--- a/lib/sqlalchemy/dialects/postgresql/asyncpg.py
+++ b/lib/sqlalchemy/dialects/postgresql/asyncpg.py
@@ -182,6 +182,7 @@ client using this setting passed to :func:`_asyncio.create_async_engine`::
 
 from __future__ import annotations
 
+import asyncio
 import collections
 import decimal
 import json as _py_json
@@ -941,6 +942,8 @@ class AsyncAdapt_asyncpg_connection(AsyncAdapt_dbapi_connection):
         self.await_(self._connection.close())
 
     def terminate(self):
+        # see issue #10717
+        self.await_(asyncio.sleep(.001))
         self._connection.terminate()
         self._started = False

Would it make sense ask for suggestion to asyncpg devs on what they think it the best approach is?

Would it make sense ask for suggestion to asyncpg devs on what they think it the best approach is?

they would say, "if you call terminate, everything stops, we can't clean up anything. do a sleep if you want to terminate but have our commands finish"

i can't imagine what else they'd say

unless we want to question why we are using terminate at all if we are still in the async loop. the answer is the program at #8419 (comment) hangs indefinitely if we don't. so maybe that's the asyncpg bug

Commented on the change.
If asyncpg does things asynchronously the connection should have a way to indicate that there are things pending.

OK report it to asyncpg, see if they can provide for us a terminate() that also waits for whatever was pending. or alteranteively, we need a "close()" that doesnt try to do a full handshake and hangs on no network

I was trying here to avoid having three forms of close. no other DBAPI, even the async ones, need to do any of this

but your proposal is that we would now have "close()", "terminate()", "close_but_less_gracefully()" essentially

@elprans

OK report it to asyncpg, see if they can provide for us a terminate() that also waits for whatever was pending. or alteranteively, we need a "close()" that doesnt try to do a full handshake and hangs on no network

let's try to cc them here. Maybe there is already a way.

@elprans what would you suggest in this case? The TLDR is basically this: a query takes more than the timeout, so an exception is raised and sqlalchemy calls terminate before asyncpg has a chance of telling pg to stop the query.
Is there a way to check if an asyncpg connection has pending commands to send to pg?

Not a public method, but you can do if conn._stmt_exclusive_section._acquired to check if the connection has an operation running. We can add a public method for this, please open an issue.

or alteranteively, we need a "close()" that doesnt try to do a full handshake and hangs on no network

close() takes a timeout, so you can do await conn.close(some_low_timeout_value) and have it still attempt to cancel the running query, but fall back to terminate on a timeout.

@zzzeek

Thanks for the reply!

or alteranteively, we need a "close()" that doesnt try to do a full handshake and hangs on no network

close() takes a timeout, so you can do await conn.close(some_low_timeout_value) and have it still attempt to cancel the running query, but fall back to terminate on a timeout.

It seems that terminate is not needed since on CancelledError close will call _abort that's the same as what terminate does.

@zzzeek I guess that code can just call close when not handing a gc call, and suppress any exception

I guess that code can just call close when not handing a gc call, and suppress any exception

right, this is the thing that our architecture is not necessarily laid out to distinguish in these cases in quite the way that's needed right now, we have a method "invalidate()" and if that's called with hard=True, it means we want the connection gone.

I think what I will do is change asyncpg's terminate() to use close() with a short timeout if the greenlet context is present. I'm not sure how I didnt notice that close() had such a timeout.

try to gracefully close even in terminate

Navigation Menu

Repository navigation

asyncpg terminate needs a delay #10717

Describe the bug

Optional link from https://docs.sqlalchemy.org which documents the behavior that is expected

SQLAlchemy Version in Use

DBAPI (i.e. the database driver)

Database Vendor and Major Version

Python Version

Operating system

To Reproduce

Error

Additional context

7 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

asyncpg terminate needs a delay #10717

Description

Describe the bug

Optional link from https://docs.sqlalchemy.org which documents the behavior that is expected

SQLAlchemy Version in Use

DBAPI (i.e. the database driver)

Database Vendor and Major Version

Python Version

Operating system

To Reproduce

Error

Additional context

Activity

zzzeek commented on Nov 30, 2023

PaulWasTaken commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

7 remaining items

CaselIT commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

CaselIT commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

CaselIT commented on Nov 30, 2023

elprans commented on Nov 30, 2023

elprans commented on Nov 30, 2023

CaselIT commented on Nov 30, 2023

zzzeek commented on Nov 30, 2023

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions