-
Bug
-
Resolution: Done
-
Normal
-
rhos-18.0.0
-
False
-
-
False
-
openstack-nova-27.1.1-0.20230518074959.b9089ac.el9ost
-
None
-
-
-
Moderate
+++ This bug was initially created as a clone of Bug #2002643 +++
Description of problem:
Currently nova executes the following steps while detaching a volume from a vm
1. Detach the block device from the vm and the compute node where the vm is running
2. Call cinder to terminate the volume connection
3. Remove block device mappings from nova
However, when the API call to terminate the volume connection fails for some reason,
an invalid bdm record can be left in nova db.
In one customer case, the API call to terminate volume attachments is slow because of
the behavior of backend volume, and API calls frequently fail with 504 error caused
by timeout in httpd hosting cinder-api.
In such case cinder completes terminating the volume attachment and the volume becomes
available status with no attachement left, while 504 is returned to nova and the bdm record
is never deleted from nova's db.
Version-Release number of selected component (if applicable):
How reproducible:
Frequently
Steps to Reproduce:
1. Create an instance and attach a volume to the instance
2. Detach a volume from instance
Actual results:
BDM record is left in nova. The volume is detached from vm and its host, and the volume is available status in cinder.
Expected results:
BDM record is also deleted from nova.
Additional info:
— Additional comment from Takashi Kajinami on 2021-09-09 12:28:33 UTC —
I can simulate the similar situation in my lab. Note that in my case cinder was not functional at all so volume attachment was not deleted from cinder.
1. Create an instance(test2) and attached a volume(testvolume) to the instance.
~~~
(overcloud) [stack@undercloud-0 ~]$ openstack server show test2
--------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
--------------------------------------------------------------------------------------------------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | compute-1.redhat.local |
| OS-EXT-SRV-ATTR:hostname | test2 |
| OS-EXT-SRV-ATTR:hypervisor_hostname | compute-1.redhat.local |
| OS-EXT-SRV-ATTR:instance_name | instance-0000000a |
| OS-EXT-SRV-ATTR:kernel_id | |
| OS-EXT-SRV-ATTR:launch_index | 0 |
| OS-EXT-SRV-ATTR:ramdisk_id | |
| OS-EXT-SRV-ATTR:reservation_id | r-c5zj577r |
| OS-EXT-SRV-ATTR:root_device_name | /dev/vda |
| OS-EXT-SRV-ATTR:user_data | None |
| OS-EXT-STS:power_state | Running |
| OS-EXT-STS:task_state | None |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2021-08-18T01:27:11.000000 |
| OS-SRV-USG:terminated_at | None |
| accessIPv4 | |
| accessIPv6 | |
| addresses | private=192.168.10.207 |
| config_drive | |
| created | 2021-08-18T01:27:01Z |
| description | None |
| flavor | disk='1', ephemeral='0', extra_specs.hw_rng:allowed='True', original_name='m1.nano', ram='128', swap='0', vcpus='1' |
| hostId | 9bec297ebfece4b6798695f950595eea458e93548257dec7f346266b |
| host_status | UP |
| id | 3a9b54b5-35b7-4427-bc64-f88b0d8949b3 |
| image | cirros-0.4.0-x86_64-disk.img (89a76ef6-2c14-4ff0-934f-fbd369fb0b1e) |
| key_name | None |
| locked | False |
| locked_reason | None |
| name | test2 |
| progress | 0 |
| project_id | e722c8ab654a440e8d3cdc5ef592f21b |
| properties | |
| security_groups | name='ssh-and-icmp' |
| server_groups | [] |
| status | ACTIVE |
| tags | [] |
| trusted_image_certificates | None |
| updated | 2021-08-18T01:27:11Z |
| user_id | 99f5628a6a55449fae14d97881a054ce |
| volumes_attached | delete_on_termination='False', id='35ff73cd-ebe2-40b3-8be6-f91aca202aa8' |
--------------------------------------------------------------------------------------------------------------------------------------------------------+
(overcloud) [stack@undercloud-0 ~]$ openstack volume show testvolume
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| attachments | [{'id': '35ff73cd-ebe2-40b3-8be6-f91aca202aa8', 'attachment_id': '34a2c438-aaaa-4000-8fb6-6b4c41d0b978', 'volume_id': '35ff73cd-ebe2-40b3-8be6-f91aca202aa8', 'server_id': '3a9b54b5-35b7-4427-bc64-f88b0d8949b3', 'host_name': 'compute-1.redhat.local', 'device': '/dev/vdb', 'attached_at': '2021-09-09T12:08:32.000000'}] |
| availability_zone | nova |
| bootable | false |
| consistencygroup_id | None |
| created_at | 2021-09-09T12:07:51.000000 |
| description | None |
| encrypted | False |
| id | 35ff73cd-ebe2-40b3-8be6-f91aca202aa8 |
| migration_status | None |
| multiattach | False |
| name | testvolume |
| os-vol-host-attr:host | hostgroup@tripleo_iscsi#tripleo_iscsi |
| os-vol-mig-status-attr:migstat | None |
| os-vol-mig-status-attr:name_id | None |
| os-vol-tenant-attr:tenant_id | e722c8ab654a440e8d3cdc5ef592f21b |
| properties | |
| replication_status | None |
| size | 1 |
| snapshot_id | None |
| source_volid | None |
| status | in-use |
| type | tripleo |
| updated_at | 2021-09-09T12:08:35.000000 |
| user_id | 99f5628a6a55449fae14d97881a054ce |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
~~~
2. Disable cinder-volume service. From this point any volume operation which requires interaction with backend storage, no longer succeeds.
~~~
[heat-admin@controller-0 ~]$ sudo pcs resource disable openstack-cinder-volume
[heat-admin@controller-0 ~]$ sudo pcs status
...
Full List of Resources:
...
- Container bundle: openstack-cinder-volume [cluster.common.tag/rhosp16-openstack-cinder-volume:pcmklatest]:
- openstack-cinder-volume-podman-0 (ocf::heartbeat:podman): Stopped (disabled)
~~~
3. Detach the volume from the instance
(overcloud) [stack@undercloud-0 ~]$ openstack server remove volume test2 testvolume
(overcloud) [stack@undercloud-0 ~]$
4. nova-compute fails to detach the volume because API call to delete the volume attachment fails
~~~
2021-09-09 12:11:14.000 7 INFO nova.compute.manager [req-d4ea1834-53a1-4786-8c9a-f495307ec9d3 99f5628a6a55449fae14d97881a054ce e722c8ab654a440e8d3cdc5ef592f21b - default default] [instance: 3a9b54b5-35b7-4427-bc64-f88b0d8949b3] Detaching volume 35ff73cd-ebe2-40b3-8be6-f91aca202aa8
...
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server [req-d4ea1834-53a1-4786-8c9a-f495307ec9d3 99f5628a6a55449fae14d97881a054ce e722c8ab654a440e8d3cdc5ef592f21b - default default] Exception during message handling: cinderclient.excep
tions.ClientException: Gateway Timeout (HTTP 504)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_messaging/rpc/dispatcher.py", line 274, in dispatch
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
...
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 6237, in _detach_volume
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server attachment_id=attachment_id, destroy_bdm=destroy_bdm)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/virt/block_device.py", line 486, in detach
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server attachment_id, destroy_bdm)
...
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 223, in delete
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server return self._cs_request(url, 'DELETE', **kwargs)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 205, in _cs_request
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server return self.request(url, method, **kwargs)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 191, in request
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server raise exceptions.from_response(resp, body)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server cinderclient.exceptions.ClientException: Gateway Timeout (HTTP 504)
2021-09-09 12:12:14.512 7 ERROR oslo_messaging.rpc.server
~~~
5. At this point the volume is detached from the instance actually
~~~
[heat-admin@compute-1 ~]$ sudo podman exec nova_libvirt virsh domblklist 3a9b54b5-35b7-4427-bc64-f88b0d8949b3
Target Source
-----------------------------------------------------------------------------
vda /var/lib/nova/instances/3a9b54b5-35b7-4427-bc64-f88b0d8949b3/disk
~~~
6. However the bdm record is still left and the volume is still shown in volumes_attached.
~~~
(overcloud) [stack@undercloud-0 ~]$ openstack server show test2
--------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
--------------------------------------------------------------------------------------------------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | compute-1.redhat.local |
| OS-EXT-SRV-ATTR:hostname | test2 |
| OS-EXT-SRV-ATTR:hypervisor_hostname | compute-1.redhat.local |
| OS-EXT-SRV-ATTR:instance_name | instance-0000000a |
| OS-EXT-SRV-ATTR:kernel_id | |
| OS-EXT-SRV-ATTR:launch_index | 0 |
| OS-EXT-SRV-ATTR:ramdisk_id | |
| OS-EXT-SRV-ATTR:reservation_id | r-c5zj577r |
| OS-EXT-SRV-ATTR:root_device_name | /dev/vda |
| OS-EXT-SRV-ATTR:user_data | None |
| OS-EXT-STS:power_state | Running |
| OS-EXT-STS:task_state | None |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2021-08-18T01:27:11.000000 |
| OS-SRV-USG:terminated_at | None |
| accessIPv4 | |
| accessIPv6 | |
| addresses | private=192.168.10.207 |
| config_drive | |
| created | 2021-08-18T01:27:01Z |
| description | None |
| flavor | disk='1', ephemeral='0', extra_specs.hw_rng:allowed='True', original_name='m1.nano', ram='128', swap='0', vcpus='1' |
| hostId | 9bec297ebfece4b6798695f950595eea458e93548257dec7f346266b |
| host_status | UP |
| id | 3a9b54b5-35b7-4427-bc64-f88b0d8949b3 |
| image | cirros-0.4.0-x86_64-disk.img (89a76ef6-2c14-4ff0-934f-fbd369fb0b1e) |
| key_name | None |
| locked | False |
| locked_reason | None |
| name | test2 |
| progress | 0 |
| project_id | e722c8ab654a440e8d3cdc5ef592f21b |
| properties | |
| security_groups | name='ssh-and-icmp' |
| server_groups | [] |
| status | ACTIVE |
| tags | [] |
| trusted_image_certificates | None |
| updated | 2021-08-18T01:27:11Z |
| user_id | 99f5628a6a55449fae14d97881a054ce |
| volumes_attached | delete_on_termination='False', id='35ff73cd-ebe2-40b3-8be6-f91aca202aa8' |
--------------------------------------------------------------------------------------------------------------------------------------------------------+
~~~
— Additional comment from Takashi Kajinami on 2021-09-09 12:35:14 UTC —
This issue was initially found in the customer case 03028853 .
In this case, the API call to delete the volume attachment failed because of slow response from backend storage.
However the delete request was accepted by cinder-volume and the volume attachment was deleted in 62 seconds.
sosreport-fkc-iso-ctl003-03028853-2021-09-09-qhavktx/var/log/containers/httpd/cinder-api/cinder_wsgi_access.log
~~~
10.232.232.52 - - [09/Sep/2021:10:06:22 +0900] "DELETE /v3/e6167d9479ba4629a006dbb6c2c0c75a/attachments/33bd4f08-9f20-45b3-9e99-fe094ba4bb54 HTTP/1.1" 504 247 "-" "python-cinderclient"
~~~
sosreport-fkc-iso-ctl003-03028853-2021-09-09-qhavktx/var/log/containers/httpd/cinder-api/cinder_wsgi_error.log
~~~
[Thu Sep 09 10:07:22.098864 2021] [wsgi:error] [pid 30093] [client 10.232.232.52:39134] Timeout when reading response headers from daemon process 'cinder-api': /var/www/cgi-bin/cinder/cinder-api
~~~
sosreport-fkc-iso-ctl003-03028853-2021-09-09-qhavktx/var/log/containers/cinder/cinder-api.log
~~~
2021-09-09 10:06:22.091 23 INFO cinder.api.openstack.wsgi [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] DELETE http://10.232.232.1:8776/v3/e6167d9479ba4629a006dbb6c2c0c75a/attachments/33bd4f08-9f20-45b3-9e99-fe094ba4bb54
...
2021-09-09 10:07:30.770 23 INFO cinder.api.openstack.wsgi [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] http://10.232.232.1:8776/v3/e6167d9479ba4629a006dbb6c2c0c75a/attachments/33bd4f08-9f20-45b3-9e99-fe094ba4bb54 returned with HTTP 200
~~~
sosreport-fkc-iso-ctl001-03028853-2021-09-09-vrifvej/var/log/containers/cinder/cinder-volume.log
~~~
2021-09-09 10:06:22.170 107 INFO cinder.volume.drivers.hitachi.hbsd.hbsd_traceutils [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] MSGID0000-I: The method terminate_connection was called. (config_group: VSPG350_01)
2021-09-09 10:07:30.686 107 INFO cinder.volume.drivers.hitachi.hbsd.hbsd_traceutils [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] MSGID0002-I: The method terminate_connection completed successfully. (config_group: VSPG350_01)
2021-09-09 10:07:30.687 107 INFO cinder.volume.manager [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] Terminate volume connection completed successfully.
2021-09-09 10:07:30.737 107 WARNING py.warnings [req-dcc6c711-35f3-408b-a3e5-29bf3a2ec15f d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] /usr/lib64/python3.6/site-packages/sqlalchemy/orm/evaluator.py:99: SAWarning: Evaluating non-mapped column expression 'updated_at' onto ORM instances; this is a deprecated use case. Please make use of the actual mapped columns in ORM-evaluated UPDATE / DELETE expressions.
"UPDATE / DELETE expressions." % clause
~~~
On the other hand nova aborted the volume detachment operation after it received
504 from cinder (actually this 504 was not returned by cinder-api but httpd
hosting cinder-api)
~~~
2021-09-09 10:06:21.485 7 INFO nova.compute.manager [req-ec8c4f81-4e6c-419e-9d13-b0b311d68e4e d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] [instance: 30456a93-cdbd-4529-a63b-bed1ef45bf9a] Detaching
volume e1026da6-56a7-464b-9155-03dd570ce552
2021-09-09 10:06:21.569 7 INFO nova.virt.block_device [req-ec8c4f81-4e6c-419e-9d13-b0b311d68e4e d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] [instance: 30456a93-cdbd-4529-a63b-bed1ef45bf9a] Attempti
ng to driver detach volume e1026da6-56a7-464b-9155-03dd570ce552 from mountpoint /dev/vdb
2021-09-09 10:07:22.100 7 ERROR nova.volume.cinder [req-ec8c4f81-4e6c-419e-9d13-b0b311d68e4e d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] Delete attachment failed for attachment 33bd4f08-9f20-45b3-9e99-fe094ba4bb54. Error: Gateway Timeout (HTTP 504) Code: 504: cinderclient.exceptions.ClientException: Gateway Timeout (HTTP 504)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server [req-ec8c4f81-4e6c-419e-9d13-b0b311d68e4e d495a9a3126142cca740c3bc905f6c17 e6167d9479ba4629a006dbb6c2c0c75a - default default] Exception during message handling: cinderclient.exceptions.ClientException: Gateway Timeout (HTTP 504)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_messaging/rpc/dispatcher.py", line 274, in dispatch
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/exception_wrapper.py", line 79, in wrapped
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server function_name, call_dict, binary, tb)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in _exit_
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server self.force_reraise()
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server raise value
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/exception_wrapper.py", line 69, in wrapped
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/utils.py", line 1372, in decorated_function
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 219, in decorated_function
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server kwargs['instance'], e, sys.exc_info())
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in _exit_
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server self.force_reraise()
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server raise value
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 207, in decorated_function
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 6288, in detach_volume
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server do_detach_volume(context, volume_id, instance, attachment_id)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_concurrency/lockutils.py", line 328, in inner
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 6286, in do_detach_volume
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server attachment_id=attachment_id)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 6237, in _detach_volume
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server attachment_id=attachment_id, destroy_bdm=destroy_bdm)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/virt/block_device.py", line 486, in detach
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server attachment_id, destroy_bdm)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/virt/block_device.py", line 467, in _do_detach
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server volume_api.attachment_delete(context, self['attachment_id'])
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/volume/cinder.py", line 399, in wrapper
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server res = method(self, ctx, *args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/volume/cinder.py", line 450, in wrapper
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server res = method(self, ctx, attachment_id, *args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/retrying.py", line 68, in wrapped_f
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return Retrying(*dargs, **dkw).call(f, *args, **kw)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/retrying.py", line 223, in call
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return attempt.get(self._wrap_exception)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/retrying.py", line 261, in get
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server six.reraise(self.value[0], self.value[1], self.value[2])
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server raise value
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/retrying.py", line 217, in call
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/volume/cinder.py", line 900, in attachment_delete
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server 'code': getattr(ex, 'code', None)})
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in _exit_
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server self.force_reraise()
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server raise value
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/nova/volume/cinder.py", line 893, in attachment_delete
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server attachment_id)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/api_versions.py", line 423, in substitution
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return method.func(obj, *args, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/v3/attachments.py", line 44, in delete
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return self._delete("/attachments/%s" % base.getid(attachment))
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/base.py", line 309, in _delete
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server resp, body = self.api.client.delete(url)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 223, in delete
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return self._cs_request(url, 'DELETE', **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 205, in _cs_request
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server return self.request(url, method, **kwargs)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/site-packages/cinderclient/client.py", line 191, in request
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server raise exceptions.from_response(resp, body)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server cinderclient.exceptions.ClientException: Gateway Timeout (HTTP 504)
2021-09-09 10:07:22.137 7 ERROR oslo_messaging.rpc.server
~~~
After all, the instance still considers the volume is attached while the volume no longer has attachments.
~~~
(overcloud) [stack@fkc-iso-drt001 ~]$ openstack server show 30456a93-cdbd-4529-a663b-bed1ef45bf9a
-----------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
-----------------------------------------------------------------------------------------------------------------------------+
| OS-DCF:diskConfig | AUTO |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | fkc-iso-cpt003.qtpro.jp |
| OS-EXT-SRV-ATTR:hostname | testins |
| OS-EXT-SRV-ATTR:hypervisor_hostname | fkc-iso-cpt003.qtpro.jp |
| OS-EXT-SRV-ATTR:instance_name | instance-0000002c |
| OS-EXT-SRV-ATTR:kernel_id | |
| OS-EXT-SRV-ATTR:launch_index | 0 |
| OS-EXT-SRV-ATTR:ramdisk_id | |
| OS-EXT-SRV-ATTR:reservation_id | r-b2s36wnq |
| OS-EXT-SRV-ATTR:root_device_name | /dev/vda |
| OS-EXT-SRV-ATTR:user_data | None |
| OS-EXT-STS:power_state | Running |
| OS-EXT-STS:task_state | None |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2021-09-09T01:03:00.000000 |
| OS-SRV-USG:terminated_at | None |
| accessIPv4 | |
| accessIPv6 | |
| addresses | hsupport_private_network=192.168.99.84 |
| config_drive | |
| created | 2021-09-09T01:02:50Z |
| description | None |
| flavor | disk='0', ephemeral='0', , original_name='Middle_Linux', ram='4096', swap='0', vcpus='2' |
| hostId | b6a20a3ce5e91b279054147501fd75bc2d9cf90de90f3f8f6993d90d |
| host_status | UP |
| id | 30456a93-cdbd-4529-a63b-bed1ef45bf9a |
| image | |
| key_name | None |
| locked | False |
| locked_reason | None |
| name | testins |
| progress | 0 |
| project_id | e6167d9479ba4629a006dbb6c2c0c75a |
| properties | |
| security_groups | name='default' |
| server_groups | [] |
| status | ACTIVE |
| tags | [] |
| trusted_image_certificates | None |
| updated | 2021-09-09T01:03:00Z |
| user_id | d495a9a3126142cca740c3bc905f6c17 |
| volumes_attached | delete_on_termination='False', id='30bb1428-9020-4ae1-9e01-177ffd5ead25' |
| delete_on_termination='False', id='e1026da6-56a7-464b-9155-03dd570ce552' |
-----------------------------------------------------------------------------------------------------------------------------+
(overcloud) [stack@fkc-iso-drt001 ~]$ openstack volume show e1026da6-56a7-464b-91155-03dd570ce552
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| attachments | [] |
| availability_zone | nova |
| bootable | true |
| consistencygroup_id | None |
| created_at | 2021-08-30T07:47:34.000000 |
| description | |
| encrypted | False |
| id | e1026da6-56a7-464b-9155-03dd570ce552 |
| migration_status | None |
| multiattach | False |
| name | e1026da6-56a7-464b-9155-03dd570ce552 |
| os-vol-host-attr:host | VSPG350_01_ha_cluster@VSPG350_01#hbsd_vsp_g350_01 |
| os-vol-mig-status-attr:migstat | None |
| os-vol-mig-status-attr:name_id | None |
| os-vol-tenant-attr:tenant_id | e6167d9479ba4629a006dbb6c2c0c75a |
| properties | ldev='11', scheduled_ss_hour='12', scheduled_ss_min='30', scheduled_ss_rotation='1', scheduled_ss_type='daily', type='Normal' |
| replication_status | None |
| size | 20 |
| snapshot_id | None |
| source_volid | None |
| status | available |
| type | Primary01 |
| updated_at | 2021-09-09T01:07:30.000000 |
| user_id | 9f07304bd19c4378a7b139de749d85d7 |
| volume_image_metadata | {'signature_verified': 'False', 'image_id': 'f910b2aa-c844-4b0b-848e-c288e550cc3c', 'image_name': 'rhel8.4', 'checksum': 'db4c3a72857b784dc6e96120351f2894', 'container_format': 'bare', 'disk_format': 'qcow2', 'min_disk': '0', 'min_ram': '0', 'size': '727449600'} |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
~~~
— Additional comment from Takashi Kajinami on 2021-09-09 12:38:52 UTC —
Looking at nova.block_device_mapping table in nova, I see there still exists the bdm record(id:62) for that volume.
I think we need to update deleted_at(to current time) and deleted(to be same as id, which means 62) here to soft-delete the bdm record properly.
~~~
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
- 20. row ***************************
created_at: 2021-09-09 01:02:52
updated_at: 2021-09-09 01:02:58
deleted_at: NULL
id: 59
device_name: /dev/vda
delete_on_termination: 0
snapshot_id: NULL
volume_id: 30bb1428-9020-4ae1-9e01-177ffd5ead25
volume_size: 20
no_device: 0
connection_info:Unknown macro: {"driver_volume_type"}instance_uuid: 30456a93-cdbd-4529-a63b-bed1ef45bf9a
deleted: 0
source_type: volume
destination_type: volume
guest_format: NULL
device_type: disk
disk_bus: virtio
boot_index: 0
image_id: NULL
tag: NULL
attachment_id: 36f6e87a-96ea-418e-9eb4-d0cf4464c6d6
uuid: 941422f5-2b72-43f6-ab55-0a2809b5cd47
volume_type: NULL - 21. row ***************************
created_at: 2021-09-09 01:04:50
updated_at: 2021-09-09 01:04:56
deleted_at: NULL
id: 62
device_name: /dev/vdb
delete_on_termination: 0
snapshot_id: NULL
volume_id: e1026da6-56a7-464b-9155-03dd570ce552
volume_size: 20
no_device: NULL
connection_info:Unknown macro: {"driver_volume_type"}instance_uuid: 30456a93-cdbd-4529-a63b-bed1ef45bf9a
deleted: 0
source_type: volume
destination_type: volume
guest_format: NULL
device_type: NULL
disk_bus: NULL
boot_index: NULL
image_id: NULL
tag: NULL
attachment_id: 33bd4f08-9f20-45b3-9e99-fe094ba4bb54
uuid: 3d8abbc0-9a3b-465d-b023-7d4e01a2c440
volume_type: NULL
~~~
- 20. row ***************************
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
[...]
- external trackers