← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1950273] [NEW] Error 500 during log update

 

Public bug reported:

It happened in the CI job:
https://70b72721af304b4c1528-2577420e766b653c3ec089b9602cc4a1.ssl.cf2.rackcdn.com/811411/7/check/neutron-
tempest-plugin-api/438deaa/testr_results.html

Test failure:

ft1.2: neutron_tempest_plugin.api.admin.test_logging.LoggingTestJSON.test_log_lifecycle[id-8d2e1ba5-455b-4519-a88e-e587002faba6]testtools.testresult.real._StringException: pythonlogging:'': {{{
2021-11-09 00:01:03,854 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 201 POST https://158.69.75.224:9696/v2.0/log/logs 0.096s
2021-11-09 00:01:03,854 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: {"log": {"name": "tempest-test-log-694677312", "description": "tempest-test-log-desc-135349090", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true}}
    Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '448', 'x-openstack-request-id': 'req-19dfbf9a-3b85-43d4-9b87-ee3495ddc617', 'connection': 'close', 'status': '201', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs'}
        Body: b'{"log": {"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "project_id": "7ff7323f47574ee5a1fbf7aa7b472c60", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z", "tenant_id": "7ff7323f47574ee5a1fbf7aa7b472c60"}}'
2021-11-09 00:01:03,893 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 200 GET https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 0.038s
2021-11-09 00:01:03,893 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '349', 'x-openstack-request-id': 'req-2ef509a0-a22c-4854-a209-245454142df0', 'connection': 'close', 'status': '200', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511'}
        Body: b'{"log": {"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z"}}'
2021-11-09 00:01:03,919 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 200 GET https://158.69.75.224:9696/v2.0/log/logs 0.025s
2021-11-09 00:01:03,919 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '451', 'x-openstack-request-id': 'req-8edc8bb1-ec39-4ef7-b12e-832a98b5553c', 'connection': 'close', 'status': '200', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs'}
        Body: b'{"logs": [{"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "project_id": "7ff7323f47574ee5a1fbf7aa7b472c60", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z", "tenant_id": "7ff7323f47574ee5a1fbf7aa7b472c60"}]}'
2021-11-09 00:01:04,176 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 500 PUT https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 0.256s
2021-11-09 00:01:04,177 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'X-Auth-Token': '<omitted>'}
        Body: {"log": {"description": "tempest-test-log-197708411", "enabled": false}}
    Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:04 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '150', 'x-openstack-request-id': 'req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1', 'connection': 'close', 'status': '500', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511'}
        Body: b'{"NeutronError": {"type": "HTTPInternalServerError", "message": "Request Failed: internal server error while processing your request.", "detail": ""}}'
}}}

