yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #90986
[Bug 2002782] [NEW] nova functional test intermittently fail with DB error: Cursor needed to be reset because of commit/rollback and can no longer be fetched from
Public bug reported:
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 |
+----------------------------------+---------------------+----------------+----------+-----------------------------------+--------+---------------------------+
** Affects: nova
Importance: Undecided
Status: New
--
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/2002782
Title:
nova functional test intermittently fail with DB error: Cursor needed
to be reset because of commit/rollback and can no longer be fetched
from
Status in OpenStack Compute (nova):
New
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 |
+----------------------------------+---------------------+----------------+----------+-----------------------------------+--------+---------------------------+
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/2002782/+subscriptions