O055、Detach Volume 操作
本节我们开始学习 Volume Detach 操作，就是将Volume从Instance上卸载下来。
1、向cinder-api 发送detach请求
2、cinder-api发送消息
3、nova-compute detach volume
4、cinder-volume删除target
volume detach 方法如下：
Detach 的操作是由 nova-compute 和 cinder-volume 共同完成
1、首先nova-compute将volume从Instance上detach，然后断开与iSCSI target 的连接
1.1、将缓存中的数据 flush 到 volume
1.2、删除计算节点上 volume 对应的 iSCSI设备
1.3、通过iscsiadmin的logout，delete操作断开与iSCSI target的连接
2、最后cinder-volume删除volume相关的iSCSI target
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@n-api.service: DEBUG nova.api.openstack.wsgi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Calling method '<bound method VolumeAttachmentController.delete of <nova.api.openstack.compute.volumes.VolumeAttachmentController object at 0x7f97892fffd0>>' {{(pid=3630) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:618}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@n-api.service: DEBUG nova.compute.api [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Fetching instance by UUID {{(pid=3630) get /opt/stack/nova/nova/compute/api.py:2421}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@n-api.service: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "fe4d50b2-4e42-45ad-af8c-acb570540b3c" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=3630) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@n-api.service: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "fe4d50b2-4e42-45ad-af8c-acb570540b3c" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=3630) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] GET http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] Empty body provided in request {{(pid=21071) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] Calling method 'show' {{(pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] Volume info retrieved successfully.
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912 returned with HTTP 200
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] POST http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912/action
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] Action body: {"os-begin_detaching": null} {{(pid=21070) get_method /opt/stack/cinder/cinder/api/openstack/wsgi.py:986}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] Action: 'action', calling method: _begin_detaching, body: {"os-begin_detaching": null} {{(pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:869}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] Volume info retrieved successfully.
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] Begin detaching volume completed successfully.
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-dd78be21-4cc2-419f-995e-e0a5a72a4ab2 admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912/action returned with HTTP 202
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@n-api.service: INFO nova.api.openstack.requestlog [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] 10.12.30.21 "DELETE /compute/v2.1/servers/502d7935-e350-4164-8ef4-95cc8b34bd54/os-volume_attachments/fe3d0886-6dfb-4cc6-898a-72e902fba912" status: 202 len: 0 microversion: 2.1 time: 0.262331
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] GET http://10.12.30.21/volume//
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] Empty body provided in request {{(pid=21071) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] Calling method 'all' {{(pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-eaffe1ea-243f-48a7-9deb-70f77ad78168 admin admin] http://10.12.30.21/volume// returned with HTTP 300
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-24a202d3-5abf-4aa1-b387-a1f686c3640b admin admin] GET http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-24a202d3-5abf-4aa1-b387-a1f686c3640b admin admin] Empty body provided in request {{(pid=21070) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-24a202d3-5abf-4aa1-b387-a1f686c3640b admin admin] Calling method 'show' {{(pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872}}
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-24a202d3-5abf-4aa1-b387-a1f686c3640b admin admin] Volume info retrieved successfully.
Jul 2 16:27:45 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-24a202d3-5abf-4aa1-b387-a1f686c3640b admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912 returned with HTTP 200
Jul 2 16:27:46 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] DELETE http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2
Jul 2 16:27:46 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] Empty body provided in request {{(pid=21071) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718}}
Jul 2 16:27:46 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] Calling method 'version_select' {{(pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872}}
Jul 2 16:27:49 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] Remaining volume attachments: VolumeAttachmentList(objects=[]) {{(pid=21071) attachment_delete /opt/stack/cinder/cinder/volume/api.py:2217}}
Jul 2 16:27:49 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] Pending status list for volume during attachment-delete: [] {{(pid=21071) attachment_delete /opt/stack/cinder/cinder/volume/api.py:2230}}
Jul 2 16:27:49 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2 returned with HTTP 200
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" acquired by "nova.compute.manager.do_detach_volume" :: waited 0.000s {{(pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.objects.instance [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lazy-loading 'flavor' on Instance uuid 502d7935-e350-4164-8ef4-95cc8b34bd54 {{(pid=25886) obj_load_attr /opt/stack/nova/nova/objects/instance.py:1111}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: INFO nova.compute.manager [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Detaching volume fe3d0886-6dfb-4cc6-898a-72e902fba912
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: INFO nova.virt.block_device [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Attempting to driver detach volume fe3d0886-6dfb-4cc6-898a-72e902fba912 from mountpoint /dev/vdb
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.guest [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Attempting initial detach for device vdb {{(pid=25886) detach_device_with_retry /opt/stack/nova/nova/virt/libvirt/guest.py:432}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.guest [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] detach device xml: <disk type="block" device="disk">
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.guest [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Successfully detached device vdb from guest. Persistent? 1. Live? True {{(pid=25886) _try_detach_device /opt/stack/nova/nova/virt/libvirt/guest.py:404}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.guest [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Start retrying detach until device vdb is gone. {{(pid=25886) detach_device_with_retry /opt/stack/nova/nova/virt/libvirt/guest.py:448}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo.service.loopingcall [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Waiting for function nova.virt.libvirt.guest._do_wait_and_retry_detach to return. {{(pid=25886) func /usr/lib/python2.7/site-packages/oslo_service/loopingcall.py:472}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.volume.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] calling os-brick to detach iSCSI Volume {{(pid=25886) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:72}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] ==> disconnect_volume: call u"{'args': (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7f8084f8c810>, {u'device_path': u'/dev/sdc', u'target_discovered': False, u'encrypted': False, u'qos_specs': None, u'target_iqn': u'iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912', u'target_portal': u'10.12.30.22:3260', u'volume_id': u'fe3d0886-6dfb-4cc6-898a-72e902fba912', u'auth_password': u'***', u'target_lun': 0, u'access_mode': u'rw', u'auth_username': u'6r6g96v5d9z6kCzCRaMr', u'auth_method': u'CHAP'}, None), 'kwargs': {}}" {{(pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:146}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "connect_volume" acquired by "os_brick.initiator.connectors.iscsi.disconnect_volume" :: waited 0.000s {{(pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Getting connected devices for (ips,iqns,luns)=[(u'10.12.30.22:3260', u'iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912', 0)] {{(pid=25886) _get_connection_devices /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:790}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] iscsiadm ('-m', 'session'): stdout=tcp: [1] 10.12.30.21:3260,1 iqn.2010-10.org.openstack:volume-06984f3c-44e1-42a5-b03c-08a0cfa19f73 (non-flash)
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] iscsi session list stdout=tcp: [1] 10.12.30.21:3260,1 iqn.2010-10.org.openstack:volume-06984f3c-44e1-42a5-b03c-08a0cfa19f73 (non-flash)
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Resulting device map defaultdict(<function <lambda> at 0x7f808535a140>, {(u'10.12.30.22:3260', u'iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912'): (set([u'sdc']), set([]))}) {{(pid=25886) _get_connection_devices /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:822}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Removing single pathed devices sdc {{(pid=25886) remove_connection /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:264}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Flushing IO for device /dev/sdc {{(pid=25886) flush_device_io /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:313}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Remove SCSI device /dev/sdc with /sys/block/sdc/device/delete {{(pid=25886) remove_scsi_device /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:76}}
Jul 2 16:27:45 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Checking to see if SCSI volumes sdc have been removed. {{(pid=25886) wait_for_volumes_removal /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:84}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] /dev/sdc still exist. {{(pid=25886) wait_for_volumes_removal /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:100}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] SCSI volumes sdc have been removed. {{(pid=25886) wait_for_volumes_removal /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:93}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Disconnecting from: [(u'10.12.30.22:3260', u'iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912')] {{(pid=25886) _disconnect_connection /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:1072}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= {{(pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] iscsiadm ('--logout',): stdout=Logging out of session [sid: 2, target: iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912, portal: 10.12.30.22,3260]
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] iscsiadm ('--op', 'delete'): stdout= stderr= {{(pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "connect_volume" released by "os_brick.initiator.connectors.iscsi.disconnect_volume" :: held 0.585s {{(pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] <== disconnect_volume: return (585ms) None {{(pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:170}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.volume.iscsi [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Disconnected iSCSI Volume {{(pid=25886) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:78}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" acquired by "cinder.volume.targets.lio._execute" :: waited 0.001s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:46 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool delete-initiator iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 iqn.1994-05.com.redhat:d77c331f2be5 {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool delete-initiator iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 iqn.1994-05.com.redhat:d77c331f2be5" returned: 0 in 0.479s {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.481s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" acquired by "cinder.volume.targets.lio._execute" :: waited 0.000s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save" returned: 0 in 0.516s {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.518s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.manager [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Terminate volume connection completed successfully.
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Deleting attachment f742381a-9b3d-41a3-9513-5dd80e2ce6c2. {{(pid=27933) _do_attachment_delete /opt/stack/cinder/cinder/volume/manager.py:4524}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" acquired by "cinder.volume.targets.lio._execute" :: waited 0.000s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:47 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool get-targets {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool get-targets" returned: 0 in 0.452s {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.454s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.targets.lio [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Removing iscsi_target: fe3d0886-6dfb-4cc6-898a-72e902fba912
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" acquired by "cinder.volume.targets.lio._execute" :: waited 0.000s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool delete iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool delete iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912" returned: 0 in 0.509s {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.511s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" acquired by "cinder.volume.targets.lio._execute" :: waited 0.000s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273}}
Jul 2 16:27:48 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}
Jul 2 16:27:49 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save" returned: 0 in 0.483s {{(pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}
Jul 2 16:27:49 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.485s {{(pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
Jul 2 16:27:49 DevStack-Rocky-Compute-22 cinder-volume: WARNING py.warnings [req-e19a911c-2d68-402b-8124-dddd27f5ff0e req-e4867178-09e4-4259-96c3-70c5506e4cdd admin None] /usr/lib64/python2.7/site-packages/sqlalchemy/orm/evaluator.py:71: 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.
Jul 2 16:27:49 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-e19a911c-2d68-402b-8124-dddd27f5ff0e admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" released by "nova.compute.manager.do_detach_volume" :: held 3.652s {{(pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285}}
