Cinder

cinder-backup doesn't connect to iscsi (huawei dorado)

Bug #1882235 reported by Lukasz
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Cinder
New
Undecided
Unassigned

Bug Description

I'm trying to do backup of volume which is created on Huawei dorado 5000 v3 array.

Retyping from ceph do array is working correctly (which also needs connection to array), but the backup fails. It looks like cinder-backup doesn't work, when have following discoverydb in iscsiadm:

 [TEST][root@cinder-03 ~]# iscsiadm -m discoverydb -o show -P1
SENDTARGETS:
DiscoveryAddress: 10.12.16.103,3260
DiscoveryAddress: 10.12.16.100,3260
DiscoveryAddress: 10.12.16.102,3260
DiscoveryAddress: 10.12.16.101,3260
iSNS:
No targets found.
STATIC:
No targets found.
FIRMWARE:
No targets found.
[TEST][root@cinder-03 ~]#

all log from time of creation of backup:

2020-06-05 12:30:53.549 14617 INFO cinder.backup.manager [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Create backup started, backup: 94343ce5-07f1-4d46-a495-6e4ce846d556 volume: 4a9b485a-5cb0-40e5-bcef-cf58db544599.
2020-06-05 12:30:53.575 14617 DEBUG os_brick.utils [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] ==> get_connector_properties: call u"{'execute': None, 'my_ip': '10.20.1.40', 'enforce_multipath': False, 'host': None, 'root_helper': 'sudo cinder-rootwrap /etc/cinder/rootwrap.conf', 'multipath': False}" trace_logging_wrapper /usr/lib/python2.7/dist-packages/os_brick/utils.py:146
2020-06-05 12:30:53.578 17187 DEBUG oslo.privsep.daemon [-] privsep: request[140322066041584]: (3, 'os_brick.privileged.rootwrap.execute_root', ('cat', '/etc/iscsi/initiatorname.iscsi'), {}) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:443
2020-06-05 12:30:53.579 17187 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): cat /etc/iscsi/initiatorname.iscsi execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2020-06-05 12:30:53.644 17187 DEBUG oslo_concurrency.processutils [-] CMD "cat /etc/iscsi/initiatorname.iscsi" returned: 0 in 0.065s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2020-06-05 12:30:53.653 17187 DEBUG oslo.privsep.daemon [-] privsep: reply[140322066041584]: (4, ('## DO NOT EDIT OR REMOVE THIS FILE!\n## If you remove this file, the iSCSI daemon will not start.\n## If you change the InitiatorName, existing access control lists\n## may reject this initiator. The InitiatorName must be unique\n## for each iSCSI initiator. Do NOT duplicate iSCSI InitiatorNames.\nInitiatorName=iqn.1993-08.org.debian:01:dcec6ae12a4c\n', '')) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:456
2020-06-05 12:30:53.659 14617 DEBUG os_brick.initiator.linuxfc [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] No Fibre Channel support detected on system. get_fc_hbas /usr/lib/python2.7/dist-packages/os_brick/initiator/linuxfc.py:106
2020-06-05 12:30:53.660 14617 DEBUG os_brick.initiator.linuxfc [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] No Fibre Channel support detected on system. get_fc_hbas /usr/lib/python2.7/dist-packages/os_brick/initiator/linuxfc.py:106
2020-06-05 12:30:53.663 14617 DEBUG os_brick.utils [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] <== get_connector_properties: return (86ms) {'initiator': u'iqn.1993-08.org.debian:01:dcec6ae12a4c', 'ip': u'10.20.1.40', 'platform': u'x86_64', 'host': u'cinder-03', 'do_local_attach': False, 'os_type': u'linux2', 'multipath': False} trace_logging_wrapper /usr/lib/python2.7/dist-packages/os_brick/utils.py:170
2020-06-05 12:30:55.938 14617 DEBUG os_brick.initiator.connector [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Factory for iscsi on x86_64 factory /usr/lib/python2.7/dist-packages/os_brick/initiator/connector.py:262
2020-06-05 12:30:55.940 14617 DEBUG os_brick.initiator.connectors.iscsi [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] ==> connect_volume: call u"{'args': (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7f9f44260f90>, {u'target_discovered': False, u'encrypted': False, u'discard': True, u'qos_specs': {u'IOType': u'2', u'maxIOPS': u'1000'}, u'target_iqn': u'iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100', u'target_portal': u'10.12.16.100:3260', u'volume_id': u'4a9b485a-5cb0-40e5-bcef-cf58db544599', u'target_lun': 1, u'access_mode': u'rw', u'map_info': {}}), 'kwargs': {}}" trace_logging_wrapper /usr/lib/python2.7/dist-packages/os_brick/utils.py:146
2020-06-05 12:30:55.942 14617 DEBUG oslo_concurrency.lockutils [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Lock "connect_volume" acquired by "os_brick.initiator.connectors.iscsi.connect_volume" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:276
2020-06-05 12:30:55.943 17187 DEBUG oslo.privsep.daemon [-] privsep: request[140322066041584]: (3, 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'node', '--op', 'show', '-p', u'10.12.16.100:3260'), {'check_exit_code': 0}) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:443
2020-06-05 12:30:55.944 17187 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m node --op show -p 10.12.16.100:3260 execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2020-06-05 12:30:55.987 17187 DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m node --op show -p 10.12.16.100:3260" returned: 21 in 0.042s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2020-06-05 12:30:55.990 17187 DEBUG oslo_concurrency.processutils [-] u'iscsiadm -m node --op show -p 10.12.16.100:3260' failed. Not Retrying. execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:457
2020-06-05 12:30:55.991 17187 DEBUG oslo.privsep.daemon [-] privsep: Exception during request[140322066041584]: Unexpected error while running command.
Command: iscsiadm -m node --op show -p 10.12.16.100:3260
Exit code: 21
Stdout: u''
Stderr: u'iscsiadm: No records found\n' loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:449
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon Traceback (most recent call last):
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py", line 445, in loop
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon reply = self._process_cmd(*msg)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py", line 428, in _process_cmd
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon ret = func(*f_args, **f_kwargs)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/oslo_privsep/priv_context.py", line 209, in _wrap
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon return func(*args, **kwargs)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/os_brick/privileged/rootwrap.py", line 194, in execute_root
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon return custom_execute(*cmd, shell=False, run_as_root=False, **kwargs)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/os_brick/privileged/rootwrap.py", line 143, in custom_execute
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon on_completion=on_completion, *cmd, **kwargs)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon File "/usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 424, in execute
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon cmd=sanitized_cmd)
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon ProcessExecutionError: Unexpected error while running command.
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon Command: iscsiadm -m node --op show -p 10.12.16.100:3260
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon Exit code: 21
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon Stdout: u''
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon Stderr: u'iscsiadm: No records found\n'
2020-06-05 12:30:55.991 17187 ERROR oslo.privsep.daemon
2020-06-05 12:30:55.995 17187 DEBUG oslo.privsep.daemon [-] privsep: reply[140322066041584]: (5, 'oslo_concurrency.processutils.ProcessExecutionError', (u'', u'iscsiadm: No records found\n', 21, u'iscsiadm -m node --op show -p 10.12.16.100:3260', None)) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:456
2020-06-05 12:30:55.997 17187 DEBUG oslo.privsep.daemon [-] privsep: request[140322066041584]: (3, 'os_brick.privileged.rootwrap.execute_root', ('iscsiadm', '-m', 'discoverydb', '-o', 'show', '-P', 1), {'check_exit_code': 0}) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:443
2020-06-05 12:30:55.998 17187 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): iscsiadm -m discoverydb -o show -P 1 execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2020-06-05 12:30:56.040 17187 DEBUG oslo_concurrency.processutils [-] CMD "iscsiadm -m discoverydb -o show -P 1" returned: 0 in 0.042s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2020-06-05 12:30:56.043 17187 DEBUG oslo.privsep.daemon [-] privsep: reply[140322066041584]: (4, ('SENDTARGETS:\nDiscoveryAddress: 10.12.16.103,3260\nDiscoveryAddress: 10.12.16.100,3260\nDiscoveryAddress: 10.12.16.102,3260\nDiscoveryAddress: 10.12.16.101,3260\niSNS:\nNo targets found.\nSTATIC:\nNo targets found.\nFIRMWARE:\nNo targets found.\n', '')) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:456
2020-06-05 12:30:56.045 14617 DEBUG os_brick.initiator.connectors.iscsi [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] iscsiadm ['-m', 'discoverydb', '-o', 'show', '-P', 1]: stdout=SENDTARGETS:
DiscoveryAddress: 10.12.16.103,3260
DiscoveryAddress: 10.12.16.100,3260
DiscoveryAddress: 10.12.16.102,3260
DiscoveryAddress: 10.12.16.101,3260
iSNS:
No targets found.
STATIC:
No targets found.
FIRMWARE:
No targets found.
 stderr= _run_iscsiadm_bare /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:1088
