← Back to team overview

yahoo-eng-team team mailing list archive

[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