yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #94652
[Bug 2083092] [NEW] sqlalchemy.exc.InvalidRequestError im image update
Public bug reported:
A strange failure was caught in glance-multistore-cinder-import job.
According to the tempest test case failure, image deleted failed because
of 500 error.
https://zuul.opendev.org/t/openstack/build/bcb2045e696c473e9ab8a1f376bcc714
And the following traceback is logged in g-api.log. I'm reporting this
here in case this could be related to recent migration to SQLAlchemy 2.0
.
```
Sep 27 15:44:58.566377 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Determining version of request: POST /v2/images Accept: application/json {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}
Sep 27 15:44:58.566594 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Using url versioning {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}
Sep 27 15:44:58.566806 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Matched version: v2 {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}
Sep 27 15:44:58.567040 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] new path /v2/images {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}
...
'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88666) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.033280 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
Sep 27 15:44:58.041288 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.062043 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.139389 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
...
Sep 27 15:44:58.507784 np0038636614 devstack@g-api.service[88666]: DEBUG glance.db.sqlalchemy.api [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] StaleDataError while deleting property 'os_glance_import_task' from image 'f16c174b-46fd-4241-aeb6-ae85583564d1' likely means we raced during delete: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched. {{(pid=88666) _image_property_delete /opt/stack/glance/glance/db/sqlalchemy/api.py:1328}}
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Caught error: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.: sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi Traceback (most recent call last):
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1302, in __call__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi action_result = self.dispatch(self.controller, action,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1345, in dispatch
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return method(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 414, in wrapped
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return func(self, req, *args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/api/v2/images.py", line 908, in delete
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_repo.remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/notifier.py", line 538, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi super(ImageRepoProxy, self).remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/__init__.py", line 211, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.db_api.image_update(self.context, image.image_id,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 56, in wrapped_f
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return Retrying(*dargs, **dkw).call(f, *args, **kw)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 257, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return attempt.get(self._wrap_exception)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 301, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi six.reraise(self.value[0], self.value[1], self.value[2])
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/usr/lib/python3/dist-packages/six.py", line 719, in reraise
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise value
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 251, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 177, in image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_ref = _image_update(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1079, in _image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _set_properties_for_image(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1254, in _set_properties_for_image
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _image_property_delete(context, session, prop_ref.name,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 566, in __get__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self.impl.get(state, dict_) # type: ignore[no-any-return]
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1086, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi value = self._fire_loader_callables(state, key, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1116, in _fire_loader_callables
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return state._load_expired(state, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/state.py", line 803, in _load_expired
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.manager.expired_attribute_loader(self, toload, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 1670, in load_scalar_attributes
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = load_on_ident(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 509, in load_on_ident
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return load_on_pk_identity(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 694, in load_on_pk_identity
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi session.execute(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self._execute_internal(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2237, in _execute_internal
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi conn = self._connection_for_bind(bind)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2101, in _connection_for_bind
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi TransactionalContext._trans_ctx_check(self)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/util.py", line 111, in _trans_ctx_check
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise exc.InvalidRequestError(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: [pid: 88666|app: 0|req: 1009/2037] 127.0.0.1 () {40 vars in 883 bytes} [Fri Sep 27 15:44:58 2024] DELETE /v2/images/f16c174b-46fd-4241-aeb6-ae85583564d1 => generated 186 bytes in 526 msecs (HTTP/1.1 500) 4 headers in 176 bytes (1 switches on core 0)
```
** Affects: glance
Importance: Undecided
Status: New
** Description changed:
A strange failure was caught in glance-multistore-cinder-import job.
+ According to the tempest test case failure, image deleted failed because
+ of 500 error.
https://zuul.opendev.org/t/openstack/build/bcb2045e696c473e9ab8a1f376bcc714
- I'm reporting it here in case this could be related to recent migration
- to SQLAlchemy 2.0 .
+ And the following traceback is logged in g-api.log. I'm reporting this
+ here in case this could be related to recent migration to SQLAlchemy 2.0
+ .
```
Sep 27 15:44:58.566377 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Determining version of request: POST /v2/images Accept: application/json {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}
Sep 27 15:44:58.566594 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Using url versioning {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}
Sep 27 15:44:58.566806 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Matched version: v2 {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}
Sep 27 15:44:58.567040 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] new path /v2/images {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}
...
'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88666) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.033280 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
Sep 27 15:44:58.041288 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.062043 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.139389 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
...
Sep 27 15:44:58.507784 np0038636614 devstack@g-api.service[88666]: DEBUG glance.db.sqlalchemy.api [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] StaleDataError while deleting property 'os_glance_import_task' from image 'f16c174b-46fd-4241-aeb6-ae85583564d1' likely means we raced during delete: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched. {{(pid=88666) _image_property_delete /opt/stack/glance/glance/db/sqlalchemy/api.py:1328}}
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Caught error: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.: sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi Traceback (most recent call last):
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1302, in __call__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi action_result = self.dispatch(self.controller, action,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1345, in dispatch
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return method(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 414, in wrapped
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return func(self, req, *args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/api/v2/images.py", line 908, in delete
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_repo.remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/notifier.py", line 538, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi super(ImageRepoProxy, self).remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/__init__.py", line 211, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.db_api.image_update(self.context, image.image_id,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 56, in wrapped_f
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return Retrying(*dargs, **dkw).call(f, *args, **kw)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 257, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return attempt.get(self._wrap_exception)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 301, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi six.reraise(self.value[0], self.value[1], self.value[2])
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/usr/lib/python3/dist-packages/six.py", line 719, in reraise
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise value
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 251, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 177, in image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_ref = _image_update(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1079, in _image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _set_properties_for_image(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1254, in _set_properties_for_image
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _image_property_delete(context, session, prop_ref.name,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 566, in __get__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self.impl.get(state, dict_) # type: ignore[no-any-return]
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1086, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi value = self._fire_loader_callables(state, key, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1116, in _fire_loader_callables
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return state._load_expired(state, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/state.py", line 803, in _load_expired
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.manager.expired_attribute_loader(self, toload, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 1670, in load_scalar_attributes
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = load_on_ident(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 509, in load_on_ident
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return load_on_pk_identity(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 694, in load_on_pk_identity
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi session.execute(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self._execute_internal(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2237, in _execute_internal
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi conn = self._connection_for_bind(bind)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2101, in _connection_for_bind
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi TransactionalContext._trans_ctx_check(self)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/util.py", line 111, in _trans_ctx_check
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise exc.InvalidRequestError(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
- Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi
+ Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: [pid: 88666|app: 0|req: 1009/2037] 127.0.0.1 () {40 vars in 883 bytes} [Fri Sep 27 15:44:58 2024] DELETE /v2/images/f16c174b-46fd-4241-aeb6-ae85583564d1 => generated 186 bytes in 526 msecs (HTTP/1.1 500) 4 headers in 176 bytes (1 switches on core 0)
```
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/2083092
Title:
sqlalchemy.exc.InvalidRequestError im image update
Status in Glance:
New
Bug description:
A strange failure was caught in glance-multistore-cinder-import job.
According to the tempest test case failure, image deleted failed
because of 500 error.
https://zuul.opendev.org/t/openstack/build/bcb2045e696c473e9ab8a1f376bcc714
And the following traceback is logged in g-api.log. I'm reporting this
here in case this could be related to recent migration to SQLAlchemy
2.0 .
```
Sep 27 15:44:58.566377 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Determining version of request: POST /v2/images Accept: application/json {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}
Sep 27 15:44:58.566594 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Using url versioning {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}
Sep 27 15:44:58.566806 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Matched version: v2 {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}
Sep 27 15:44:58.567040 np0038636614 devstack@g-api.service[88666]: DEBUG glance.api.middleware.version_negotiation [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] new path /v2/images {{(pid=88666) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}
...
'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88666) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.033280 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
Sep 27 15:44:58.041288 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.062043 np0038636614 devstack@g-api.service[88665]: DEBUG glance.common.utils [-] Sorted locations: [{'id': 37, 'url': 'cinder://lvmdriver-1/09bc6160-d566-45c9-9cde-4e35497dd7a9', 'metadata': {'store': 'lvmdriver-1'}, 'status': 'active'}, {'id': 38, 'url': 'cinder://lvmdriver-2/3cd47cd3-ad7f-437e-bfa4-10101e019d15', 'metadata': {'store': 'lvmdriver-2'}, 'status': 'active'}] {{(pid=88665) sort_image_locations /opt/stack/glance/glance/common/utils.py:735}}
Sep 27 15:44:58.139389 np0038636614 devstack@g-api.service[88666]: DEBUG glance_store._drivers.cinder.store [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Cinderclient connection created for user glance using URL: https://158.69.74.140/identity/v3. {{(pid=88666) get_cinderclient /opt/stack/data/venv/lib/python3.10/site-packages/glance_store/_drivers/cinder/store.py:648}}
...
Sep 27 15:44:58.507784 np0038636614 devstack@g-api.service[88666]: DEBUG glance.db.sqlalchemy.api [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] StaleDataError while deleting property 'os_glance_import_task' from image 'f16c174b-46fd-4241-aeb6-ae85583564d1' likely means we raced during delete: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched. {{(pid=88666) _image_property_delete /opt/stack/glance/glance/db/sqlalchemy/api.py:1328}}
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi [None req-cb60319b-481e-4127-96ff-8e6dfdfafeca tempest-ImagesFormatTest-522606120 tempest-ImagesFormatTest-522606120-project-member] Caught error: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.: sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi Traceback (most recent call last):
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1302, in __call__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi action_result = self.dispatch(self.controller, action,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1345, in dispatch
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return method(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 414, in wrapped
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return func(self, req, *args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/api/v2/images.py", line 908, in delete
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_repo.remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/notifier.py", line 538, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi super(ImageRepoProxy, self).remove(image)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = self.base.remove(base_item)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/__init__.py", line 211, in remove
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.db_api.image_update(self.context, image.image_id,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 56, in wrapped_f
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return Retrying(*dargs, **dkw).call(f, *args, **kw)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 257, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return attempt.get(self._wrap_exception)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 301, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi six.reraise(self.value[0], self.value[1], self.value[2])
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/usr/lib/python3/dist-packages/six.py", line 719, in reraise
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise value
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/retrying.py", line 251, in call
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 177, in image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi image_ref = _image_update(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1079, in _image_update
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _set_properties_for_image(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 545, in wrapper
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return f(*args, **kwargs)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1254, in _set_properties_for_image
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi _image_property_delete(context, session, prop_ref.name,
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 566, in __get__
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self.impl.get(state, dict_) # type: ignore[no-any-return]
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1086, in get
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi value = self._fire_loader_callables(state, key, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/attributes.py", line 1116, in _fire_loader_callables
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return state._load_expired(state, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/state.py", line 803, in _load_expired
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi self.manager.expired_attribute_loader(self, toload, passive)
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 1670, in load_scalar_attributes
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi result = load_on_ident(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 509, in load_on_ident
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return load_on_pk_identity(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/loading.py", line 694, in load_on_pk_identity
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi session.execute(
Sep 27 15:44:58.532097 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi return self._execute_internal(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2237, in _execute_internal
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi conn = self._connection_for_bind(bind)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2101, in _connection_for_bind
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi TransactionalContext._trans_ctx_check(self)
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/util.py", line 111, in _trans_ctx_check
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi raise exc.InvalidRequestError(
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi sqlalchemy.exc.InvalidRequestError: Can't operate on closed transaction inside context manager. Please complete the context manager before emitting further commands.
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: ERROR glance.common.wsgi
Sep 27 15:44:58.535876 np0038636614 devstack@g-api.service[88666]: [pid: 88666|app: 0|req: 1009/2037] 127.0.0.1 () {40 vars in 883 bytes} [Fri Sep 27 15:44:58 2024] DELETE /v2/images/f16c174b-46fd-4241-aeb6-ae85583564d1 => generated 186 bytes in 526 msecs (HTTP/1.1 500) 4 headers in 176 bytes (1 switches on core 0)
```
To manage notifications about this bug go to:
https://bugs.launchpad.net/glance/+bug/2083092/+subscriptions
