O054Attach Volume 操作（Part II）

Posted 2022-03-13 www1707

参考https://www.cnblogs.com/CloudMan6/p/5631328.html

 

 

计算节点作为iSCSI initiator 访问存储节点 iSCSI Target 上的volume，并将其attach 到 Instance 。

 

nova-compute 一次执行 iscsiadmin 的 new、update、login、rescan 操作访问target 上的volume

 

计算节点将iSCSI target 上的volume识别为一个磁盘文件

 

然后通过更新Instance的XML配置文件将volume 映射给Instance

 

 

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG nova.api.openstack.wsgi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Action: ‘create‘, calling method: <bound method VolumeAttachmentController.create of <nova.api.openstack.compute.volumes.VolumeAttachmentController object at 0x7f9789b1cf90>>, body: "volumeAttachment": "volumeId": "fe3d0886-6dfb-4cc6-898a-72e902fba912" (pid=3631) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:615

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG nova.compute.api [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Fetching instance by UUID (pid=3631) get /opt/stack/nova/nova/compute/api.py:2421

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "fe4d50b2-4e42-45ad-af8c-acb570540b3c" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s (pid=3631) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "fe4d50b2-4e42-45ad-af8c-acb570540b3c" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s (pid=3631) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-36721fe0-2996-4610-9870-a00d7470d4d6 admin admin] GET http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-36721fe0-2996-4610-9870-a00d7470d4d6 admin admin] Empty body provided in request (pid=21071) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-36721fe0-2996-4610-9870-a00d7470d4d6 admin admin] Calling method ‘show‘ (pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.volume.api [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-36721fe0-2996-4610-9870-a00d7470d4d6 admin admin] Volume info retrieved successfully.

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-36721fe0-2996-4610-9870-a00d7470d4d6 admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912 returned with HTTP 200

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-7092d57a-092b-41db-a2ae-f5da4696bf10 admin admin] POST http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-7092d57a-092b-41db-a2ae-f5da4696bf10 admin admin] Action: ‘create‘, calling method: version_select, body: "attachment": "instance_uuid": "502d7935-e350-4164-8ef4-95cc8b34bd54", "connector": null, "volume_uuid": "fe3d0886-6dfb-4cc6-898a-72e902fba912" (pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:869

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-7092d57a-092b-41db-a2ae-f5da4696bf10 admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments returned with HTTP 200

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO nova.api.openstack.requestlog [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] 10.12.30.21 "POST /compute/v2.1/servers/502d7935-e350-4164-8ef4-95cc8b34bd54/os-volume_attachments" status: 200 len: 194 microversion: 2.1 time: 0.485424

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-3f7c443e-3727-4c88-abd7-996aa93c00c6 admin admin] GET http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-3f7c443e-3727-4c88-abd7-996aa93c00c6 admin admin] Empty body provided in request (pid=21070) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-3f7c443e-3727-4c88-abd7-996aa93c00c6 admin admin] Calling method ‘show‘ (pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.volume.api [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-3f7c443e-3727-4c88-abd7-996aa93c00c6 admin admin] Volume info retrieved successfully.

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-3f7c443e-3727-4c88-abd7-996aa93c00c6 admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes/fe3d0886-6dfb-4cc6-898a-72e902fba912 returned with HTTP 200

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin admin] PUT http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2

Jul  1 20:50:15 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin admin] Action: ‘update‘, calling method: version_select, body: "attachment": "connector": "initiator": "iqn.1994-05.com.redhat:d77c331f2be5", "ip": "10.12.30.22", "platform": "x86_64", "host": "DevStack-Rocky-Compute-22", "do_local_attach": false, "mountpoint": "/dev/vdb", "os_type": "linux2", "multipath": false (pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:869

Jul  1 20:50:19 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2 returned with HTTP 200

Jul  1 20:50:20 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-2822f736-68ea-49f8-bfde-363aff42b6ec admin admin] POST http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2/action

Jul  1 20:50:20 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-2822f736-68ea-49f8-bfde-363aff42b6ec admin admin] Action body: "os-complete": null (pid=21071) get_method /opt/stack/cinder/cinder/api/openstack/wsgi.py:986

Jul  1 20:50:20 DevStack-Rocky-Controller-21 [email protected]: DEBUG cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-2822f736-68ea-49f8-bfde-363aff42b6ec admin admin] Action: ‘action‘, calling method: version_select, body: "os-complete": null (pid=21071) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:869

