Repository navigation
Infinite hang on leaving conn.transaction() block #442
Description
Hi, I am experiencing hangs at aexit of Transaction context manager, with traceback as follows:
...
File "/usr/local/lib/python3.7/dist-packages/asyncpg/transaction.py", line 89, in __aexit__
await self.__rollback()
File "/usr/local/lib/python3.7/dist-packages/asyncpg/transaction.py", line 198, in __rollback
await self._connection.execute(query)
File "/code/callmeback/detail/log_helpers/postgre_conn.py", line 53, in execute
return await super(LoggingConn, self).execute(query, *args, timeout=timeout)
File "/usr/local/lib/python3.7/dist-packages/asyncpg/connection.py", line 273, in execute
return await self._protocol.query(query, timeout)Default command timeout is set for connection:
>>> conn = frame.f_locals['self']
>>> conn._config
ConnectionConfiguration(command_timeout=10.0, statement_cache_size=100, max_cached_statement_lifetime=300, max_cacheable_statement_size=15360)
>>> conn._protocol._get_timeout(None)
10.0So I expect self._protocol.query() to throw TimeoutError of some kind, but related coroutine hanged for three days with no progress.
I will happily provide you with any additional information, if I can. My app has aiomonitor onboard, so if any info reachable that way will help you - please let me know.
I tried to fiddle with conn._protocol, but almost nothing of its state is reachable from aioconsole since it's Cython.
My suspection is that exception that leads to rollback is coming from in-transaction query that somehow leads connection in such a state that rollback() cannot be processed normally. I will provide you with information about exception once that problem triggers next time.
- asyncpg version: 0.18.3
- PostgreSQL version: 10.7
- Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
the issue with a local PostgreSQL install?: - Python version: 3.7
- Platform: Ubuntu 16.04
- Do you use pgbouncer?: Yes (session-level pooling)
- Did you install asyncpg with pip?: Yes
- If you built asyncpg locally, which version of Cython did you use?: --
- Can the issue be reproduced under both asyncio and
uvloop?: Yes, I am using uvloop
Activity
Piatachock commentedon May 16, 2019
Update: original exception that forces
conn.rollback()isconcurrent.futures._base.TimeoutErrorwith traceback like this:While examining this stack, I've noticed that
_do_execute()frame has negativetimeoutvalue, probably after_get_statement()call. So looks like successorself._protocol.bind_execute()call is raising TimeoutError right away inself._get_timeout_impl(timeout)because of negative timeout.[-]Infinite hang on conn.release()[/-][+]Infinite hang on conn.rollback()[/+][-]Infinite hang on conn.rollback()[/-][+]Infinite hang on leaving conn.transaction() block[/+]elprans commentedon May 17, 2019
This is interesting. Does this trigger on a specific query, or randomly? I wonder why
_get_statementwould trigger a timeout, unless there's something seriously wrong with the connection.Piatachock commentedon May 17, 2019
This is happening in same place on same queries, yes. My app has very little amount of queries, tho, so I'm not sure if this is query-specific problem. Query itself is pretty light and planning + execution time is usually <1ms.
I can imagine some problems with connections since I sometimes see TimeoutError even without further hangs. I wans't able to dig on that problem yet, tho.
Piatachock commentedon May 17, 2019
Besides _get_statement() timeout - please note that there actually was an
stmtobject inlocals()of_do_execute()frame, altho I wasn't able to recognize if it was properly initiated or not. I looked on couple of it's method's return values like binded attribute oids and stuff like that - and there was reasonable values. Butafter - beforewas a bit bigger thantimeoutvaluePiatachock commentedon Jun 10, 2019
JFYI wrapping Connection object with this ugly code fixed problem for me:
But this code does not look good indeed, so if you will have a chance to find more stable solution, that would be wonderful.