2020-06-05 12:30:56.047 14617 DEBUG os_brick.initiator.connectors.iscsi [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Regex to get portals from discoverydb: ^SENDTARGETS:
.*?^DiscoveryAddress: 10.12.16.100,3260.*?
(.*?)^(?:DiscoveryAddress|iSNS):.* _get_discoverydb_portals /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:356
2020-06-05 12:30:56.049 14617 DEBUG os_brick.initiator.connectors.iscsi [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Skipping cleanup Unable to find target portals information on discoverydb. _cleanup_connection /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:876
2020-06-05 12:30:56.050 14617 DEBUG oslo_concurrency.lockutils [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Lock "connect_volume" released by "os_brick.initiator.connectors.iscsi.connect_volume" :: held 0.108s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:288
2020-06-05 12:30:56.051 14617 DEBUG os_brick.initiator.connectors.iscsi [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] <== connect_volume: exception (108ms) TargetPortalNotFound(u'Unable to find target portal 10.12.16.100:3260.',) trace_logging_wrapper /usr/lib/python2.7/dist-packages/os_brick/utils.py:156
2020-06-05 12:30:56.987 14617 DEBUG oslo_db.sqlalchemy.engines [req-3cb78d2e-fe96-4c95-b9bc-bb8b930ec418 - - - - -] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:290
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server [req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default] Exception during message handling: TargetPortalNotFound: Unable to find target portal 10.12.16.100:3260.
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 413, in create_backup
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server self._update_backup_error(backup, six.text_type(err))
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server self.force_reraise()
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 402, in create_backup
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server updates = self._run_backup(context, backup, volume)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 472, in _run_backup
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server backup_device.is_snapshot)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 1036, in _attach_device
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return self._attach_volume(ctxt, backup_device, properties)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 1058, in _attach_volume
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server {'volume_id', volume.id})
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server self.force_reraise()
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 1047, in _attach_volume
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return self._connect_device(conn)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/backup/manager.py", line 1088, in _connect_device
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server vol_handle = connector.connect_volume(conn['data'])
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/utils.py", line 150, in trace_logging_wrapper
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 277, in inner
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py", line 516, in connect_volume
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server self._cleanup_connection(connection_properties, force=True)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server self.force_reraise()
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py", line 509, in connect_volume
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return self._connect_multipath_volume(connection_properties)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/utils.py", line 61, in _wrapper
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return r.call(f, *args, **kwargs)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/retrying.py", line 206, in call
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server return attempt.get(self._wrap_exception)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/retrying.py", line 247, in get
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server six.reraise(self.value[0], self.value[1], self.value[2])
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/retrying.py", line 200, in call
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py", line 692, in _connect_multipath_volume
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server ips_iqns_luns = self._get_ips_iqns_luns(connection_properties)
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py", line 202, in _get_ips_iqns_luns
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server target_portal=connection_properties['target_portal'])
2020-06-05 12:30:57.779 14617 ERROR oslo_messaging.rpc.server TargetPortalNotFound: Unable to find target portal 10.12.16.100:3260.