Traceback (most recent call last):
  File "/opt/stack/tempest/.tox/tempest/lib/python3.8/site-packages/neutron_tempest_plugin/api/admin/test_logging.py", line 50, in test_log_lifecycle
    self.admin_client.update_log(log['id'],
  File "/opt/stack/tempest/.tox/tempest/lib/python3.8/site-packages/neutron_tempest_plugin/services/network/json/network_client.py", line 158, in _update
    resp, body = self.put(uri, post_data, headers=headers)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 363, in put
    return self.request('PUT', url, extra_headers, headers, body, chunked)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 703, in request
    self._error_checker(resp, resp_body)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 879, in _error_checker
    raise exceptions.ServerFault(resp_body, resp=resp,
tempest.lib.exceptions.ServerFault: Got server fault
Details: Request Failed: internal server error while processing your request.


Error in the neutron server:

Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR ovsdbapp.backend.ovs_idl.transaction [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] Traceback (most recent call last):
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 131, in run
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     txn.results.put(txn.do_commit())
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 93, in do_commit
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     command.run_idl(txn)
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/command.py", line 139, in run_idl
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     record = self.api.lookup(self.table, self.record)
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 207, in lookup
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     return super().lookup(table, record, default=default, timeout=timeout,
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 208, in lookup
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     return self._lookup(table, record)
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 240, in _lookup
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     raise idlutils.RowNotFound(table=table, col='uuid',
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: 
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] Extension driver 'ovn' failed in update_log: ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager Traceback (most recent call last):
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/services/logapi/drivers/manager.py", line 116, in call
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     getattr(driver, method_name)(*args, **kwargs)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/services/logapi/drivers/ovn/driver.py", line 295, in update_log
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     self._set_acls_log(pgs, ovn_txn, actions_enabled,
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/lib/python3.8/contextlib.py", line 120, in __exit__
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     next(self.gen)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 274, in transaction
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     yield t
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/lib/python3.8/contextlib.py", line 120, in __exit__
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     next(self.gen)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/api.py", line 110, in transaction
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     del self._nested_txns_map[cur_thread_id]
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/api.py", line 61, in __exit__
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     self.result = self.commit()
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 65, in commit
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     raise result.ex
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 131, in run
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     txn.results.put(txn.do_commit())
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 93, in do_commit
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     command.run_idl(txn)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/command.py", line 139, in run_idl
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     record = self.api.lookup(self.table, self.record)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 207, in lookup
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     return super().lookup(table, record, default=default, timeout=timeout,
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 208, in lookup
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     return self._lookup(table, record)
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 240, in _lookup
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     raise idlutils.RowNotFound(table=table, col='uuid',
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager 
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] update failed: No details.: neutron_lib.exceptions.DriverCallError
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource Traceback (most recent call last):
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 98, in resource
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     result = method(request=request, **args)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 630, in update
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return self._update(request, id, body, **kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 139, in wrapped
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     setattr(e, '_RETRY_EXCEEDED', True)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 135, in wrapped
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*args, **kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_db/api.py", line 154, in wrapper
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     ectxt.value = e.inner_exc
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_db/api.py", line 142, in wrapper
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*args, **kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 183, in wrapped
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     LOG.debug("Retry wrapper got retriable exception: %s", e)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 179, in wrapped
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*dup_args, **dup_kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 695, in _update
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 48, in inner
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     result = f(*args, **kwargs)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/services/logapi/logging_plugin.py", line 125, in update_log
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.driver_manager.call(
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/services/logapi/drivers/manager.py", line 125, in call
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise exceptions.DriverCallError(exc_list=exc_list)
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource neutron_lib.exceptions.DriverCallError
Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource 
Nov 09 00:01:04.178416 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: INFO neutron.wsgi [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] 158.69.75.224,158.69.75.224 "PUT /v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 HTTP/1.1" status: 500  len: 368 time: 0.2507014

** Affects: neutron
     Importance: High
         Status: Confirmed


** Tags: api logging ovn

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1950273

Title:
  Error 500 during log update

Status in neutron:
  Confirmed

Bug description:
  It happened in the CI job:
  https://70b72721af304b4c1528-2577420e766b653c3ec089b9602cc4a1.ssl.cf2.rackcdn.com/811411/7/check/neutron-
  tempest-plugin-api/438deaa/testr_results.html

  Test failure:

  ft1.2: neutron_tempest_plugin.api.admin.test_logging.LoggingTestJSON.test_log_lifecycle[id-8d2e1ba5-455b-4519-a88e-e587002faba6]testtools.testresult.real._StringException: pythonlogging:'': {{{
  2021-11-09 00:01:03,854 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 201 POST https://158.69.75.224:9696/v2.0/log/logs 0.096s
  2021-11-09 00:01:03,854 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
          Body: {"log": {"name": "tempest-test-log-694677312", "description": "tempest-test-log-desc-135349090", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true}}
      Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '448', 'x-openstack-request-id': 'req-19dfbf9a-3b85-43d4-9b87-ee3495ddc617', 'connection': 'close', 'status': '201', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs'}
          Body: b'{"log": {"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "project_id": "7ff7323f47574ee5a1fbf7aa7b472c60", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z", "tenant_id": "7ff7323f47574ee5a1fbf7aa7b472c60"}}'
  2021-11-09 00:01:03,893 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 200 GET https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 0.038s
  2021-11-09 00:01:03,893 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
          Body: None
      Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '349', 'x-openstack-request-id': 'req-2ef509a0-a22c-4854-a209-245454142df0', 'connection': 'close', 'status': '200', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511'}
          Body: b'{"log": {"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z"}}'
  2021-11-09 00:01:03,919 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 200 GET https://158.69.75.224:9696/v2.0/log/logs 0.025s
  2021-11-09 00:01:03,919 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
          Body: None
      Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:03 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '451', 'x-openstack-request-id': 'req-8edc8bb1-ec39-4ef7-b12e-832a98b5553c', 'connection': 'close', 'status': '200', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs'}
          Body: b'{"logs": [{"id": "fae55a16-cc4f-4346-8d71-020f6573b511", "project_id": "7ff7323f47574ee5a1fbf7aa7b472c60", "name": "tempest-test-log-694677312", "resource_type": "security_group", "resource_id": null, "target_id": null, "event": "ALL", "enabled": true, "revision_number": 0, "description": "tempest-test-log-desc-135349090", "created_at": "2021-11-09T00:01:03Z", "updated_at": "2021-11-09T00:01:03Z", "tenant_id": "7ff7323f47574ee5a1fbf7aa7b472c60"}]}'
  2021-11-09 00:01:04,176 122316 INFO     [tempest.lib.common.rest_client] Request (LoggingTestJSON:test_log_lifecycle): 500 PUT https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 0.256s
  2021-11-09 00:01:04,177 122316 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'X-Auth-Token': '<omitted>'}
          Body: {"log": {"description": "tempest-test-log-197708411", "enabled": false}}
      Response - Headers: {'date': 'Tue, 09 Nov 2021 00:01:04 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'content-length': '150', 'x-openstack-request-id': 'req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1', 'connection': 'close', 'status': '500', 'content-location': 'https://158.69.75.224:9696/v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511'}
          Body: b'{"NeutronError": {"type": "HTTPInternalServerError", "message": "Request Failed: internal server error while processing your request.", "detail": ""}}'
  }}}

  Traceback (most recent call last):
    File "/opt/stack/tempest/.tox/tempest/lib/python3.8/site-packages/neutron_tempest_plugin/api/admin/test_logging.py", line 50, in test_log_lifecycle
      self.admin_client.update_log(log['id'],
    File "/opt/stack/tempest/.tox/tempest/lib/python3.8/site-packages/neutron_tempest_plugin/services/network/json/network_client.py", line 158, in _update
      resp, body = self.put(uri, post_data, headers=headers)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 363, in put
      return self.request('PUT', url, extra_headers, headers, body, chunked)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 703, in request
      self._error_checker(resp, resp_body)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 879, in _error_checker
      raise exceptions.ServerFault(resp_body, resp=resp,
  tempest.lib.exceptions.ServerFault: Got server fault
  Details: Request Failed: internal server error while processing your request.

  
  Error in the neutron server:

  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR ovsdbapp.backend.ovs_idl.transaction [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] Traceback (most recent call last):
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 131, in run
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     txn.results.put(txn.do_commit())
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 93, in do_commit
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     command.run_idl(txn)
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/command.py", line 139, in run_idl
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     record = self.api.lookup(self.table, self.record)
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 207, in lookup
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     return super().lookup(table, record, default=default, timeout=timeout,
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 208, in lookup
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     return self._lookup(table, record)
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 240, in _lookup
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]:     raise idlutils.RowNotFound(table=table, col='uuid',
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
  Nov 09 00:01:04.170991 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: 
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] Extension driver 'ovn' failed in update_log: ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager Traceback (most recent call last):
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/services/logapi/drivers/manager.py", line 116, in call
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     getattr(driver, method_name)(*args, **kwargs)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/services/logapi/drivers/ovn/driver.py", line 295, in update_log
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     self._set_acls_log(pgs, ovn_txn, actions_enabled,
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/lib/python3.8/contextlib.py", line 120, in __exit__
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     next(self.gen)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 274, in transaction
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     yield t
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/lib/python3.8/contextlib.py", line 120, in __exit__
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     next(self.gen)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/api.py", line 110, in transaction
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     del self._nested_txns_map[cur_thread_id]
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/api.py", line 61, in __exit__
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     self.result = self.commit()
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 65, in commit
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     raise result.ex
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 131, in run
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     txn.results.put(txn.do_commit())
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 93, in do_commit
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     command.run_idl(txn)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/command.py", line 139, in run_idl
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     record = self.api.lookup(self.table, self.record)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 207, in lookup
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     return super().lookup(table, record, default=default, timeout=timeout,
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 208, in lookup
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     return self._lookup(table, record)
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager   File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 240, in _lookup
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager     raise idlutils.RowNotFound(table=table, col='uuid',
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager ovsdbapp.backend.ovs_idl.idlutils.RowNotFound: Cannot find ACL with uuid=1de76163-c1d7-4bf4-aa09-8c081b191562
  Nov 09 00:01:04.172751 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.services.logapi.drivers.manager 
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] update failed: No details.: neutron_lib.exceptions.DriverCallError
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource Traceback (most recent call last):
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 98, in resource
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     result = method(request=request, **args)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 630, in update
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return self._update(request, id, body, **kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 139, in wrapped
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     setattr(e, '_RETRY_EXCEEDED', True)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 135, in wrapped
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*args, **kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_db/api.py", line 154, in wrapper
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     ectxt.value = e.inner_exc
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_db/api.py", line 142, in wrapper
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*args, **kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 183, in wrapped
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     LOG.debug("Retry wrapper got retriable exception: %s", e)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.force_reraise()
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise self.value
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.8/dist-packages/neutron_lib/db/api.py", line 179, in wrapped
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     return f(*dup_args, **dup_kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 695, in _update
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     obj = obj_updater(request.context, id, **kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 48, in inner
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     result = f(*args, **kwargs)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/services/logapi/logging_plugin.py", line 125, in update_log
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     self.driver_manager.call(
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource   File "/opt/stack/neutron/neutron/services/logapi/drivers/manager.py", line 125, in call
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource     raise exceptions.DriverCallError(exc_list=exc_list)
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource neutron_lib.exceptions.DriverCallError
  Nov 09 00:01:04.175451 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: ERROR neutron.api.v2.resource 
  Nov 09 00:01:04.178416 ubuntu-focal-ovh-bhs1-0027269263 neutron-server[108826]: INFO neutron.wsgi [None req-fa4186cb-5926-49b0-a913-f8ffa8e7f6b1 tempest-LoggingTestJSON-1708151946 tempest-LoggingTestJSON-1708151946-project-admin] 158.69.75.224,158.69.75.224 "PUT /v2.0/log/logs/fae55a16-cc4f-4346-8d71-020f6573b511 HTTP/1.1" status: 500  len: 368 time: 0.2507014

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