Error unprotecting snapshot volume

[Ivan Lozgachev]

Software: MOS 8.0 MU2

Configuration:
3 controller
178 compute
20 compute + ceph nodes

The error is occured while running Rally test CinderVolumes.create_and_list_snapshots
GetResourceErrorStatus: Resource <Snapshot: adb6fd80-8522-4a83-b856-5d18233aae7a> has ERROR status.

From Cinder logs:
2016-07-18 19:13:45.704 38622 DEBUG oslo_concurrency.lockutils [req-167c889b-ede0-485a-851c-86d8e038cd35 74e2dcc03afb42f0b4314dd073c379
27 d966618b42c745f1aa0373b17e086ba5 - - -] Lock "adb6fd80-8522-4a83-b856-5d18233aae7a-delete_snapshot" released by "cinder.volume.manag
er.lso_inner2" :: held 0.461s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:265
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher [req-167c889b-ede0-485a-851c-86d8e038cd35 74e2dcc03afb42f0b4314dd073c
37927 d966618b42c745f1aa0373b17e086ba5 - - -] Exception during message handling: error unprotecting snapshot volume-0e5fd059-96c1-4761-
81ba-693def92eb90@snapshot-adb6fd80-8522-4a83-b856-5d18233aae7a
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatche
r.py", line 142, in _dispatch_and_reply
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher executor_callback))
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatche
r.py", line 186, in _dispatch
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher executor_callback)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatche
r.py", line 129, in _do_dispatch
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/osprofiler/profiler.py", line 105, in wrapper
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 187, in lso_inner1
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher return lso_inner2(inst, context, snapshot, **kwargs)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 254, in inner
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 186, in lso_inner2
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher return f(*_args, **_kwargs)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 799, in delete_snapshot
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher snapshot.save()
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 789, in delete_snapshot
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher self.driver.delete_snapshot(snapshot)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/osprofiler/profiler.py", line 105, in wrapper
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/drivers/rbd.py", line 763, in delete_snapshot
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher volume.unprotect_snap(snap_name)
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/rbd.py", line 654, in unprotect_snap
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher raise make_ex(ret, 'error unprotecting snapshot %s@%s' % (self.name, name))
2016-07-18 19:13:45.705 38622 ERROR oslo_messaging.rpc.dispatcher ImageNotFound: error unprotecting snapshot volume-0e5fd059-96c1-4761-81ba-693def92eb90@snapshot-adb6fd80-8522-4a83-b856-5d18233aae7a

See attached log files from controller node. The error is found in "cinder-volume.log.2.gz" file.

[Yuriy Nesenenko (ynesenenko)]

This bug was not reproduced on MOS8 for Rally test task:
  CinderVolumes.create_and_list_snapshots:
    -
      args:
        force: False
        detailed: True
      runner:
        type: "constant"
        times: 10
        concurrency: 20
      context:
        users:
          tenants: 1
          users_per_tenant: 1
        volumes:
          size: 1
        api_versions:
          cinder:
            version: 2
            service_name: cinderv2
      sla:
        failure_rate:
          max: 0

Please add more info about test scenario CinderVolumes.create_and_list_snapshots.

[Alexey Stupnikov (astupnikov)]

Need more information for 8.0-updates. @msemenov, can you check comment #2?

[Andrew Kalach (akndex)]

Not reproduced on Fuel 9.0.0-1.mos6355