Jul  1 20:50:20 DevStack-Rocky-Controller-21 [email protected]: INFO cinder.api.openstack.wsgi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-2822f736-68ea-49f8-bfde-363aff42b6ec admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/attachments/f742381a-9b3d-41a3-9513-5dd80e2ce6c2/action returned with HTTP 204

 

 

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" acquired by "nova.compute.manager.do_reserve" :: waited 0.000s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.objects.instance [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" released by "nova.compute.manager.do_reserve" :: held 0.106s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" acquired by "nova.compute.manager.do_attach_volume" :: waited 0.000s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: INFO nova.compute.manager [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Attaching volume fe3d0886-6dfb-4cc6-898a-72e902fba912 to /dev/vdb

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.objects.instance [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.utils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] ==> get_connector_properties: call u"‘execute‘: None, ‘my_ip‘: ‘10.12.30.22‘, ‘enforce_multipath‘: True, ‘host‘: ‘DevStack-Rocky-Compute-22‘, ‘root_helper‘: ‘sudo nova-rootwrap /etc/nova/rootwrap.conf‘, ‘multipath‘: False" (pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:146

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxfc [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] No Fibre Channel support detected on system. (pid=25886) get_fc_hbas /usr/lib/python2.7/site-packages/os_brick/initiator/linuxfc.py:134

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxfc [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] No Fibre Channel support detected on system. (pid=25886) get_fc_hbas /usr/lib/python2.7/site-packages/os_brick/initiator/linuxfc.py:134

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.utils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] <== get_connector_properties: return (8ms) ‘initiator‘: u‘iqn.1994-05.com.redhat:d77c331f2be5‘, ‘ip‘: u‘10.12.30.22‘, ‘platform‘: u‘x86_64‘, ‘host‘: u‘DevStack-Rocky-Compute-22‘, ‘do_local_attach‘: False, ‘os_type‘: u‘linux2‘, ‘multipath‘: False (pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:170

Jul  1 20:50:15 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.block_device [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] [instance: 502d7935-e350-4164-8ef4-95cc8b34bd54] Updating existing volume attachment record: f742381a-9b3d-41a3-9513-5dd80e2ce6c2 (pid=25886) _volume_attach /opt/stack/nova/nova/virt/block_device.py:535

Jul  1 20:50:15 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvchange -a y --yes -K stack-volumes-lvmdriver-1/volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372

Jul  1 20:50:15 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvchange -a y --yes -K stack-volumes-lvmdriver-1/volume-fe3d0886-6dfb-4cc6-898a-72e902fba912" returned: 0 in 0.287s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:15 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.targets.lio [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Creating iscsi_target for volume: volume-fe3d0886-6dfb-4cc6-898a-72e902fba912

Jul  1 20:50:15 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:15 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool create /dev/stack-volumes-lvmdriver-1/volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 6r6g96v5d9z6kCzCRaMr uKSpojdTH2ajUz9d False -p3260 -a10.12.30.22 (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372

Jul  1 20:50:16 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool create /dev/stack-volumes-lvmdriver-1/volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 6r6g96v5d9z6kCzCRaMr uKSpojdTH2ajUz9d False -p3260 -a10.12.30.22" returned: 0 in 0.864s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:16 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.866s (pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:16 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:16 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool get-targets" returned: 0 in 0.472s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.474s (pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save" returned: 0 in 0.500s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.503s (pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.targets.iscsi [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Set provider_location to: 10.12.30.22:3260,iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 0 (pid=27933) create_export /opt/stack/cinder/cinder/volume/targets/iscsi.py:215

Jul  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:17 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool add-initiator iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 6r6g96v5d9z6kCzCRaMr uKSpojdTH2ajUz9d iqn.1994-05.com.redhat:d77c331f2be5 (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372

Jul  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool add-initiator iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912 6r6g96v5d9z6kCzCRaMr uKSpojdTH2ajUz9d iqn.1994-05.com.redhat:d77c331f2be5" returned: 0 in 0.464s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.466s (pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c 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  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf cinder-rtstool save" returned: 0 in 0.487s (pid=27933) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409

Jul  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.lockutils [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] Lock "lioadm" released by "cinder.volume.targets.lio._execute" :: held 0.489s (pid=27933) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:18 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.manager [req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a req-b78805cd-823e-4ce5-b708-f37efd6ac60c admin None] attachment_update completed successfully.

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.volume.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Calling os-brick to attach iSCSI Volume (pid=25886) connect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:63

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] ==> connect_volume: call u"‘args‘: (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7f8084f8c810>, u‘access_mode‘: u‘rw‘, 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‘target_lun‘: 0, u‘auth_password‘: u‘***‘, u‘auth_username‘: u‘6r6g96v5d9z6kCzCRaMr‘, u‘auth_method‘: u‘CHAP‘), ‘kwargs‘: " (pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:146

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "connect_volume" acquired by "os_brick.initiator.connectors.iscsi.connect_volume" :: waited 0.000s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: INFO os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Trying to connect to iSCSI portal 10.12.30.22:3260

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (): stdout= stderr=iscsiadm: No records found

Jul  1 20:50:18 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--interface‘, ‘default‘, ‘--op‘, ‘new‘): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.30.22,3260,-1 iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912] added

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--op‘, ‘update‘, ‘-n‘, ‘node.session.scan‘, ‘-v‘, ‘manual‘): stdout= stderr= (pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--op‘, ‘update‘, ‘-n‘, ‘node.session.auth.authmethod‘, ‘-v‘, u‘CHAP‘): stdout= stderr= (pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--op‘, ‘update‘, ‘-n‘, ‘node.session.auth.username‘, ‘-v‘, u‘6r6g96v5d9z6kCzCRaMr‘): stdout= stderr= (pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--op‘, ‘update‘, ‘-n‘, ‘node.session.auth.password‘, ‘-v‘, u‘***‘): stdout= stderr= (pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--login‘,): stdout=Logging in to [iface: default, target: iqn.2010-10.org.openstack:volume-fe3d0886-6dfb-4cc6-898a-72e902fba912, portal: 10.12.30.22,3260] (multiple)

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] iscsiadm (‘--op‘, ‘update‘, ‘-n‘, ‘node.startup‘, ‘-v‘, ‘automatic‘): stdout= stderr= (pid=25886) _run_iscsiadm /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:973

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a 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  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Connected to 10.12.30.22:3260 (pid=25886) _connect_vol /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:624

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] HCTL (u‘4‘, ‘-‘, ‘-‘, 0) found on session 2 with lun 0 (pid=25886) get_hctl /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:622

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Scanning host 4 c: -, t: -, l: 0) (pid=25886) scan_iscsi /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:650

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.linuxscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Searching for a device in session 2 and hctl [u‘4‘, ‘*‘, ‘*‘, 0] yield: sdc (pid=25886) device_name_by_hctl /usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py:642

