Please check your iscsid.conf

On 06-Mar-2017 1:41 PM, "MarginHu" <jhu_com@163.com> wrote:

> Public bug reported:
>
> i Guys:
> I found that I failed to attach a volume to vm when cinder use lvm as
> backend.
>
> [root@kode0 ~]# openstack server list
> +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
> | ID                                   | Name  | Status | Networks
>                    | Image Name |
> +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
> | d1544927-291c-4a34-9634-dcc23880d1b7 | demo1 | ACTIVE |
> demo-net=10.0.0.8, 192.168.122.152 | cirros     |
> +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
>
> [root@kode0 ~]# openstack volume list
> +--------------------------------------+--------------+-----
> ------+------+-------------+
> | ID                                   | Display Name | Status    | Size |
> Attached to |
> +--------------------------------------+--------------+-----
> ------+------+-------------+
> | 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 | vol2         | available |    1
> |             |
> +--------------------------------------+--------------+-----
> ------+------+-------------+
> [root@kode0 ~]#
>
> [root@kode0 ~]# openstack server add volume demo1 vol2
> Unknown Error (HTTP 504)
>
> I find the following log from compute node,
>
> kolla_logs/_data/nova/nova-compute.log:52767:2017-03-06 14:24:18.022 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52768:2017-03-06 14:24:18.047 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260" returned: 0 in 0.025s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52769:2017-03-06 14:24:18.048 6
> DEBUG oslo.privsep.daemon [-] privsep: reply[111132336]: (4, ('# BEGIN
> RECORD 6.2.0.873-35\nnode.name = iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7\nnode.tpgt = -1\nnode.startup
> = automatic\nnode.leading_login = No\niface.hwaddress =
> <empty>\niface.ipaddress = <empty>\niface.iscsi_ifacename =
> default\niface.net_ifacename = <empty>\niface.gateway =
> <empty>\niface.subnet_mask = <empty>\niface.transport_name =
> tcp\niface.initiatorname = <empty>\niface.state = <empty>\niface.vlan_id =
> 0\niface.vlan_priority = 0\niface.vlan_state = <empty>\niface.iface_num =
> 0\niface.mtu = 0\niface.port = 0\niface.bootproto = <empty>\niface.dhcp_alt_client_id_state
> = <empty>\niface.dhcp_alt_client_id = <empty>\niface.dhcp_dns =
> <empty>\niface.dhcp_learn_iqn = <empty>\niface.dhcp_req_vendor_id_state =
> <empty>\niface.dhcp_vendor_id_state = <empty>\niface.dhcp_vendor_id =
> <empty>\niface.dhcp_slp_da = <empty>\niface.fragmentation =
> <empty>\niface.gratuitous_arp = <empty>\niface.incoming_forwarding =
> <empty>\niface.tos_state = <empty>\niface.tos = 0\niface.ttl =
> 0\niface.delayed_ack = <empty>\niface.tcp_nagle =
> <empty>\niface.tcp_wsf_state = <empty>\niface.tcp_wsf =
> 0\niface.tcp_timer_scale = 0\niface.tcp_timestamp = <empty>\niface.redirect
> = <empty>\niface.def_task_mgmt_timeout = 0\niface.header_digest =
> <empty>\niface.data_digest = <empty>\niface.immediate_data =
> <empty>\niface.initial_r2t = <empty>\niface.data_seq_inorder =
> <empty>\niface.data_pdu_inorder = <empty>\niface.erl =
> 0\niface.max_receive_data_len = 0\niface.first_burst_len =
> 0\niface.max_outstanding_r2t = 0\niface.max_burst_len = 0\niface.chap_auth
> = <empty>\niface.bidi_chap = <empty>\niface.strict_login_compliance =
> <empty>\niface.discovery_auth = <empty>\niface.discovery_logout =
> <empty>\nnode.discovery_address = <empty>\nnode.discovery_port =
> 0\nnode.discovery_type = static\nnode.session.initial_cmdsn =
> 0\nnode.session.initial_login_retry_max = 8\nnode.session.xmit_thread_priority
> = -20\nnode.session.cmds_max = 128\nnode.session.queue_depth =
> 32\nnode.session.nr_sessions = 1\nnode.session.auth.authmethod =
> CHAP\nnode.session.auth.username = zP5vX8BZscZKQ5NpxjCt\nnode.session.auth.password
> = ********\nnode.session.auth.username_in = <empty>\nnode.session.auth.password_in
> = <empty>\nnode.session.timeo.replacement_timeout =
> 120\nnode.session.err_timeo.abort_timeout = 15\nnode.session.err_timeo.lu_reset_timeout
> = 30\nnode.session.err_timeo.tgt_reset_timeout =
> 30\nnode.session.err_timeo.host_reset_timeout = 60\nnode.session.iscsi.FastAbort
> = Yes\nnode.session.iscsi.InitialR2T = No\nnode.session.iscsi.ImmediateData
> = Yes\nnode.session.iscsi.FirstBurstLength = 262144\nnode.session.iscsi.MaxBurstLength
> = 16776192\nnode.session.iscsi.DefaultTime2Retain = 0\nnode.session.iscsi.DefaultTime2Wait
> = 2\nnode.session.iscsi.MaxConnections = 1\nnode.session.iscsi.MaxOutstandingR2T
> = 1\nnode.session.iscsi.ERL = 0\nnode.conn[0].address =
> 127.0.0.1\nnode.conn[0].port = 3260\nnode.conn[0].startup =
> manual\nnode.conn[0].tcp.window_size = 524288\nnode.conn[0].tcp.type_of_service
> = 0\nnode.conn[0].timeo.logout_timeout = 15\nnode.conn[0].timeo.login_timeout
> = 15\nnode.conn[0].timeo.auth_timeout = 45\nnode.conn[0].timeo.noop_out_interval
> = 5\nnode.conn[0].timeo.noop_out_timeout = 5\nnode.conn[0].iscsi.MaxXmitDataSegmentLength
> = 0\nnode.conn[0].iscsi.MaxRecvDataSegmentLength =
> 262144\nnode.conn[0].iscsi.HeaderDigest = None\nnode.conn[0].iscsi.IFMarker
> = No\nnode.conn[0].iscsi.OFMarker = No\n# END RECORD\n', '')) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52771:node.name =
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7
> kolla_logs/_data/nova/nova-compute.log:52875:2017-03-06 14:24:18.050 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.authmethod', '-v', u'CHAP'), {'attempts': 1,
> 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52876:2017-03-06 14:24:18.050 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.authmethod -v CHAP
> out_of_band /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52877:2017-03-06 14:24:18.076 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.authmethod -v CHAP"
> returned: 0 in 0.026s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52880:2017-03-06 14:24:18.079 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.username', '-v', u'zP5vX8BZscZKQ5NpxjCt'), {'attempts':
> 1, 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52881:2017-03-06 14:24:18.079 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.username -v
> zP5vX8BZscZKQ5NpxjCt out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52882:2017-03-06 14:24:18.105 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.username -v
> zP5vX8BZscZKQ5NpxjCt" returned: 0 in 0.025s out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52885:2017-03-06 14:24:18.108 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.password', '-v', u'AziatHk74fjwTU97'), {'attempts': 1,
> 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52886:2017-03-06 14:24:18.109 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.password -v ***
> out_of_band /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52887:2017-03-06 14:24:18.133 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.password -v ***"
> returned: 0 in 0.024s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52896:2017-03-06 14:24:18.161 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--login'), {'attempts': 1, 'check_exit_code':
> (0, 255), 'delay_on_retry': True}) out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:52897:2017-03-06 14:24:18.162 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:53052:2017-03-06 14:26:18.217 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login" returned: 8 in 120.055s out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:53053:2017-03-06 14:26:18.218 6
> DEBUG oslo.privsep.daemon [-] u'iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login' failed. Not Retrying. out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:53055:Command: iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login
> kolla_logs/_data/nova/nova-compute.log:53057:Stdout: u'Logging in to
> [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal: 127.0.0.1,3260]
> (multiple)\n'
> kolla_logs/_data/nova/nova-compute.log:53058:Stderr: u'iscsiadm: Could
> not login to [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal:
> 127.0.0.1,3260].\niscsiadm: initiator reported error (8 - connection timed
> out)\niscsiadm: Could not log into all portals\n' out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:53059:2017-03-06 14:26:18.219 6
> DEBUG oslo.privsep.daemon [-] privsep: reply[111132336]: (5,
> 'oslo_concurrency.processutils.ProcessExecutionError', (u'Logging in to
> [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal: 127.0.0.1,3260]
> (multiple)\n', u'iscsiadm: Could not login to [iface: default, target:
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7,
> portal: 127.0.0.1,3260].\niscsiadm: initiator reported error (8 -
> connection timed out)\niscsiadm: Could not log into all portals\n', 8,
> u'iscsiadm -m node -T iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7
> -p 127.0.0.1:3260 --login', None)) out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
> kolla_logs/_data/nova/nova-compute.log:53060:2017-03-06 14:26:18.220 6
> WARNING os_brick.initiator.connectors.iscsi [req-b3e37102-4705-4d4e-a952-32d131e449a4
> - - - - -] Failed to login iSCSI target iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 on portal 127.0.0.1:3260
> (exit code 8).
> kolla_logs/_data/nova/nova-compute.log:53065:2017-03-06 14:26:18.224 6
> ERROR nova.virt.block_device [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] [instance: d1544927-291c-4a34-9634-dcc23880d1b7] Driver failed
> to attach volume 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 at /dev/vdb
> kolla_logs/_data/nova/nova-compute.log:53093:2017-03-06 14:26:18.230 6
> DEBUG cinderclient.v2.client [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] REQ: curl -g -i -X POST http://192.168.102.254:8776/v2/
> aa0bc3b5640a4c83bbb6d98526969834/volumes/9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7/action -H "User-Agent: python-cinderclient" -H
> "Content-Type: application/json" -H "Accept: application/json" -H
> "X-Auth-Token: {SHA1}5df529b2adf5150fe4f7046fc86b920ddd932145" -d
> '{"os-terminate_connection": {"connector": {"platform": "x86_64", "host": "
> kode4.genomics.cn", "do_local_attach": false, "ip": "192.168.102.24",
> "os_type": "linux2", "multipath": false, "initiator":
> "iqn.1994-05.com.redhat:2574299a1c8f"}}}' _http_log_request
> /usr/lib/python2.7/site-packages/keystoneauth1/session.py:347
> kolla_logs/_data/nova/nova-compute.log:53097:2017-03-06 14:26:18.563 6
> DEBUG cinderclient.v2.client [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] POST call to cinderv2 for http://192.168.102.254:8776/v2/
> aa0bc3b5640a4c83bbb6d98526969834/volumes/9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7/action used request id req-fbecdac2-59eb-4f8a-b43c-bb0f755232bd
> request /usr/lib/python2.7/site-packages/keystoneauth1/session.py:640
> kolla_logs/_data/nova/nova-compute.log:53100:2017-03-06 14:26:18.607 6
> ERROR nova.compute.manager [req-b3e37102-4705-4d4e-a952-32d131e449a4 - -
> - - -] [instance: d1544927-291c-4a34-9634-dcc23880d1b7] Failed to attach
> 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 at /dev/vdb
>
>
> 分析
>
> [root@kode1 kolla]# docker ps | grep tgt
> 446f9817d1bd        192.168.103.16:5000/bgi/centos-binary-tgtd:ocata-rc1-1
>                     "kolla_start"       2 days ago          Up About an
> hour                                    tgtd
> [root@kode1 kolla]# docker inspect 446f9817d1bd | grep -i pid
>             "Pid": 3356,
>             "PidMode": "",
>             "PidsLimit": 0,
> [root@kode1 kolla]# nsenter  -t 3356 -m -u -n -i -p
> ()[root@kode1 /]#
>
> ()[root@kode1 /]# cat run_command
> tgtd -d 1 -f --iscsi portal=192.168.102.21:3260()[root@kode1 /]#
>
>
> ()[root@kode1 /]#  tgtadm --mode target --op show
> Target 1: iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7
>     System information:
>         Driver: iscsi
>         State: ready
>     I_T nexus information:
>     LUN information:
>         LUN: 0
>             Type: controller
>             SCSI ID: IET     00010000
>             SCSI SN: beaf10
>             Size: 0 MB, Block size: 1
>             Online: Yes
>             Removable media: No
>             Prevent removal: No
>             Readonly: No
>             SWP: No
>             Thin-provisioning: No
>             Backing store type: null
>             Backing store path: None
>             Backing store flags:
>         LUN: 1
>             Type: disk
>             SCSI ID: IET     00010001
>             SCSI SN: beaf11
>             Size: 1074 MB, Block size: 512
>             Online: Yes
>             Removable media: No
>             Prevent removal: No
>             Readonly: No
>             SWP: No
>             Thin-provisioning: No
>             Backing store type: rdwr
>             Backing store path: /dev/cinder-volumes/volume-
> 9bd59ed1-97b9-4cfb-b74f-187bac143fb7
>             Backing store flags:
>     Account information:
>         zP5vX8BZscZKQ5NpxjCt
>     ACL information:
>         ALL
> ()[root@kode1 /]# exit
>
> [root@kode1 kolla]# netstat -anlp | grep 3260
> tcp        0      0 192.168.102.21:3260     0.0.0.0:*
>  LISTEN      3618/tgtd
> [root@kode1 kolla]#
>
> why the iscsi initiator think portal is 127.0.0.1:3260 ?
>
> ** Affects: kolla
>      Importance: Undecided
>          Status: New
>
> --
> You received this bug notification because you are subscribed to kolla.
> https://bugs.launchpad.net/bugs/1670284
>
> Title:
>   failed to attach a volume when using lvm as cinder backend
>
> Status in kolla:
>   New
>
> Bug description:
>   i Guys:
>   I found that I failed to attach a volume to vm when cinder use lvm as
> backend.
>
>   [root@kode0 ~]# openstack server list
>   +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
>   | ID                                   | Name  | Status | Networks
>                      | Image Name |
>   +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
>   | d1544927-291c-4a34-9634-dcc23880d1b7 | demo1 | ACTIVE |
> demo-net=10.0.0.8, 192.168.122.152 | cirros     |
>   +--------------------------------------+-------+--------+---
> ---------------------------------+------------+
>
>   [root@kode0 ~]# openstack volume list
>   +--------------------------------------+--------------+-----
> ------+------+-------------+
>   | ID                                   | Display Name | Status    | Size
> | Attached to |
>   +--------------------------------------+--------------+-----
> ------+------+-------------+
>   | 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 | vol2         | available |
> 1 |             |
>   +--------------------------------------+--------------+-----
> ------+------+-------------+
>   [root@kode0 ~]#
>
>   [root@kode0 ~]# openstack server add volume demo1 vol2
>   Unknown Error (HTTP 504)
>
>   I find the following log from compute node,
>
>   kolla_logs/_data/nova/nova-compute.log:52767:2017-03-06 14:24:18.022 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52768:2017-03-06 14:24:18.047 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260" returned: 0 in 0.025s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52769:2017-03-06 14:24:18.048 6
> DEBUG oslo.privsep.daemon [-] privsep: reply[111132336]: (4, ('# BEGIN
> RECORD 6.2.0.873-35\nnode.name = iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7\nnode.tpgt = -1\nnode.startup
> = automatic\nnode.leading_login = No\niface.hwaddress =
> <empty>\niface.ipaddress = <empty>\niface.iscsi_ifacename =
> default\niface.net_ifacename = <empty>\niface.gateway =
> <empty>\niface.subnet_mask = <empty>\niface.transport_name =
> tcp\niface.initiatorname = <empty>\niface.state = <empty>\niface.vlan_id =
> 0\niface.vlan_priority = 0\niface.vlan_state = <empty>\niface.iface_num =
> 0\niface.mtu = 0\niface.port = 0\niface.bootproto = <empty>\niface.dhcp_alt_client_id_state
> = <empty>\niface.dhcp_alt_client_id = <empty>\niface.dhcp_dns =
> <empty>\niface.dhcp_learn_iqn = <empty>\niface.dhcp_req_vendor_id_state =
> <empty>\niface.dhcp_vendor_id_state = <empty>\niface.dhcp_vendor_id =
> <empty>\niface.dhcp_slp_da = <empty>\niface.fragmentation =
> <empty>\niface.gratuitous_arp = <empty>\niface.incoming_forwarding =
> <empty>\niface.tos_state = <empty>\niface.tos = 0\niface.ttl =
> 0\niface.delayed_ack = <empty>\niface.tcp_nagle =
> <empty>\niface.tcp_wsf_state = <empty>\niface.tcp_wsf =
> 0\niface.tcp_timer_scale = 0\niface.tcp_timestamp = <empty>\niface.redirect
> = <empty>\niface.def_task_mgmt_timeout = 0\niface.header_digest =
> <empty>\niface.data_digest = <empty>\niface.immediate_data =
> <empty>\niface.initial_r2t = <empty>\niface.data_seq_inorder =
> <empty>\niface.data_pdu_inorder = <empty>\niface.erl =
> 0\niface.max_receive_data_len = 0\niface.first_burst_len =
> 0\niface.max_outstanding_r2t = 0\niface.max_burst_len = 0\niface.chap_auth
> = <empty>\niface.bidi_chap = <empty>\niface.strict_login_compliance =
> <empty>\niface.discovery_auth = <empty>\niface.discovery_logout =
> <empty>\nnode.discovery_address = <empty>\nnode.discovery_port =
> 0\nnode.discovery_type = static\nnode.session.initial_cmdsn =
> 0\nnode.session.initial_login_retry_max = 8\nnode.session.xmit_thread_priority
> = -20\nnode.session.cmds_max = 128\nnode.session.queue_depth =
> 32\nnode.session.nr_sessions = 1\nnode.session.auth.authmethod =
> CHAP\nnode.session.auth.username = zP5vX8BZscZKQ5NpxjCt\nnode.session.auth.password
> = ********\nnode.session.auth.username_in = <empty>\nnode.session.auth.password_in
> = <empty>\nnode.session.timeo.replacement_timeout =
> 120\nnode.session.err_timeo.abort_timeout = 15\nnode.session.err_timeo.lu_reset_timeout
> = 30\nnode.session.err_timeo.tgt_reset_timeout =
> 30\nnode.session.err_timeo.host_reset_timeout = 60\nnode.session.iscsi.FastAbort
> = Yes\nnode.session.iscsi.InitialR2T = No\nnode.session.iscsi.ImmediateData
> = Yes\nnode.session.iscsi.FirstBurstLength = 262144\nnode.session.iscsi.MaxBurstLength
> = 16776192\nnode.session.iscsi.DefaultTime2Retain = 0\nnode.session.iscsi.DefaultTime2Wait
> = 2\nnode.session.iscsi.MaxConnections = 1\nnode.session.iscsi.MaxOutstandingR2T
> = 1\nnode.session.iscsi.ERL = 0\nnode.conn[0].address =
> 127.0.0.1\nnode.conn[0].port = 3260\nnode.conn[0].startup =
> manual\nnode.conn[0].tcp.window_size = 524288\nnode.conn[0].tcp.type_of_service
> = 0\nnode.conn[0].timeo.logout_timeout = 15\nnode.conn[0].timeo.login_timeout
> = 15\nnode.conn[0].timeo.auth_timeout = 45\nnode.conn[0].timeo.noop_out_interval
> = 5\nnode.conn[0].timeo.noop_out_timeout = 5\nnode.conn[0].iscsi.MaxXmitDataSegmentLength
> = 0\nnode.conn[0].iscsi.MaxRecvDataSegmentLength =
> 262144\nnode.conn[0].iscsi.HeaderDigest = None\nnode.conn[0].iscsi.IFMarker
> = No\nnode.conn[0].iscsi.OFMarker = No\n# END RECORD\n', '')) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52771:node.name =
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7
>   kolla_logs/_data/nova/nova-compute.log:52875:2017-03-06 14:24:18.050 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.authmethod', '-v', u'CHAP'), {'attempts': 1,
> 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52876:2017-03-06 14:24:18.050 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.authmethod -v CHAP
> out_of_band /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52877:2017-03-06 14:24:18.076 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.authmethod -v CHAP"
> returned: 0 in 0.026s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52880:2017-03-06 14:24:18.079 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.username', '-v', u'zP5vX8BZscZKQ5NpxjCt'), {'attempts':
> 1, 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52881:2017-03-06 14:24:18.079 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.username -v
> zP5vX8BZscZKQ5NpxjCt out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52882:2017-03-06 14:24:18.105 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.username -v
> zP5vX8BZscZKQ5NpxjCt" returned: 0 in 0.025s out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52885:2017-03-06 14:24:18.108 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--op', 'update', '-n',
> 'node.session.auth.password', '-v', u'AziatHk74fjwTU97'), {'attempts': 1,
> 'check_exit_code': 0, 'delay_on_retry': True}) out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52886:2017-03-06 14:24:18.109 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.password -v ***
> out_of_band /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52887:2017-03-06 14:24:18.133 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --op update -n node.session.auth.password -v ***"
> returned: 0 in 0.024s out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52896:2017-03-06 14:24:18.161 6
> DEBUG oslo.privsep.daemon [-] privsep: request[111132336]: (3,
> 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node',
> '-T', u'iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7',
> '-p', u'127.0.0.1:3260', '--login'), {'attempts': 1, 'check_exit_code':
> (0, 255), 'delay_on_retry': True}) out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:52897:2017-03-06 14:24:18.162 6
> DEBUG oslo.privsep.daemon [-] Running cmd (subprocess): iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:53052:2017-03-06 14:26:18.217 6
> DEBUG oslo.privsep.daemon [-] CMD "iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login" returned: 8 in 120.055s out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:53053:2017-03-06 14:26:18.218 6
> DEBUG oslo.privsep.daemon [-] u'iscsiadm -m node -T
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 -p
> 127.0.0.1:3260 --login' failed. Not Retrying. out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:53055:Command: iscsiadm -m node
> -T iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7
> -p 127.0.0.1:3260 --login
>   kolla_logs/_data/nova/nova-compute.log:53057:Stdout: u'Logging in to
> [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal: 127.0.0.1,3260]
> (multiple)\n'
>   kolla_logs/_data/nova/nova-compute.log:53058:Stderr: u'iscsiadm: Could
> not login to [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal:
> 127.0.0.1,3260].\niscsiadm: initiator reported error (8 - connection timed
> out)\niscsiadm: Could not log into all portals\n' out_of_band
> /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:53059:2017-03-06 14:26:18.219 6
> DEBUG oslo.privsep.daemon [-] privsep: reply[111132336]: (5,
> 'oslo_concurrency.processutils.ProcessExecutionError', (u'Logging in to
> [iface: default, target: iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7, portal: 127.0.0.1,3260]
> (multiple)\n', u'iscsiadm: Could not login to [iface: default, target:
> iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7,
> portal: 127.0.0.1,3260].\niscsiadm: initiator reported error (8 -
> connection timed out)\niscsiadm: Could not log into all portals\n', 8,
> u'iscsiadm -m node -T iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7
> -p 127.0.0.1:3260 --login', None)) out_of_band /usr/lib/python2.7/site-
> packages/oslo_privsep/daemon.py:194
>   kolla_logs/_data/nova/nova-compute.log:53060:2017-03-06 14:26:18.220 6
> WARNING os_brick.initiator.connectors.iscsi [req-b3e37102-4705-4d4e-a952-32d131e449a4
> - - - - -] Failed to login iSCSI target iqn.2010-10.org.openstack:
> volume-9bd59ed1-97b9-4cfb-b74f-187bac143fb7 on portal 127.0.0.1:3260
> (exit code 8).
>   kolla_logs/_data/nova/nova-compute.log:53065:2017-03-06 14:26:18.224 6
> ERROR nova.virt.block_device [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] [instance: d1544927-291c-4a34-9634-dcc23880d1b7] Driver failed
> to attach volume 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 at /dev/vdb
>   kolla_logs/_data/nova/nova-compute.log:53093:2017-03-06 14:26:18.230 6
> DEBUG cinderclient.v2.client [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] REQ: curl -g -i -X POST http://192.168.102.254:8776/v2/
> aa0bc3b5640a4c83bbb6d98526969834/volumes/9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7/action -H "User-Agent: python-cinderclient" -H
> "Content-Type: application/json" -H "Accept: application/json" -H
> "X-Auth-Token: {SHA1}5df529b2adf5150fe4f7046fc86b920ddd932145" -d
> '{"os-terminate_connection": {"connector": {"platform": "x86_64", "host": "
> kode4.genomics.cn", "do_local_attach": false, "ip": "192.168.102.24",
> "os_type": "linux2", "multipath": false, "initiator":
> "iqn.1994-05.com.redhat:2574299a1c8f"}}}' _http_log_request
> /usr/lib/python2.7/site-packages/keystoneauth1/session.py:347
>   kolla_logs/_data/nova/nova-compute.log:53097:2017-03-06 14:26:18.563 6
> DEBUG cinderclient.v2.client [req-b3e37102-4705-4d4e-a952-32d131e449a4 -
> - - - -] POST call to cinderv2 for http://192.168.102.254:8776/v2/
> aa0bc3b5640a4c83bbb6d98526969834/volumes/9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7/action used request id req-fbecdac2-59eb-4f8a-b43c-bb0f755232bd
> request /usr/lib/python2.7/site-packages/keystoneauth1/session.py:640
>   kolla_logs/_data/nova/nova-compute.log:53100:2017-03-06 14:26:18.607 6
> ERROR nova.compute.manager [req-b3e37102-4705-4d4e-a952-32d131e449a4 - -
> - - -] [instance: d1544927-291c-4a34-9634-dcc23880d1b7] Failed to attach
> 9bd59ed1-97b9-4cfb-b74f-187bac143fb7 at /dev/vdb
>
>
>   分析
>
>   [root@kode1 kolla]# docker ps | grep tgt
>   446f9817d1bd        192.168.103.16:5000/bgi/
> centos-binary-tgtd:ocata-rc1-1                      "kolla_start"       2
> days ago          Up About an hour                                    tgtd
>   [root@kode1 kolla]# docker inspect 446f9817d1bd | grep -i pid
>               "Pid": 3356,
>               "PidMode": "",
>               "PidsLimit": 0,
>   [root@kode1 kolla]# nsenter  -t 3356 -m -u -n -i -p
>   ()[root@kode1 /]#
>
>   ()[root@kode1 /]# cat run_command
>   tgtd -d 1 -f --iscsi portal=192.168.102.21:3260()[root@kode1 /]#
>
>
>   ()[root@kode1 /]#  tgtadm --mode target --op show
>   Target 1: iqn.2010-10.org.openstack:volume-9bd59ed1-97b9-4cfb-
> b74f-187bac143fb7
>       System information:
>           Driver: iscsi
>           State: ready
>       I_T nexus information:
>       LUN information:
>           LUN: 0
>               Type: controller
>               SCSI ID: IET     00010000
>               SCSI SN: beaf10
>               Size: 0 MB, Block size: 1
>               Online: Yes
>               Removable media: No
>               Prevent removal: No
>               Readonly: No
>               SWP: No
>               Thin-provisioning: No
>               Backing store type: null
>               Backing store path: None
>               Backing store flags:
>           LUN: 1
>               Type: disk
>               SCSI ID: IET     00010001
>               SCSI SN: beaf11
>               Size: 1074 MB, Block size: 512
>               Online: Yes
>               Removable media: No
>               Prevent removal: No
>               Readonly: No
>               SWP: No
>               Thin-provisioning: No
>               Backing store type: rdwr
>               Backing store path: /dev/cinder-volumes/volume-
> 9bd59ed1-97b9-4cfb-b74f-187bac143fb7
>               Backing store flags:
>       Account information:
>           zP5vX8BZscZKQ5NpxjCt
>       ACL information:
>           ALL
>   ()[root@kode1 /]# exit
>
>   [root@kode1 kolla]# netstat -anlp | grep 3260
>   tcp        0      0 192.168.102.21:3260     0.0.0.0:*
>  LISTEN      3618/tgtd
>   [root@kode1 kolla]#
>
>   why the iscsi initiator think portal is 127.0.0.1:3260 ?
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/kolla/+bug/1670284/+subscriptions
>