and here are commands (greped by iscsiadm) when doing backup:

[TEST][root@cinder-03 ~]# grep req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 /var/log/cinder/cinder-backup.log | grep -v 'Transferred chunk' | grep iscsiadm | sed 's/\[req-bb7795cb-f21e-46c2-8f54-3c635c00d2a7 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default]//'
2020-06-05 12:30:56.045 14617 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ['-m', 'discoverydb', '-o', 'show', '-P', 1]: stdout=SENDTARGETS:
[TEST][root@cinder-03 ~]#

and here are commands (greped by iscsiadm) when doing retype:

 [TEST][root@cinder-03 ~]# grep req-f597ba62-aede-4651-8303-47da880fdb33 /var/log/cinder/cinder-volume.log | grep -v 'Transferred chunk' | grep iscsiadm | sed 's/\[req-f597ba62-aede-4651-8303-47da880fdb33 833873b8f04842188a0709c3ef23ab6b 2037dd6132e348749e830b89af87df7d - default default]//'
2020-06-05 11:38:45.759 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm (): stdout= stderr=iscsiadm: No records found
2020-06-05 11:38:45.815 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm (): stdout= stderr=iscsiadm: No records found
2020-06-05 11:38:45.863 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm (): stdout= stderr=iscsiadm: No records found
2020-06-05 11:38:45.913 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm (): stdout= stderr=iscsiadm: No records found
2020-06-05 11:38:45.964 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--interface', 'default', '--op', 'new'): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.16.100,3260,-1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100] added
2020-06-05 11:38:46.020 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--interface', 'default', '--op', 'new'): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.16.101,3260,-1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20001:10.12.16.101] added
2020-06-05 11:38:46.077 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--interface', 'default', '--op', 'new'): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.16.102,3260,-1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020000:10.12.16.102] added
2020-06-05 11:38:46.132 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--interface', 'default', '--op', 'new'): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.16.103,3260,-1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020001:10.12.16.103] added
2020-06-05 11:38:46.185 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr=iscsiadm: Cannot modify node.session.scan. Invalid param name.
2020-06-05 11:38:46.239 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr=iscsiadm: Cannot modify node.session.scan. Invalid param name.
2020-06-05 11:38:46.291 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr=iscsiadm: Cannot modify node.session.scan. Invalid param name.
2020-06-05 11:38:46.345 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.session.scan', '-v', 'manual'): stdout= stderr=iscsiadm: Cannot modify node.session.scan. Invalid param name.
2020-06-05 11:38:46.397 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.399 14252 DEBUG os_brick.initiator.connectors.iscsi iscsi session list stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.402 14252 WARNING os_brick.initiator.connectors.iscsi Couldn't find iscsi sessions because iscsiadm err: iscsiadm: No active sessions.
2020-06-05 11:38:46.451 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.454 14252 DEBUG os_brick.initiator.connectors.iscsi iscsi session list stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.456 14252 WARNING os_brick.initiator.connectors.iscsi Couldn't find iscsi sessions because iscsiadm err: iscsiadm: No active sessions.
2020-06-05 11:38:46.506 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.510 14252 DEBUG os_brick.initiator.connectors.iscsi iscsi session list stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.512 14252 WARNING os_brick.initiator.connectors.iscsi Couldn't find iscsi sessions because iscsiadm err: iscsiadm: No active sessions.
2020-06-05 11:38:46.577 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.580 14252 DEBUG os_brick.initiator.connectors.iscsi iscsi session list stdout= stderr=iscsiadm: No active sessions.
2020-06-05 11:38:46.583 14252 WARNING os_brick.initiator.connectors.iscsi Couldn't find iscsi sessions because iscsiadm err: iscsiadm: No active sessions.
2020-06-05 11:38:47.184 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--login',): stdout=Logging in to [iface: default, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100, portal: 10.12.16.100,3260] (multiple)
2020-06-05 11:38:47.808 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--login',): stdout=Logging in to [iface: default, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20001:10.12.16.101, portal: 10.12.16.101,3260] (multiple)
2020-06-05 11:38:48.457 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--login',): stdout=Logging in to [iface: default, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020000:10.12.16.102, portal: 10.12.16.102,3260] (multiple)
2020-06-05 11:38:49.108 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--login',): stdout=Logging in to [iface: default, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020001:10.12.16.103, portal: 10.12.16.103,3260] (multiple)
2020-06-05 11:38:49.223 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'automatic'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:38:49.282 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'automatic'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:38:49.330 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'automatic'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:38:49.378 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'automatic'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:38:49.429 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout=tcp: [10] 10.12.16.100:3260,1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100 (non-flash)
2020-06-05 11:38:49.487 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout=tcp: [10] 10.12.16.100:3260,1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100 (non-flash)
2020-06-05 11:38:49.548 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout=tcp: [10] 10.12.16.100:3260,1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100 (non-flash)
2020-06-05 11:38:49.613 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout=tcp: [10] 10.12.16.100:3260,1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100 (non-flash)
2020-06-05 11:39:48.367 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('-m', 'session'): stdout=tcp: [10] 10.12.16.100:3260,1 iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100 (non-flash)
2020-06-05 11:39:48.999 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:49.564 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--logout',): stdout=Logging out of session [sid: 12, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020000:10.12.16.102, portal: 10.12.16.102,3260]
2020-06-05 11:39:49.623 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'delete'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:49.681 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:50.258 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--logout',): stdout=Logging out of session [sid: 13, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::1020001:10.12.16.103, portal: 10.12.16.103,3260]
2020-06-05 11:39:50.311 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'delete'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:50.363 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:50.929 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--logout',): stdout=Logging out of session [sid: 11, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20001:10.12.16.101, portal: 10.12.16.101,3260]
2020-06-05 11:39:50.978 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'delete'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:51.025 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
2020-06-05 11:39:51.588 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--logout',): stdout=Logging out of session [sid: 10, target: iqn.2006-08.com.huawei:oceanstor:21007cc38577f64f::20000:10.12.16.100, portal: 10.12.16.100,3260]
2020-06-05 11:39:51.643 14252 DEBUG os_brick.initiator.connectors.iscsi iscsiadm ('--op', 'delete'): stdout= stderr= _run_iscsiadm /usr/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:966
[TEST][root@cinder-03 ~]#

Revision history for this message
Lukasz (luksky2) wrote :

some more info:

[TEST][root@cinder-03 ~]# dpkg -l | grep cinder
ii cinder-api 2:12.0.9-0ubuntu1~cloud0 all Cinder storage service - API server
ii cinder-backup 2:12.0.9-0ubuntu1~cloud0 all Cinder storage service - Scheduler server
ii cinder-common 2:12.0.9-0ubuntu1~cloud0 all Cinder storage service - common files
ii cinder-scheduler 2:12.0.9-0ubuntu1~cloud0 all Cinder storage service - Scheduler server
ii cinder-volume 2:12.0.9-0ubuntu1~cloud0 all Cinder storage service - Volume server

when I add the targets by hand backup is working, but cleanup process deletes targets, and next backup doesn't work.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.