MagicStack / asyncpg

A fast PostgreSQL Database Client Library for Python/asyncio.
Apache License 2.0
6.88k stars 399 forks source link

InternalClientError: cannot switch to state 12 #1069

Open elprans opened 1 year ago

elprans commented 1 year ago

Discussed in https://github.com/MagicStack/asyncpg/discussions/1068

Originally posted by **amacfie-tc** August 21, 2023 I received the following error, does anyone know what it means? In the SQLAlchemy engine, `pool_pre_ping` is set to `True`. ``` asyncpg.exceptions._base.InternalClientError: cannot switch to state 12; another operation (2) is in progress Traceback (most recent call last): [...] status = (await session.execute(sel_status)).scalar() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/ext/asyncio/session.py", line 454, in execute result = await greenlet_spawn( ^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 190, in greenlet_spawn result = context.throw(*sys.exc_info()) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2262, in execute return self._execute_internal( ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2134, in _execute_internal conn = self._connection_for_bind(bind) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2001, in _connection_for_bind return trans._connection_for_bind(engine, execution_options) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "", line 2, in _connection_for_bind File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/state_changes.py", line 139, in _go ret_value = fn(self, *arg, **kw) ^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1126, in _connection_for_bind conn = bind.connect() ^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3264, in connect return self._connection_cls(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 145, in __init__ self._dbapi_connection = engine.raw_connection() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3288, in raw_connection return self.pool.connect() ^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 452, in connect return _ConnectionFairy._checkout(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1366, in _checkout with util.safe_reraise(): File "/usr/local/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in __exit__ raise exc_value.with_traceback(exc_tb) File "/usr/local/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1304, in _checkout result = pool._dialect._do_ping_w_event( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 708, in _do_ping_w_event return self.do_ping(dbapi_connection) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 1117, in do_ping dbapi_connection.ping() asyncpg.exceptions._base.InternalClientError: cannot switch to state 12; another operation (2) is in progress ```
elprans commented 1 year ago

@amacfie-tc Looks like a bug. How are you running your Postgres?

amacfie-tc commented 1 year ago

Another one:

asyncpg.exceptions._base.InternalClientError: cannot switch to state 15; another operation (2) is in progress
Traceback (most recent call last):
[...]
    async with session.begin():
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/ext/asyncio/session.py", line 1818, in __aexit__
    await greenlet_spawn(
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 190, in greenlet_spawn
    result = context.throw(*sys.exc_info())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/util.py", line 146, in __exit__
    with util.safe_reraise():
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in __exit__
    raise exc_value.with_traceback(exc_tb)
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/util.py", line 144, in __exit__
    self.commit()
  File "<string>", line 2, in commit
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/state_changes.py", line 139, in _go
    ret_value = fn(self, *arg, **kw)
                ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1246, in commit
    trans.commit()
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2615, in commit
    self._do_commit()
  File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2720, in _do_commit
    self._connection_commit_impl()
asyncpg.exceptions._base.InternalClientError: cannot switch to state 15; another operation (2) is in progress
amacfie-tc commented 1 year ago

Pretty standard Postgres 14, here's the config:

listen_addresses = '*'
max_connections = 100
shared_buffers = 128MB
dynamic_shared_memory_type = posix
max_wal_size = 1GB
min_wal_size = 80MB
log_min_messages = notice
datestyle = 'iso, mdy'
timezone = 'Etc/UTC'
lc_messages = 'en_US.utf8'
lc_monetary = 'en_US.utf8'
lc_numeric = 'en_US.utf8'
lc_time = 'en_US.utf8'
default_text_search_config = 'pg_catalog.english'
shared_preload_libraries = 'pg_cron'
cron.database_name = '...'
amacfie-tc commented 1 year ago

The second one I can reproduce with

async with session.begin():
    await session.execute(
        text("set idle_in_transaction_session_timeout = 3000")
    )
    await session.execute(select(...))
    await asyncio.sleep(3)
    await session.execute(select(...))

The first one I'm not sure yet.

amacfie-tc commented 1 year ago

The first case seems to have been caused by the database server shutting down. So the only bug here, if any, is that the error messages could be more informative.

elprans commented 1 year ago

Yeah, state 2 in the message refers to an unpropagated error state (i.e. "error consume"), I'll try to reproduce.

lokucrazy commented 11 months ago

@elprans @amacfie-tc did this get resolved? i'm running into the issue as well, with NullPool

amacfie-tc commented 10 months ago

@lokucrazy to summarize the above, I observed this when the database closed the connection or ended the transaction