Reviewed: https://review.opendev.org/c/openstack/glance/+/783668 Committed: https://opendev.org/openstack/glance/commit/7779c20198c4ee09ee2c31ba0f5752151331abaf Submitter: "Zuul (22348)" Branch: master
commit 7779c20198c4ee09ee2c31ba0f5752151331abaf Author: Dan Smith <[email protected]> Date: Mon Mar 29 08:07:41 2021 -0700 Ignore stale image property removal Occasionally we fail to delete a property from an image and get a StaleDataError from SQLAlchemy. It looks like maybe we are just racing with another operation to delete a single property (i.e. a race between image delete and the end of an import cleanup). This ignores that "can't delete because it is already deleted" error and logs to debug about the situation for later auditing and confirmation. Change-Id: Ida5bc659b7481fa0a7f3926a54520628a7a4c406 Closes-Bug: #1895173 ** Changed in: glance Status: In Progress => Fix Released -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to Glance. https://bugs.launchpad.net/bugs/1895173 Title: Caught error: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched Status in Glance: Fix Released Bug description: tearDownClass (tempest.api.image.v2.test_images.ImportImagesTest) https://32e87445f1b3f9b72fad-889023abcee881d48f07f1c8f07a15d7.ssl.cf2.rackcdn.com/749304/2/check/nova- ceph-multistore/03c5041/testr_results.html File "/opt/stack/tempest/tempest/test.py", line 242, in tearDownClass six.reraise(etype, value, trace) File "/opt/stack/tempest/.tox/tempest/lib/python3.6/site-packages/six.py", line 703, in reraise raise value File "/opt/stack/tempest/tempest/test.py", line 214, in tearDownClass teardown() File "/opt/stack/tempest/tempest/test.py", line 585, in resource_cleanup raise testtools.MultipleExceptions(*cleanup_errors) testtools.runtest.MultipleExceptions: ((<class 'tempest.lib.exceptions.ServerFault'>, Got server fault Details: The server has either erred or is incapable of performing the requested operation.<br /><br /> , <traceback object at 0x7ff36844c388>), (<class 'tempest.lib.exceptions.TimeoutException'>, Request timed out Details: (ImportImagesTest:tearDownClass) Failed to delete image 286e8f52-2d10-4605-a086-30b3d64fe284 within the required time (300 s)., <traceback object at 0x7ff368a48208>)) https://zuul.opendev.org/t/openstack/build/03c5041a95064d6c8320dfb4a8ccd528/log/controller/logs/screen-g-api.txt#21361 Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi [None req-d49277db-83c2-472e-a9c6-084b46e95d07 tempest-ImportImagesTest-1047019480 tempest-ImportImagesTest-1047019480] Caught error: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched.: sqlalchemy.orm.exc.StaleDataError: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched. Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi Traceback (most recent call last): Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1348, in __call__ Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi request, **action_args) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/wsgi.py", line 1391, in dispatch Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return method(*args, **kwargs) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 416, in wrapped Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return func(self, req, *args, **kwargs) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/api/v2/images.py", line 664, in delete Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi image_repo.remove(image) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi result = self.base.remove(base_item) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/notifier.py", line 542, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi super(ImageRepoProxy, self).remove(image) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi result = self.base.remove(base_item) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi result = self.base.remove(base_item) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/domain/proxy.py", line 104, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi result = self.base.remove(base_item) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi [Previous line repeated 1 more time] Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/__init__.py", line 204, in remove Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi purge_props=True) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 161, in image_update Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi from_state=from_state, atomic_props=atomic_props) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/retrying.py", line 49, in wrapped_f Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return Retrying(*dargs, **dkw).call(f, *args, **kw) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/retrying.py", line 206, in call Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return attempt.get(self._wrap_exception) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/retrying.py", line 247, in get Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi six.reraise(self.value[0], self.value[1], self.value[2]) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/six.py", line 703, in reraise Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi raise value Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/retrying.py", line 200, in call Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi attempt = Attempt(fn(*args, **kwargs), attempt_number, False) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 547, in wrapper Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return f(*args, **kwargs) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 972, in _image_update Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi atomic_props, session) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/common/utils.py", line 547, in wrapper Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi return f(*args, **kwargs) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1131, in _set_properties_for_image Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi image_ref.id, session=session) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/api.py", line 1190, in image_property_delete Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi prop.delete(session=session) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/models.py", line 93, in delete Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi self.save(session=session) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/opt/stack/glance/glance/db/sqlalchemy/models.py", line 73, in save Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi super(GlanceBase, self).save(session or db_api.get_session()) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/oslo_db/sqlalchemy/models.py", line 48, in save Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi session.flush() Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 2523, in flush Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi self._flush(objects) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 2664, in _flush Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi transaction.rollback(_capture_exception=True) Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/util/langhelpers.py", line 69, in __exit__ Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi exc_value, with_traceback=exc_tb, Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/util/compat.py", line 182, in raise_ Sep 10 14:27:15.924967 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi raise exception Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/session.py", line 2624, in _flush Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi flush_context.execute() Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/unitofwork.py", line 422, in execute Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi rec.execute(self) Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/unitofwork.py", line 589, in execute Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi uow, Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/persistence.py", line 236, in save_obj Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi update, Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/persistence.py", line 1028, in _emit_update_statements Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi % (table.description, len(records), rows) Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi sqlalchemy.orm.exc.StaleDataError: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched. Sep 10 14:27:15.930499 ubuntu-bionic-ovh-gra1-0019749715 glance-api[48306]: ERROR glance.common.wsgi To manage notifications about this bug go to: https://bugs.launchpad.net/glance/+bug/1895173/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
