Uploaded image for project: 'Red Hat OpenStack Services on OpenShift'
  1. Red Hat OpenStack Services on OpenShift
  2. OSPRH-3142

Invalid bdm record is left when cinder api call to delete a volume attachment times out

XMLWordPrintable

    • False
    • Hide

      None

      Show
      None
    • 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
                                                            ~~~

      [...]

              rhn-support-tkajinam Takashi Kajinami (Inactive)
              jira-bugzilla-migration RH Bugzilla Integration
              rhos-workloads-compute
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: