nova functional test intermittently fail with DB error: Cursor needed to be reset because of commit/rollback and can no longer be fetched from

Bug #2002782 reported by Balazs Gibizer
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Confirmed
High
Unassigned

Bug Description

Example stack trace:

2023-01-13 03:17:37,055 WARNING [oslo_db.sqlalchemy.exc_filters] DBAPIError exception wrapped.
Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse(buffering=True)
TypeError: HTTPConnection.getresponse() got an unexpected keyword argument 'buffering'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 977, in fetchall
    rows = dbapi_cursor.fetchall()
sqlite3.InterfaceError: Cursor needed to be reset because of commit/rollback and can no longer be fetched from.
2023-01-13 03:17:37,057 ERROR [nova.api.openstack.wsgi] Unexpected exception in API method
Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse(buffering=True)
TypeError: HTTPConnection.getresponse() got an unexpected keyword argument 'buffering'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 977, in fetchall
    rows = dbapi_cursor.fetchall()
sqlite3.InterfaceError: Cursor needed to be reset because of commit/rollback and can no longer be fetched from.

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

Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/nova/api/openstack/wsgi.py", line 664, in wrapped
    return f(*args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/api/validation/__init__.py", line 110, in wrapper
    return func(*args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/api/openstack/compute/servers.py", line 1139, in _action_resize
    self._resize(req, id, flavor_ref, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/api/openstack/compute/servers.py", line 1053, in _resize
    self.compute_api.resize(context, instance, flavor_id,
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 388, in inner
    return function(self, context, instance, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 373, in wrapper
    return func(self, context, instance, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 356, in wrapper
    return func(self, context, instance, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 241, in inner
    return function(self, context, instance, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 167, in inner
    return f(self, context, instance, *args, **kw)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 231, in wrapped
    return function(self, context, instance, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/api.py", line 4244, in resize
    volume_backed = compute_utils.is_volume_backed_instance(
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/utils.py", line 270, in is_volume_backed_instance
    root_bdm = get_root_bdm(context, instance, bdms)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/utils.py", line 263, in get_root_bdm
    bdms = objects.BlockDeviceMappingList.get_by_instance_uuid(
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/oslo_versionedobjects/base.py", line 184, in wrapper
    result = fn(cls, context, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/objects/block_device.py", line 420, in get_by_instance_uuid
    db_bdms = cls._db_block_device_mapping_get_all_by_instance(
  File "/home/zuul/src/opendev.org/openstack/nova/nova/db/main/api.py", line 179, in wrapper
    return f(*args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/objects/block_device.py", line 415, in _db_block_device_mapping_get_all_by_instance
    return db.block_device_mapping_get_all_by_instance(
  File "/home/zuul/src/opendev.org/openstack/nova/nova/db/utils.py", line 35, in wrapper
    return f(*args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/db/main/api.py", line 241, in wrapper
    return f(context, *args, **kwargs)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/db/main/api.py", line 2931, in block_device_mapping_get_all_by_instance
    all()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2772, in all
    return self._iter().all()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1430, in all
    return self._allrows()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 401, in _allrows
    rows = self._fetchall_impl()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1343, in _fetchall_impl
    return self._real_result._fetchall_impl()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1755, in _fetchall_impl
    return list(self.iterator)
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 147, in chunks
    fetch = cursor._raw_all_rows()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 392, in _raw_all_rows
    rows = self._fetchall_impl()
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 1805, in _fetchall_impl
    return self.cursor_strategy.fetchall(self, self.cursor)
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 981, in fetchall
    self.handle_exception(result, dbapi_cursor, e)
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 941, in handle_exception
    result.connection._handle_dbapi_exception(
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2122, in _handle_dbapi_exception
    util.raise_(newraise, with_traceback=exc_info[2], from_=e)
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/sqlalchemy/engine/cursor.py", line 977, in fetchall
    rows = dbapi_cursor.fetchall()
oslo_db.exception.DBError: (sqlite3.InterfaceError) Cursor needed to be reset because of commit/rollback and can no longer be fetched from.
(Background on this error at: https://sqlalche.me/e/14/rvf5)
2023-01-13 03:17:37,059 INFO [nova.api.openstack.wsgi] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_db.exception.DBError'>
2023-01-13 03:17:37,062 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/servers/ee5262e1-ddd0-44f4-a9b6-3d3abc1c44ad/action" status: 500 len: 199 microversion: 2.15 time: 0.091336
}}}

stderr: {{{
/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py310/lib/python3.10/site-packages/oslo_db/sqlalchemy/enginefacade.py:541: DeprecationWarning: Using the 'mysql_enable_ndb' argument is deprecated in version '12.1.0': Support for the MySQL NDB Cluster storage engine has been deprecated and will be removed in a future release.
  engine = engines.create_engine(
}}}

Traceback (most recent call last):
  File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/test_server_group.py", line 406, in test_resize_to_same_host_with_anti_affinity
    self.admin_api.post_server_action(servers[1]['id'], post)
  File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 273, in post_server_action
    return self.api_post(
  File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 215, in api_post
    return APIResponse(self.api_request(relative_uri, **kwargs))
  File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 191, in api_request
    raise OpenStackApiException(
nova.tests.functional.api.client.OpenStackApiException: Unexpected status code: {"computeFault": {"code": 500, "message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'oslo_db.exception.DBError'>"}}

Note that it is not test case specific and seen in multiple functional test cases.

Example zuul run: https://zuul.opendev.org/t/openstack/build/c942764f8f3f4d5fb8bf847795875c91/logs

It seems to be fairly new failure as I only found 4 hits in the last 20 days and all is since 01-10:

$ logsearch log --job-group nova-functional --result FAILURE 'Cursor needed to be reset because of commit/rollback and can no longer be fetched from.' --days 20
[..snip..]
Builds with matching logs 4/115:
+----------------------------------+---------------------+----------------+----------+-----------------------------------+--------+---------------------------+
| uuid | finished | project | pipeline | review | branch | job |
+----------------------------------+---------------------+----------------+----------+-----------------------------------+--------+---------------------------+
| c942764f8f3f4d5fb8bf847795875c91 | 2023-01-13T03:25:13 | openstack/nova | check | https://review.opendev.org/855649 | master | nova-tox-functional-py310 |
| e57c4a0052ab43e2943c1dcffd45681f | 2023-01-13T03:30:30 | openstack/nova | check | https://review.opendev.org/855654 | master | nova-tox-functional-py39 |
| 42e7e146e6174b2e8fd0949ab671a38a | 2023-01-12T21:48:15 | openstack/nova | check | https://review.opendev.org/863918 | master | nova-tox-functional-py38 |
| 71abaf4c3cce47148976a4c2055dc69a | 2023-01-10T19:53:20 | openstack/nova | check | https://review.opendev.org/863915 | master | nova-tox-functional-py39 |
+----------------------------------+---------------------+----------------+----------+-----------------------------------+--------+---------------------------+

Tags: gate-failure
Revision history for this message
Balazs Gibizer (balazs-gibizer) wrote :

while I still see this happening on the gate I was not able to reproduce it locally even after running the functional test in a loop with randomized order. So the next step would be to instrument the code in a DNM patch and recheck that patch until it reproduces the problem.

tags: added: gate-failure
Changed in nova:
status: New → Confirmed
importance: Undecided → High
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.