Opened 3 months ago

Last modified 3 months ago

#35672 closed Bug

Using database connection pooling raises PoolTimeout after a while — at Version 1

Reported by: André S. Hansen Owned by:
Component: Database layer (models, ORM) Version: 5.1
Severity: Normal Keywords:
Cc: Florian Apolloner Triage Stage: Unreviewed
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX: no

Description (last modified by André S. Hansen)

I am testing the new db connection pooling, which increased the performance greatly, typically lowering api response times from 30ms -> 20ms on my dev env.

However, after a while i started getting 

psycopg_pool.PoolTimeout : couldn't get a connection after 30.00 sec

It happened after 220 api calls within the span of 7minutes, which probably means x5-10 database calls.

This forces me to turn of connection pooling.

Using settings

{
   "ENGINE": os.environ.get("DB_ENGINE", "django.db.backends.postgresql"),
   "OPTIONS": {"pool": True}
}

Extra info:

  • Python 3.12.1
  • Django 5.1
  • psycopg 3.2.1
  • psycopg-pool 3.2.2
  • Local docker image hosted postgresql database using image "postgres"

Logs

[13/Aug/2024 00:50:41] "POST /api/instances/2/actions/move/ HTTP/1.1" 200 91
couldn't get a connection after 30.00 sec
Traceback (most recent call last):
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 279, in ensure_connection
    self.connect()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 256, in connect
    self.connection = self.get_new_connection(conn_params)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\postgresql\base.py", line 348, in get_new_connection
    connection = self.pool.getconn()
                 ^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\psycopg_pool\pool.py", line 202, in getconn
    raise PoolTimeout(
psycopg_pool.PoolTimeout: couldn't get a connection after 30.00 sec

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\ninja\operation.py", line 192, in _run_authentication
    result = callback(request)
             ^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\ninja\security\apikey.py", line 23, in __call__
    return self.authenticate(request, key)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\ninja\security\session.py", line 17, in authenticate
    if request.user.is_authenticated:
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\functional.py", line 251, in inner
    self._setup()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\functional.py", line 404, in _setup
    self._wrapped = self._setupfunc()
                    ^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\middleware.py", line 37, in <lambda>
    request.user = SimpleLazyObject(lambda: get_user(request))
                                            ^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\middleware.py", line 17, in get_user
    request._cached_user = auth.get_user(request)
                           ^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\__init__.py", line 209, in get_user
    user_id = _get_user_session_key(request)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\__init__.py", line 62, in _get_user_session_key
    return get_user_model()._meta.pk.to_python(request.session[SESSION_KEY])
                                               ~~~~~~~~~~~~~~~^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\base.py", line 55, in __getitem__
    return self._session[key]
           ^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\base.py", line 249, in _get_session
    self._session_cache = self.load()
                          ^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\db.py", line 55, in load
    s = self._get_session_from_db()
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\db.py", line 34, in _get_session_from_db
    return self.model.objects.get(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 645, in get
    num = len(clone)
          ^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 382, in __len__
    self._fetch_all()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 1928, in _fetch_all
    self._result_cache = list(self._iterable_class(self))
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 91, in __iter__
    results = compiler.execute_sql(
              ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 37, in inner
    return original(compiler, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 94, in inner
    return execute_query_func()
           ^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 80, in <lambda>
    execute_query_func = lambda: original(compiler, *args, **kwargs)
                                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\sql\compiler.py", line 1572, in execute_sql
    cursor = self.connection.cursor()
             ^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 320, in cursor
    return self._cursor()
           ^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 296, in _cursor
    self.ensure_connection()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 278, in ensure_connection
    with self.wrap_database_errors:
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 279, in ensure_connection
    self.connect()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 256, in connect
    self.connection = self.get_new_connection(conn_params)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\postgresql\base.py", line 348, in get_new_connection
    connection = self.pool.getconn()
                 ^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\psycopg_pool\pool.py", line 202, in getconn
    raise PoolTimeout(
django.db.utils.OperationalError: couldn't get a connection after 30.00 sec
Internal Server Error: /api/instances/2/actions/move/
Traceback (most recent call last):
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 279, in ensure_connection
    self.connect()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 256, in connect
    self.connection = self.get_new_connection(conn_params)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\postgresql\base.py", line 348, in get_new_connection
    connection = self.pool.getconn()
                 ^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\psycopg_pool\pool.py", line 202, in getconn
    raise PoolTimeout(
psycopg_pool.PoolTimeout: couldn't get a connection after 30.00 sec

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\core\handlers\exception.py", line 55, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Repos\untitledgame\backend\monitor\middleware.py", line 35, in __call__
    user_id=user_id_or_none(request.user),
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Repos\untitledgame\backend\game\api\utils.py", line 9, in user_id_or_none
    if isinstance(user, AnonymousUser):
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\functional.py", line 280, in __getattribute__
    value = super().__getattribute__(name)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\functional.py", line 251, in inner
    self._setup()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\functional.py", line 404, in _setup
    self._wrapped = self._setupfunc()
                    ^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\middleware.py", line 37, in <lambda>
    request.user = SimpleLazyObject(lambda: get_user(request))
                                            ^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\middleware.py", line 17, in get_user
    request._cached_user = auth.get_user(request)
                           ^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\__init__.py", line 209, in get_user
    user_id = _get_user_session_key(request)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\auth\__init__.py", line 62, in _get_user_session_key
    return get_user_model()._meta.pk.to_python(request.session[SESSION_KEY])
                                               ~~~~~~~~~~~~~~~^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\base.py", line 55, in __getitem__
    return self._session[key]
           ^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\base.py", line 249, in _get_session
    self._session_cache = self.load()
                          ^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\db.py", line 55, in load
    s = self._get_session_from_db()
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\contrib\sessions\backends\db.py", line 34, in _get_session_from_db
    return self.model.objects.get(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 645, in get
    num = len(clone)
          ^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 382, in __len__
    self._fetch_all()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 1928, in _fetch_all
    self._result_cache = list(self._iterable_class(self))
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\query.py", line 91, in __iter__
    results = compiler.execute_sql(
              ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 37, in inner
    return original(compiler, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 94, in inner
    return execute_query_func()
           ^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\cachalot\monkey_patch.py", line 80, in <lambda>
    execute_query_func = lambda: original(compiler, *args, **kwargs)
                                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\models\sql\compiler.py", line 1572, in execute_sql
    cursor = self.connection.cursor()
             ^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 320, in cursor
    return self._cursor()
           ^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 296, in _cursor
    self.ensure_connection()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 278, in ensure_connection
    with self.wrap_database_errors:
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 279, in ensure_connection
    self.connect()
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\base\base.py", line 256, in connect
    self.connection = self.get_new_connection(conn_params)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\utils\asyncio.py", line 26, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\django\db\backends\postgresql\base.py", line 348, in get_new_connection
    connection = self.pool.getconn()
                 ^^^^^^^^^^^^^^^^^^^
  File "C:\Users\andre\.virtualenvs\backend-jnn8gBG-\Lib\site-packages\psycopg_pool\pool.py", line 202, in getconn
    raise PoolTimeout(
django.db.utils.OperationalError: couldn't get a connection after 30.00 sec
[13/Aug/2024 00:56:42] "POST /api/instances/2/actions/move/ HTTP/1.1" 500 235606

Change History (1)

comment:1 by André S. Hansen, 3 months ago

Description: modified (diff)
Note: See TracTickets for help on using tickets.
Back to Top