yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1895173] Re: Caught error: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1895173@xxxxxxxxxxxxxxxxxx>
Date: Thu, 22 Jul 2021 03:42:43 -0000
Reply-to: Bug 1895173 <1895173@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
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 <dansmith@xxxxxxxxxx>
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
References

[Bug 1895173] [NEW] Caught error: UPDATE statement on table 'image_properties' expected to update 1 row(s); 0 were matched
From: Lee Yarwood, 2020-09-10