Jul  1 20:50:19 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Connected to sdc using u‘auth_password‘: u‘***‘, 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‘target_lun‘: 0, u‘access_mode‘: u‘rw‘, u‘auth_username‘: u‘6r6g96v5d9z6kCzCRaMr‘, u‘auth_method‘: u‘CHAP‘ (pid=25886) _connect_vol /usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py:651

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "connect_volume" released by "os_brick.initiator.connectors.iscsi.connect_volume" :: held 1.148s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG os_brick.initiator.connectors.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] <== connect_volume: return (1148ms) ‘path‘: u‘/dev/sdc‘, ‘scsi_wwn‘: u‘3600140501eebd8031364e63a796e9a92‘, ‘type‘: u‘block‘ (pid=25886) trace_logging_wrapper /usr/lib/python2.7/site-packages/os_brick/utils.py:170

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.volume.iscsi [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Attached iSCSI volume ‘path‘: u‘/dev/sdc‘, ‘scsi_wwn‘: ‘3600140501eebd8031364e63a796e9a92‘, ‘type‘: ‘block‘ (pid=25886) connect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:65

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.guest [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] attach device xml: <disk type="block" device="disk">

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.driver [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] No BDM found with device name vda, not building metadata. (pid=25886) _build_disk_metadata /opt/stack/nova/nova/virt/libvirt/driver.py:8721

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.driver [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] No BDM found with device name vdb, not building metadata. (pid=25886) _build_disk_metadata /opt/stack/nova/nova/virt/libvirt/driver.py:8721

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG nova.virt.libvirt.driver [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] No VIF found with MAC fa:16:3e:fb:35:7a, not building metadata (pid=25886) _build_interface_metadata /opt/stack/nova/nova/virt/libvirt/driver.py:8697

Jul  1 20:50:20 DevStack-Rocky-Compute-22 nova-compute: DEBUG oslo_concurrency.lockutils [None req-d82c0c2b-7534-4ff2-b905-a25b7c2a194a admin admin] Lock "502d7935-e350-4164-8ef4-95cc8b34bd54" released by "nova.compute.manager.do_attach_volume" :: held 5.109s (pid=25886) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285