nova-ceph-multistore test_resize_server_revert fails with rbd.ReadOnlyImage: [errno 30] RBD read-only image

[Balazs Gibizer]

Traceback (most recent call last):
  File "/opt/stack/tempest/tempest/api/compute/base.py", line 222, in server_check_teardown
    waiters.wait_for_server_status(cls.servers_client,
  File "/opt/stack/tempest/tempest/common/waiters.py", line 75, in wait_for_server_status
    raise exceptions.BuildErrorException(body['fault'],
tempest.exceptions.BuildErrorException: Server a1fd599b-909a-4e77-b69d-253b0995bd3d failed to build and is in ERROR status
Details: {'code': 500, 'created': '2021-06-15T14:47:21Z', 'message': 'ReadOnlyImage'}

https://storage.bhs.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_037/796269/3/check/nova-ceph-multistore/0373da6/controller/logs/screen-n-cpu.txt

Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [None req-ac59ec60-ec07-465d-a82b-ae72be0f2454 tempest-ServerActionsTestJSON-45354220 tempest-ServerActionsTestJSON-45354220-project] [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] Setting instance vm_state to ERROR: rbd.ReadOnlyImage: [errno 30] RBD read-only image (error creating snapshot b'nova-resize' from b'a1fd599b-909a-4e77-b69d-253b0995bd3d_disk')
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] Traceback (most recent call last):
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/compute/manager.py", line 10171, in _error_out_instance_on_exception
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] yield
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/compute/manager.py", line 5862, in _finish_resize_helper
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] network_info = self._finish_resize(context, instance, migration,
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/compute/manager.py", line 5800, in _finish_resize
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] self._set_instance_info(instance, old_flavor)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] self.force_reraise()
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] raise self.value
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/compute/manager.py", line 5783, in _finish_resize
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] self.driver.finish_migration(context, migration, instance,
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 10939, in finish_migration
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] self._create_image(context, instance, block_disk_info['mapping'],
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 4534, in _create_image
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] created_disks = self._create_and_inject_local_root(
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 4632, in _create_and_inject_local_root
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] backend.create_snap(libvirt_utils.RESIZE_SNAPSHOT_NAME)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/virt/libvirt/imagebackend.py", line 1097, in create_snap
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] return self.driver.create_snap(self.rbd_name, name)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/opt/stack/nova/nova/storage/rbd_utils.py", line 463, in create_snap
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] vol.create_snap(name)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 190, in doit
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] result = proxy_call(self._autowrap, f, *args, **kwargs)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 148, in proxy_call
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] rv = execute(f, *args, **kwargs)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 129, in execute
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] six.reraise(c, e, tb)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/six.py", line 719, in reraise
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] raise value
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 83, in tworker
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] rv = meth(*args, **kwargs)
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "rbd.pyx", line 3363, in rbd.requires_not_closed.wrapper
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] File "rbd.pyx", line 4080, in rbd.Image.create_snap
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d] rbd.ReadOnlyImage: [errno 30] RBD read-only image (error creating snapshot b'nova-resize' from b'a1fd599b-909a-4e77-b69d-253b0995bd3d_disk')
Jun 15 14:47:20.281985 ubuntu-focal-ovh-bhs1-0025123352 nova-compute[114395]: ERROR nova.compute.manager [instance: a1fd599b-909a-4e77-b69d-253b0995bd3d]

See couple times:

* (the one from above) https://storage.bhs.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_037/796269/3/check/nova-ceph-multistore/0373da6/controller/logs/screen-n-cpu.txt
* https://87d895c288913f4b95e6-03232f7d524ee42df12375f1eb2a72ef.ssl.cf1.rackcdn.com/795533/5/check/nova-ceph-multistore/ab4200e/
* https://566b9c6657ec2a5e75cb-ab2a100eb8c442d7b8c2264a964910ac.ssl.cf1.rackcdn.com/780628/7/check/nova-ceph-multistore/db2a01a/

[Lee Yarwood (lyarwood)]

I don't think we've seen this reproduce for a while so moving to incomplete.

[Balazs Gibizer (balazs-gibizer)]

Something similar happened again[1] (it is now visible in cinder side and failing another tempest test case test_volume_backup_restore) Still I agree that it is low frequency.

[1] https://ddbcd145bedf294c8288-f0a55fc4957fe55450e72f1f6d277d79.ssl.cf1.rackcdn.com/796208/4/gate/nova-ceph-multistore/4fde70b/controller/logs/screen-c-vol.txt

[melanie witt (melwitt)]

Logstash query (nova-compute specific), for reference:

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Setting%20instance%20vm_state%20to%20ERROR%3A%20rbd.ReadOnlyImage%3A%20%5Berrno%2030%5D%20RBD%20read-only%20image%20(error%20creating%20snapshot%20b'nova-resize'%5C%22%20AND%20tags%3A%5C%22screen-n-cpu.txt%5C%22&from=7d

[Balazs Gibizer (balazs-gibizer)]

We still had 4 hits in the last 7 days.

[Launchpad Janitor (janitor)]

[Expired for OpenStack Compute (nova) because there has been no activity for 60 days.]

[yatin (yatinkarel)]

Seen it today in https://c83b20527acf2b0f8494-4a0455790e56cb733d68b35ced7c28e7.ssl.cf5.rackcdn.com/886250/2/check/nova-ceph-multistore/2231918/testr_results.html