Open Stack

Hi,

I have a kolla-ansible deployment, and I am trying to switch from the LVM iSCSI protocol to iSER (RDMA).

On the host machine, I have installed rdma-core, which enabled kernel module loading for the NIC card we are using, the "BCM57414 NetXtreme-E 10Gb/25Gb RDMA Ethernet Controller". I have verified the function of RDMA with ib_write_bw, which worked fine. 

The first problem I encountered with Kolla is the absence of necessary packages - ibverbs-providers, which includes userspace drivers for RDMA. Without it, cinder_volume will not attach a volume. I did a image rebuild with package ibverbs-providers included. I will fill an issue for this later. Then I just changed target_protocol = iser in cinder_volume config file.

The current issue I am facing is that the instance is stuck at the "Spawning" phase. In the nova_compute log, I see the following lines:

2023-06-26 10:57:36.204 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] ==> connect_volume: call "{'self': <os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7f4dd45adc30>, 'connection_properties': {'target_discovered': False, 'target_portal': '10.47.1.25:3260', 'target_iqn': 'iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26', 'target_lun': 1, 'volume_id': 'bc382b4c-dac4-4ca6-a260-0d450d6c4e26', 'auth_method': 'CHAP', 'auth_username': '8n7WyZ2wZFNd7B33rfYw', 'auth_password': '***', 'encrypted': False, 'qos_specs': None, 'access_mode': 'rw': False}}" trace_logging_wrapper /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/utils.py:174
2023-06-26 10:57:36.208 7 DEBUG os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Acquiring lock "connect_to_iscsi_portal-10.47.1.25:3260-iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26" by "os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_to_iscsi_portal_unsafe" inner /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:68
2023-06-26 10:57:36.208 7 DEBUG os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Lock "connect_to_iscsi_portal-10.47.1.25:3260-iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26" acquired by "os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_to_iscsi_portal_unsafe" :: waited 0.001s inner /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:73
2023-06-26 10:57:36.209 7 INFO os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Trying to connect to iSCSI portal 10.47.1.25:3260
2023-06-26 10:57:36.219 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm (): stdout= stderr=iscsiadm: No records found
 _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.227 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--interface', 'iser', '--op', 'new'): stdout=New iSCSI node [iser:[hw=,ip=,net_if=,iscsi_if=iser] 10.47.1.25,3260,-1 iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26] added
 stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.234 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.241 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.authmethod', '-v', 'CHAP'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.247 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.username', '-v', '8n7WyZ2wZFNd7B33rfYw'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.254 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.password', '-v', '***'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:57:36.260 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
 _run_iscsiadm_bare /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1182
2023-06-26 10:57:36.261 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsi session list stdout= stderr=iscsiadm: No active sessions.
 _run_iscsi_session /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1171
2023-06-26 10:57:36.261 7 WARNING os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm stderr output when getting sessions: iscsiadm: No active sessions.


2 min later it timeouts:

2023-06-26 10:59:38.377 7 WARNING os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Failed to login iSCSI target iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26 on portal 10.47.1.25:3260 (exit code 8).: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
2023-06-26 10:59:38.378 7 DEBUG os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Lock "connect_to_iscsi_portal-10.47.1.25:3260-iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26" "released" by "os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_to_iscsi_portal_unsafe" :: held 122.170s inner /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:87
2023-06-26 10:59:38.378 7 WARNING os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Failed to connect to iSCSI portal 10.47.1.25:3260.
2023-06-26 10:59:38.378 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Getting connected devices for (ips,iqns,luns)=[('10.47.1.25:3260', 'iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26', 1)] _get_connection_devices /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:819
2023-06-26 10:59:38.394 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
 _run_iscsiadm_bare /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1182
2023-06-26 10:59:38.394 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsi session list stdout= stderr=iscsiadm: No active sessions.
 _run_iscsi_session /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1171
