InternalClientError: cannot switch to state 12

[elprans]

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 "<string>", 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
```</div>

[elprans]

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

[amacfie-tc]

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]

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]

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]

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]

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

[lokucrazy]

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

[amacfie-tc]

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