← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #94561

[Bug 2080072] [NEW] Failed to delete vpnaas ipsec-site-connections with 502 error, ORM session: SQL execution without transaction in progress

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

This was triggered in gate here:
https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_5e9/928461/4/check/neutron-
tempest-plugin-vpnaas/5e965fe/testr_results.html

The test traceback:

ft1.1: tearDownClass (neutron_tempest_plugin.vpnaas.scenario.test_vpnaas.Vpnaas6in6)testtools.testresult.real._StringException: Traceback (most recent call last):
  File "/opt/stack/tempest/tempest/test.py", line 246, in tearDownClass
    raise value.with_traceback(trace)
  File "/opt/stack/tempest/tempest/test.py", line 210, in tearDownClass
    teardown()
  File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/vpnaas/api/base_vpnaas.py", line 51, in resource_cleanup
    cls._try_delete_resource(
  File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/api/base.py", line 332, in _try_delete_resource
    delete_callable(*args, **kwargs)
  File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/services/network/json/network_client.py", line 112, in _delete
    resp, body = self.delete(uri)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 359, in delete
    return self.request('DELETE', url, extra_headers, headers, body)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 762, in request
    self._error_checker(resp, resp_body)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 856, in _error_checker
    raise exceptions.UnexpectedContentType(str(resp.status),
tempest.lib.exceptions.UnexpectedContentType: Unexpected content type provided
Details: 502

The request is:

2024-09-09 16:55:44.459 89493 INFO tempest.lib.common.rest_client [-] Request (Vpnaas6in6:tearDownClass): 502 DELETE https://10.209.0.221/networking/v2.0/vpn/ipsec-site-connections/f5ce2f15-6b6d-4323-8c79-efeab2c06ad6 300.098s
2024-09-09 16:55:44.460 89493 DEBUG tempest.lib.common.rest_client [-] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Mon, 09 Sep 2024 16:50:44 GMT', 'server': 'Apache/2.4.52 (Ubuntu)', 'content-length': '420', 'connection': 'close', 'content-type': 'text/html; charset=iso-8859-1', 'status': '502', 'content-location': 'https://10.209.0.221/networking/v2.0/vpn/ipsec-site-connections/f5ce2f15-6b6d-4323-8c79-efeab2c06ad6'}
        Body: b'<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">\n<html><head>\n<title>502 Proxy Error</title>\n</head><body>\n<h1>Proxy Error</h1>\n<p>The proxy server received an invalid\r\nresponse from an upstream server.<br />\r\nThe proxy server could not handle the request<p>Reason: <strong>Error reading from remote server</strong></p></p>\n<hr>\n<address>Apache/2.4.52 (Ubuntu) Server at 10.209.0.221 Port 443</address>\n</body></html>\n' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:484

neutron log is filled with these for the duration of the (eventually
failed) request - 5mins:

Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]: WARNING neutron.objects.base [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] ORM session: SQL execution without transaction in progress, traceback:
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/paste/urlmap.py", line 211, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return app(environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/base.py", line 124, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/base.py", line 124, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/request_id.py", line 58, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/catch_errors.py", line 40, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/osprofiler/web.py", line 111, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return request.get_response(self.application)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/keystonemiddleware/auth_token/__init__.py", line 340, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self._app)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/routes/middleware.py", line 153, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = self.app(environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 97, in resource
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     result = method(request=request, **args)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 578, in delete
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self._delete(request, id, **kwargs)
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 135, in wrapped
Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return f(*args, **kwargs)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 142, in wrapper
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return f(*args, **kwargs)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 181, in wrapped
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return f(*dup_args, **dup_kwargs)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 587, in _delete
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     obj = self._item(request, id, parent_id=parent_id)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 353, in _item
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     obj = obj_getter(request.context, id, **kwargs)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 268, in get_ipsec_site_connection
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     ipsec_site_conn_db = self._get_ipsec_site_connection(
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 263, in _get_ipsec_site_connection
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._get_resource(
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 68, in _get_resource
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     r = model_query.get_by_id(context, model, v_id)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/model_query.py", line 211, in get_by_id
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return query.filter(model.id == object_id).one()
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2778, in one
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._iter().one()  # type: ignore
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2827, in _iter
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     result: Union[ScalarResult[_T], Result[_T]] = self.session.execute(
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._execute_internal(
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2207, in _execute_internal
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     fn_result: Optional[Result[Any]] = fn(orm_exec_state)
Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]: 
Sep 09 16:50:54.387442 np0038439257 devstack@neutron-api.service[60639]: DEBUG dbcounter [-] [60639] Writing DB stats neutron:SELECT=609,neutron:DELETE=36,neutron:UPDATE=8 {{(pid=60639) stat_writer /opt/stack/data/venv/lib/python3.10/site-packages/dbcounter.py:115}}
Sep 09 16:51:27.918858 np0038439257 devstack@neutron-api.service[60639]: DEBUG dbcounter [-] [60639] Writing DB stats neutron:SELECT=25 {{(pid=60639) stat_writer /opt/stack/data/venv/lib/python3.10/site-packages/dbcounter.py:115}}
Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: DEBUG neutron_lib.db.api [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] Retry wrapper got retriable exception: (pymysql.err.OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction')
Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: [SQL: DELETE FROM ipsec_site_connections WHERE ipsec_site_connections.id = %(id)s]
Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: [parameters: {'id': 'f5ce2f15-6b6d-4323-8c79-efeab2c06ad6'}]
Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: (Background on this error at: https://sqlalche.me/e/20/e3q8) {{(pid=60639) wrapped /opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py:185}}
Sep 09 16:51:34.398761 np0038439257 devstack@neutron-api.service[60639]: DEBUG oslo_db.api [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] Performing DB retry for function neutron.api.v2.base.Controller._delete {{(pid=60639) wrapper /opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:155}}

Looks like a programming error somewhere in re: transaction handling for
sqlalchemy.

** Affects: neutron
     Importance: Undecided
         Status: New


** Tags: db gate-failure vpnaas

** Tags added: gate-failure vpnaas

** Tags added: db

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

Title:
  Failed to delete vpnaas ipsec-site-connections with 502 error, ORM
  session: SQL execution without transaction in progress

Status in neutron:
  New

Bug description:
  This was triggered in gate here:
  https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_5e9/928461/4/check/neutron-
  tempest-plugin-vpnaas/5e965fe/testr_results.html

  The test traceback:

  ft1.1: tearDownClass (neutron_tempest_plugin.vpnaas.scenario.test_vpnaas.Vpnaas6in6)testtools.testresult.real._StringException: Traceback (most recent call last):
    File "/opt/stack/tempest/tempest/test.py", line 246, in tearDownClass
      raise value.with_traceback(trace)
    File "/opt/stack/tempest/tempest/test.py", line 210, in tearDownClass
      teardown()
    File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/vpnaas/api/base_vpnaas.py", line 51, in resource_cleanup
      cls._try_delete_resource(
    File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/api/base.py", line 332, in _try_delete_resource
      delete_callable(*args, **kwargs)
    File "/opt/stack/tempest/.tox/tempest/lib/python3.10/site-packages/neutron_tempest_plugin/services/network/json/network_client.py", line 112, in _delete
      resp, body = self.delete(uri)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 359, in delete
      return self.request('DELETE', url, extra_headers, headers, body)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 762, in request
      self._error_checker(resp, resp_body)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 856, in _error_checker
      raise exceptions.UnexpectedContentType(str(resp.status),
  tempest.lib.exceptions.UnexpectedContentType: Unexpected content type provided
  Details: 502

  The request is:

  2024-09-09 16:55:44.459 89493 INFO tempest.lib.common.rest_client [-] Request (Vpnaas6in6:tearDownClass): 502 DELETE https://10.209.0.221/networking/v2.0/vpn/ipsec-site-connections/f5ce2f15-6b6d-4323-8c79-efeab2c06ad6 300.098s
  2024-09-09 16:55:44.460 89493 DEBUG tempest.lib.common.rest_client [-] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
          Body: None
      Response - Headers: {'date': 'Mon, 09 Sep 2024 16:50:44 GMT', 'server': 'Apache/2.4.52 (Ubuntu)', 'content-length': '420', 'connection': 'close', 'content-type': 'text/html; charset=iso-8859-1', 'status': '502', 'content-location': 'https://10.209.0.221/networking/v2.0/vpn/ipsec-site-connections/f5ce2f15-6b6d-4323-8c79-efeab2c06ad6'}
          Body: b'<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">\n<html><head>\n<title>502 Proxy Error</title>\n</head><body>\n<h1>Proxy Error</h1>\n<p>The proxy server received an invalid\r\nresponse from an upstream server.<br />\r\nThe proxy server could not handle the request<p>Reason: <strong>Error reading from remote server</strong></p></p>\n<hr>\n<address>Apache/2.4.52 (Ubuntu) Server at 10.209.0.221 Port 443</address>\n</body></html>\n' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:484

  neutron log is filled with these for the duration of the (eventually
  failed) request - 5mins:

  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]: WARNING neutron.objects.base [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] ORM session: SQL execution without transaction in progress, traceback:
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/paste/urlmap.py", line 211, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return app(environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/base.py", line 124, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/base.py", line 124, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/request_id.py", line 58, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_middleware/catch_errors.py", line 40, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self.application)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/osprofiler/web.py", line 111, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return request.get_response(self.application)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/keystonemiddleware/auth_token/__init__.py", line 340, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = req.get_response(self._app)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1313, in send
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     status, headers, app_iter = self.call_application(
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/request.py", line 1278, in call_application
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     app_iter = application(self.environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/routes/middleware.py", line 153, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     response = self.app(environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 143, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return resp(environ, start_response)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 129, in __call__
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     resp = self.call_func(req, *args, **kw)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/webob/dec.py", line 193, in call_func
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self.func(req, *args, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 97, in resource
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     result = method(request=request, **args)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 578, in delete
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return self._delete(request, id, **kwargs)
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 135, in wrapped
  Sep 09 16:50:44.375166 np0038439257 devstack@neutron-api.service[60639]:     return f(*args, **kwargs)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 142, in wrapper
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return f(*args, **kwargs)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 181, in wrapped
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return f(*dup_args, **dup_kwargs)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 587, in _delete
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     obj = self._item(request, id, parent_id=parent_id)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron/neutron/api/v2/base.py", line 353, in _item
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     obj = obj_getter(request.context, id, **kwargs)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 268, in get_ipsec_site_connection
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     ipsec_site_conn_db = self._get_ipsec_site_connection(
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 263, in _get_ipsec_site_connection
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._get_resource(
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/neutron-vpnaas/neutron_vpnaas/db/vpn/vpn_db.py", line 68, in _get_resource
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     r = model_query.get_by_id(context, model, v_id)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/model_query.py", line 211, in get_by_id
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return query.filter(model.id == object_id).one()
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2778, in one
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._iter().one()  # type: ignore
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2827, in _iter
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     result: Union[ScalarResult[_T], Result[_T]] = self.session.execute(
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     return self._execute_internal(
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2207, in _execute_internal
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]:     fn_result: Optional[Result[Any]] = fn(orm_exec_state)
  Sep 09 16:50:44.381363 np0038439257 devstack@neutron-api.service[60639]: 
  Sep 09 16:50:54.387442 np0038439257 devstack@neutron-api.service[60639]: DEBUG dbcounter [-] [60639] Writing DB stats neutron:SELECT=609,neutron:DELETE=36,neutron:UPDATE=8 {{(pid=60639) stat_writer /opt/stack/data/venv/lib/python3.10/site-packages/dbcounter.py:115}}
  Sep 09 16:51:27.918858 np0038439257 devstack@neutron-api.service[60639]: DEBUG dbcounter [-] [60639] Writing DB stats neutron:SELECT=25 {{(pid=60639) stat_writer /opt/stack/data/venv/lib/python3.10/site-packages/dbcounter.py:115}}
  Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: DEBUG neutron_lib.db.api [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] Retry wrapper got retriable exception: (pymysql.err.OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction')
  Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: [SQL: DELETE FROM ipsec_site_connections WHERE ipsec_site_connections.id = %(id)s]
  Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: [parameters: {'id': 'f5ce2f15-6b6d-4323-8c79-efeab2c06ad6'}]
  Sep 09 16:51:34.397983 np0038439257 devstack@neutron-api.service[60639]: (Background on this error at: https://sqlalche.me/e/20/e3q8) {{(pid=60639) wrapped /opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py:185}}
  Sep 09 16:51:34.398761 np0038439257 devstack@neutron-api.service[60639]: DEBUG oslo_db.api [None req-a3a367f8-aeb8-4767-a96b-69b1c05a6a38 tempest-Vpnaas6in6-389378637 tempest-Vpnaas6in6-389378637-project-member] Performing DB retry for function neutron.api.v2.base.Controller._delete {{(pid=60639) wrapper /opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py:155}}

  Looks like a programming error somewhere in re: transaction handling
  for sqlalchemy.

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/2080072/+subscriptions
  Thread Previous • Date Previous • • Thread Next