← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 2027755] [NEW] "sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50 reached, connection timed out, timeout 30.00" error raised after repeated calls of Flavor.get_* methods

 

Public bug reported:

The error:

  sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50
reached, connection timed out, timeout 30.00 (Background on this error
at: https://sqlalche.me/e/14/3o7r)

is being raised in nova-api, causing a 500 error to be returned.

I think this is happening because of the placement of the
@api_db_api.context_manager.reader decorator (which manages the database
session) on a helper method instead of on the methods that actually
execute the database queries. I think it's resulting in connections not
being closed and eventually reaching the database connection pool size
limits.

The database context manager decorator needs to be on the methods that
execute the queries because part of what it does is close connections
after the method is run.

Full traceback:

Jul 13 22:06:48 ubuntu-jammy devstack@n-api.service[270259]: DEBUG nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Calling method '<bound method FlavorExtraSpecsController.index of <nova.api.openstack.compute.flavors_extraspecs.FlavorExtraSpecsController object at 0x7ff2813d6ce0>>' {{(pid=270259) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:513}}
Jul 13 22:06:58 ubuntu-jammy devstack@n-api.service[270259]: DEBUG dbcounter [-] [270259] Writing DB stats nova_api:SELECT=2 {{(pid=270259) stat_writer /usr/local/lib/python3.10/dist-packages/dbcounter.py:117}}
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Unexpected exception in API method: sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50 reached, connection timed out, timeout 30.00 (Background on this error at: https://sqlalche.me/e/14/3o7r)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi Traceback (most recent call last):
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/wsgi.py", line 658, in wrapped
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/compute/flavors_extraspecs.py", line 64, in index
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._get_extra_specs(context, flavor_id)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/compute/flavors_extraspecs.py", line 34, in _get_extra_specs
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     flavor = common.get_flavor(context, flavor_id)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/common.py", line 494, in get_flavor
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return objects.Flavor.get_by_flavor_id(context, flavor_id)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     result = fn(cls, context, *args, **kwargs)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/objects/flavor.py", line 395, in get_by_flavor_id
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     db_flavor = cls._flavor_get_by_flavor_id_from_db(context,
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/db/utils.py", line 35, in wrapper
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/objects/flavor.py", line 320, in _flavor_get_by_flavor_id_from_db
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     first()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2823, in first
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self.limit(1)._iter().first()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2907, in _iter
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     result = self.session.execute(
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1711, in execute
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     conn = self._connection_for_bind(bind)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._transaction._connection_for_bind(
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     conn = bind.connect()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3315, in connect
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._connection_cls(self, close_with_result=close_with_result)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 96, in __init__
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     else engine.raw_connection()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._wrap_pool_connect(self.pool.connect, _connection)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return fn()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 320, in connect
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return _ConnectionFairy._checkout(self)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 884, in _checkout
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     fairy = _ConnectionRecord.checkout(pool)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 486, in checkout
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     rec = pool._do_get()
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/impl.py", line 134, in _do_get
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     raise exc.TimeoutError(
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50 reached, connection timed out, timeout 30.00 (Background on this error at: https://sqlalche.me/e/14/3o7r)
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi 
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: INFO nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: <class 'sqlalchemy.exc.TimeoutError'>
Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: DEBUG nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

** Affects: nova
     Importance: Undecided
     Assignee: melanie witt (melwitt)
         Status: In Progress


** Tags: api db

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/2027755

Title:
  "sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50
  reached, connection timed out, timeout 30.00" error raised after
  repeated calls of Flavor.get_* methods

Status in OpenStack Compute (nova):
  In Progress

Bug description:
  The error:

    sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50
  reached, connection timed out, timeout 30.00 (Background on this error
  at: https://sqlalche.me/e/14/3o7r)

  is being raised in nova-api, causing a 500 error to be returned.

  I think this is happening because of the placement of the
  @api_db_api.context_manager.reader decorator (which manages the
  database session) on a helper method instead of on the methods that
  actually execute the database queries. I think it's resulting in
  connections not being closed and eventually reaching the database
  connection pool size limits.

  The database context manager decorator needs to be on the methods that
  execute the queries because part of what it does is close connections
  after the method is run.

  Full traceback:

  Jul 13 22:06:48 ubuntu-jammy devstack@n-api.service[270259]: DEBUG nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Calling method '<bound method FlavorExtraSpecsController.index of <nova.api.openstack.compute.flavors_extraspecs.FlavorExtraSpecsController object at 0x7ff2813d6ce0>>' {{(pid=270259) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:513}}
  Jul 13 22:06:58 ubuntu-jammy devstack@n-api.service[270259]: DEBUG dbcounter [-] [270259] Writing DB stats nova_api:SELECT=2 {{(pid=270259) stat_writer /usr/local/lib/python3.10/dist-packages/dbcounter.py:117}}
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Unexpected exception in API method: sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50 reached, connection timed out, timeout 30.00 (Background on this error at: https://sqlalche.me/e/14/3o7r)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi Traceback (most recent call last):
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/wsgi.py", line 658, in wrapped
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/compute/flavors_extraspecs.py", line 64, in index
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._get_extra_specs(context, flavor_id)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/compute/flavors_extraspecs.py", line 34, in _get_extra_specs
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     flavor = common.get_flavor(context, flavor_id)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/api/openstack/common.py", line 494, in get_flavor
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return objects.Flavor.get_by_flavor_id(context, flavor_id)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     result = fn(cls, context, *args, **kwargs)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/objects/flavor.py", line 395, in get_by_flavor_id
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     db_flavor = cls._flavor_get_by_flavor_id_from_db(context,
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/db/utils.py", line 35, in wrapper
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/opt/stack/nova/nova/objects/flavor.py", line 320, in _flavor_get_by_flavor_id_from_db
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     first()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2823, in first
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self.limit(1)._iter().first()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2907, in _iter
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     result = self.session.execute(
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1711, in execute
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     conn = self._connection_for_bind(bind)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1552, in _connection_for_bind
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._transaction._connection_for_bind(
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 747, in _connection_for_bind
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     conn = bind.connect()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3315, in connect
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._connection_cls(self, close_with_result=close_with_result)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 96, in __init__
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     else engine.raw_connection()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return self._wrap_pool_connect(self.pool.connect, _connection)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return fn()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 320, in connect
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     return _ConnectionFairy._checkout(self)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 884, in _checkout
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     fairy = _ConnectionRecord.checkout(pool)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/base.py", line 486, in checkout
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     rec = pool._do_get()
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/pool/impl.py", line 134, in _do_get
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi     raise exc.TimeoutError(
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi sqlalchemy.exc.TimeoutError: QueuePool limit of size 5 overflow 50 reached, connection timed out, timeout 30.00 (Background on this error at: https://sqlalche.me/e/14/3o7r)
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: ERROR nova.api.openstack.wsgi 
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: INFO nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: <class 'sqlalchemy.exc.TimeoutError'>
  Jul 13 22:07:18 ubuntu-jammy devstack@n-api.service[270259]: DEBUG nova.api.openstack.wsgi [None req-b47b7ad6-eecd-44a9-8264-706742dd8539 demo demo] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/2027755/+subscriptions



Follow ups