2023-06-26 10:59:38.394 7 WARNING os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm stderr output when getting sessions: iscsiadm: No active sessions.
2023-06-26 10:59:38.394 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Resulting device map defaultdict(<function ISCSIConnector._get_connection_devices.<locals>.<lambda> at 0x7f4dd43230a0>, {('10.47.1.25:3260', 'iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26'): (set(), set())}) _get_connection_devices /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:852
2023-06-26 10:59:38.394 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Disconnecting from: [('10.47.1.25:3260', 'iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26')] _disconnect_connection /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1160
2023-06-26 10:59:38.401 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:38.407 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--logout',): stdout= stderr=iscsiadm: No matching sessions found
 _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:38.413 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'delete'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:38.414 7 DEBUG os_brick.utils [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Finished call to 'os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_single_volume' after 122.207(s), this was the 1st time calling it. log_it /var/lib/kolla/venv/lib/python3.10/site-packages/tenacity/after.py:30
2023-06-26 10:59:38.415 7 DEBUG os_brick.utils [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Retrying os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_single_volume in 1.0 seconds as it raised VolumeDeviceNotFound: Volume device not found at .. log_it /var/lib/kolla/venv/lib/python3.10/site-packages/tenacity/before_sleep.py:40
2023-06-26 10:59:39.393 7 DEBUG oslo_service.periodic_task [None req-a325bda7-8910-43e3-90a9-6ae0dc8ae6a7 - - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /var/lib/kolla/venv/lib/python3.10/site-packages/oslo_service/periodic_task.py:210
2023-06-26 10:59:39.416 7 WARNING os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Service needs to call os_brick.setup() before connecting volumes, if it doesn't it will break on the next release
2023-06-26 10:59:39.416 7 DEBUG os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Acquiring lock "connect_to_iscsi_portal-10.47.1.25:3260-iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26" by "os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_to_iscsi_portal_unsafe" inner /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:68
2023-06-26 10:59:39.417 7 DEBUG os_brick.initiator.connectors.base [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Lock "connect_to_iscsi_portal-10.47.1.25:3260-iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26" acquired by "os_brick.initiator.connectors.iscsi.ISCSIConnector._connect_to_iscsi_portal_unsafe" :: waited 0.001s inner /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/base.py:73
2023-06-26 10:59:39.418 7 INFO os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] Trying to connect to iSCSI portal 10.47.1.25:3260
2023-06-26 10:59:39.426 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm (): stdout= stderr=iscsiadm: No records found
 _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.435 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--interface', 'iser', '--op', 'new'): stdout=New iSCSI node [iser:[hw=,ip=,net_if=,iscsi_if=iser] 10.47.1.25,3260,-1 iqn.2010-10.org.openstack:volume-bc382b4c-dac4-4ca6-a260-0d450d6c4e26] added
 stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.441 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.447 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.authmethod', '-v', 'CHAP'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.454 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.username', '-v', '8n7WyZ2wZFNd7B33rfYw'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.454 7 DEBUG ovsdbapp.backend.ovs_idl.vlog [-] [POLLIN] on fd 20 __log_wakeup /usr/lib/python3/dist-packages/ovs/poller.py:263
2023-06-26 10:59:39.461 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('--op', 'update', '-n', 'node.session.auth.password', '-v', '***'): stdout= stderr= _run_iscsiadm /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1026
2023-06-26 10:59:39.467 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
 _run_iscsiadm_bare /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1182
2023-06-26 10:59:39.467 7 DEBUG os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsi session list stdout= stderr=iscsiadm: No active sessions.
 _run_iscsi_session /var/lib/kolla/venv/lib/python3.10/site-packages/os_brick/initiator/connectors/iscsi.py:1171
2023-06-26 10:59:39.468 7 WARNING os_brick.initiator.connectors.iscsi [None req-67fc8494-95ce-45ca-972b-63d0833da0b2 c10f2f77bb9d43a0832dcc9262d63943 49fccac069b847a98fe3aae84ecf9aa4 - - default default] iscsiadm stderr output when getting sessions: iscsiadm: No active sessions.

In this log, the problem is the line "Failed to login to iSCSI target", but I am not sure why this is happening. Does anyone have any ideas about what could be wrong? Thanks!

---
Best regards,
Tomas Leypold