Open tobad357 opened 6 years ago
Logs when running sudo journalctl -xn 100 -f -u multipathd -u systemd-udevd -u iscsid
sudo iscsiadm -m node -T iqn.2007-11.com.nimblestorage:xxxxxx-v42a8502da2d80974.0000002c.e0705959 -u
111
Jan 17 09:36:16 srv04. multipathd[833]: tick (1.000259 secs)
Jan 17 09:36:17 srv04. multipathd[833]: tick (1.000240 secs)
Jan 17 09:36:17 srv04. multipathd[833]: uevent 'remove' from '/devices/platform/host8/session2/target8:0:0/8:0:0:0/block/sde'
Jan 17 09:36:17 srv04. multipathd[833]: .ID_FS_TYPE_NEW=xfs
Jan 17 09:36:17 srv04. multipathd[833]: ACTION=remove
Jan 17 09:36:17 srv04. multipathd[833]: DEVLINKS=/dev/disk/by-id/scsi-2a938c3feb74838096c9ce900595970e0 /dev/disk/by-path/ip-172.20.2.10:3260-iscsi-iqn.2007-11.com.nimblestorage:xxxxx-v42a8502da2d80974.0000002c.e0705959-lun-0 /dev/disk/by-uuid/0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: DEVNAME=/dev/sde
Jan 17 09:36:17 srv04. multipathd[833]: DEVPATH=/devices/platform/host8/session2/target8:0:0/8:0:0:0/block/sde
Jan 17 09:36:17 srv04. multipathd[833]: DEVTYPE=disk
Jan 17 09:36:17 srv04. multipathd[833]: DM_MULTIPATH_DEVICE_PATH=1
Jan 17 09:36:17 srv04. multipathd[833]: ID_BUS=scsi
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_TYPE=xfs
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_USAGE=filesystem
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_UUID=0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_UUID_ENC=0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: ID_MODEL=Server
Jan 17 09:36:17 srv04. multipathd[833]: ID_MODEL_ENC=Server\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20
Jan 17 09:36:17 srv04. multipathd[833]: ID_PATH=ip-172.20.2.10:3260-iscsi-iqn.2007-11.com.nimblestorage:xxxxx-v42a8502da2d80974.0000002c.e0705959-lun-0
Jan 17 09:36:17 srv04. multipathd[833]: ID_PATH_TAG=ip-172_20_2_10_3260-iscsi-iqn_2007-11_com_nimblestorage_xxxxx-v42a8502da2d80974_0000002c_e0705959-lun-0
Jan 17 09:36:17 srv04. multipathd[833]: ID_REVISION=1.0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SCSI=1
Jan 17 09:36:17 srv04. multipathd[833]: ID_SCSI_SERIAL=a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SERIAL=2a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SERIAL_SHORT=a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_TARGET_PORT=0
Jan 17 09:36:17 srv04. multipathd[833]: ID_TYPE=disk
Jan 17 09:36:17 srv04. multipathd[833]: ID_VENDOR=Nimble
Jan 17 09:36:17 srv04. multipathd[833]: ID_VENDOR_ENC=Nimble\x20\x20
Jan 17 09:36:17 srv04. multipathd[833]: MAJOR=8
Jan 17 09:36:17 srv04. multipathd[833]: MINOR=64
Jan 17 09:36:17 srv04. multipathd[833]: MPATH_SBIN_PATH=/sbin
Jan 17 09:36:17 srv04. multipathd[833]: SEQNUM=5448
Jan 17 09:36:17 srv04. multipathd[833]: SUBSYSTEM=block
Jan 17 09:36:17 srv04. multipathd[833]: SYSTEMD_READY=0
Jan 17 09:36:17 srv04. multipathd[833]: Forwarding 1 uevents
Jan 17 09:36:17 srv04. multipathd[833]: sde: remove path (uevent)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: failback = "immediate" (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: path_grouping_policy = group_by_serial (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: path_selector = "round-robin 0" (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: features = "1 queue_if_no_path" (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: hardware_handler = "1 alua" (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: rr_weight = "priorities" (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: minio = 1 (config file setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: no_path_retry = 20 (controller setting)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: fast_io_fail_tmo = 5 (config file default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: retain_attached_hw_handler = yes (config file default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: deferred_remove = no (config file default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: delay_watch_checks = "off" (internal default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: delay_wait_checks = "off" (internal default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: skip_kpartx = no (config file default)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: update dev_loss_tmo to 100
Jan 17 09:36:17 srv04. multipathd[833]: target7:0:0 -> session1
Jan 17 09:36:17 srv04. multipathd[833]: sdf: ignoring dev_loss_tmo on iSCSI
Jan 17 09:36:17 srv04. multipathd[833]: open '/sys/devices/platform/host7/session1/iscsi_session/session1/recovery_tmo'
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: assembled map [2 queue_if_no_path retain_attached_hw_handler 1 alua 1 1 round-robin 0 1 1 8:80 50]
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: reload [0 209715200 multipath 2 queue_if_no_path retain_attached_hw_handler 1 alua 1 1 round-robin 0 1 1 8:80 50]
Jan 17 09:36:17 srv04. multipathd[833]: uevent 'remove' from '/devices/platform/host7/session1/target7:0:0/7:0:0:0/block/sdf'
Jan 17 09:36:17 srv04. multipathd[833]: .ID_FS_TYPE_NEW=xfs
Jan 17 09:36:17 srv04. multipathd[833]: ACTION=remove
Jan 17 09:36:17 srv04. multipathd[833]: DEVLINKS=/dev/disk/by-path/ip-172.20.1.10:3260-iscsi-iqn.2007-11.com.nimblestorage:xxxxx-v42a8502da2d80974.0000002c.e0705959-lun-0 /dev/disk/by-id/scsi-2a938c3feb74838096c9ce900595970e0 /dev/disk/by-uuid/0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: DEVNAME=/dev/sdf
Jan 17 09:36:17 srv04. multipathd[833]: DEVPATH=/devices/platform/host7/session1/target7:0:0/7:0:0:0/block/sdf
Jan 17 09:36:17 srv04. multipathd[833]: DEVTYPE=disk
Jan 17 09:36:17 srv04. multipathd[833]: DM_MULTIPATH_DEVICE_PATH=1
Jan 17 09:36:17 srv04. multipathd[833]: ID_BUS=scsi
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_TYPE=xfs
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_USAGE=filesystem
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_UUID=0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: ID_FS_UUID_ENC=0bff3b54-cee5-4415-b8a5-11e8a946c641
Jan 17 09:36:17 srv04. multipathd[833]: ID_MODEL=Server
Jan 17 09:36:17 srv04. multipathd[833]: ID_MODEL_ENC=Server\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20
Jan 17 09:36:17 srv04. multipathd[833]: ID_PATH=ip-172.20.1.10:3260-iscsi-iqn.2007-11.com.nimblestorage:xxxxx-v42a8502da2d80974.0000002c.e0705959-lun-0
Jan 17 09:36:17 srv04. multipathd[833]: ID_PATH_TAG=ip-172_20_1_10_3260-iscsi-iqn_2007-11_com_nimblestorage_xxxxx-v42a8502da2d80974_0000002c_e0705959-lun-0
Jan 17 09:36:17 srv04. multipathd[833]: ID_REVISION=1.0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SCSI=1
Jan 17 09:36:17 srv04. multipathd[833]: ID_SCSI_SERIAL=a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SERIAL=2a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_SERIAL_SHORT=a938c3feb74838096c9ce900595970e0
Jan 17 09:36:17 srv04. multipathd[833]: ID_TARGET_PORT=0
Jan 17 09:36:17 srv04. multipathd[833]: ID_TYPE=disk
Jan 17 09:36:17 srv04. multipathd[833]: ID_VENDOR=Nimble
Jan 17 09:36:17 srv04. multipathd[833]: ID_VENDOR_ENC=Nimble\x20\x20
Jan 17 09:36:17 srv04. multipathd[833]: MAJOR=8
Jan 17 09:36:17 srv04. multipathd[833]: MINOR=80
Jan 17 09:36:17 srv04. multipathd[833]: MPATH_SBIN_PATH=/sbin
Jan 17 09:36:17 srv04. multipathd[833]: SEQNUM=5452
Jan 17 09:36:17 srv04. multipathd[833]: SUBSYSTEM=block
Jan 17 09:36:17 srv04. multipathd[833]: SYSTEMD_READY=0
Jan 17 09:36:17 srv04. multipathd[833]: Forwarding 1 uevents
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: load table [0 209715200 multipath 2 queue_if_no_path retain_attached_hw_handler 1 alua 1 1 round-robin 0 1 1 8:80 50]
Jan 17 09:36:17 srv04. multipathd[833]: 8:80: dev_t not found in pathvec
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: update_multipath_strings
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: disassemble map [2 queue_if_no_path retain_attached_hw_handler 1 alua 1 1 round-robin 0 1 1 8:80 1 ]
Jan 17 09:36:17 srv04. multipathd[833]: *word = 2, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = queue_if_no_path, len = 16
Jan 17 09:36:17 srv04. multipathd[833]: *word = retain_attached_hw_handler, len = 26
Jan 17 09:36:17 srv04. multipathd[833]: *word = 1, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = alua, len = 4
Jan 17 09:36:17 srv04. multipathd[833]: *word = 1, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = round-robin, len = 11
Jan 17 09:36:17 srv04. multipathd[833]: *word = 0, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 1, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 8:80, len = 4
Jan 17 09:36:17 srv04. multipathd[833]: No device found for 8:80
Jan 17 09:36:17 srv04. multipathd[833]: 8:80: cannot find block device
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0 dropped path sdf
Jan 17 09:36:17 srv04. multipathd[833]: sdf: orphan path, path removed externally
Jan 17 09:36:17 srv04. multipathd[833]: sysfs prioritizer refcount 2
Jan 17 09:36:17 srv04. multipathd[833]: tur checker refcount 2
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: disassemble status [2 1 0 0 1 1 E 0 1 0 8:80 A 0 ]
Jan 17 09:36:17 srv04. multipathd[833]: *word = 2, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 0, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 1, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = E, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 1, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: *word = 0, len = 1
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: cannot disassemble status
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: failed to setup multipath
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: remove multipath map
Jan 17 09:36:17 srv04. multipathd[833]: sde: orphan path, map flushed
Jan 17 09:36:17 srv04. multipathd[833]: sysfs prioritizer refcount 1
Jan 17 09:36:17 srv04. multipathd[833]: tur checker refcount 1
Jan 17 09:36:17 srv04. multipathd[833]: uevent trigger error
Jan 17 09:36:17 srv04. multipathd[833]: sdf: remove path (uevent)
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: devmap event #1
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: multipath map not found
Jan 17 09:36:17 srv04. multipathd[833]: 2a938c3feb74838096c9ce900595970e0: event checker exit
Jan 17 09:36:18 srv04. multipathd[833]: tick (1.000212 secs)
Jan 17 09:36:18 srv04. iscsid[1118]: Connection2:0 to [target: iqn.2007-11.com.nimblestorage:xxxxx-v42a8502da2d80974.0000002c.e0705959, portal: 172.20.2.10,3260] through [iface: default] is shutdown.
Jan 17 09:36:19 srv04. multipathd[833]: tick (1.000229 secs)
Jan 17 09:36:19 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:20 srv04. multipathd[833]: tick (1.000204 secs)
Jan 17 09:36:21 srv04. multipathd[833]: tick (1.000189 secs)
Jan 17 09:36:22 srv04. multipathd[833]: tick (1.000215 secs)
Jan 17 09:36:23 srv04. multipathd[833]: tick (1.000195 secs)
Jan 17 09:36:24 srv04. multipathd[833]: tick (1.000209 secs)
Jan 17 09:36:25 srv04. multipathd[833]: tick (1.000241 secs)
Jan 17 09:36:25 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:26 srv04. multipathd[833]: tick (1.000240 secs)
Jan 17 09:36:27 srv04. multipathd[833]: tick (1.000204 secs)
Jan 17 09:36:28 srv04. multipathd[833]: tick (1.000169 secs)
Jan 17 09:36:29 srv04. multipathd[833]: tick (1.000214 secs)
Jan 17 09:36:30 srv04. multipathd[833]: tick (1.000184 secs)
Jan 17 09:36:31 srv04. multipathd[833]: tick (1.000166 secs)
Jan 17 09:36:31 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:32 srv04. multipathd[833]: tick (1.000193 secs)
Jan 17 09:36:33 srv04. multipathd[833]: tick (1.000204 secs)
Jan 17 09:36:34 srv04. multipathd[833]: tick (1.000195 secs)
Jan 17 09:36:35 srv04. multipathd[833]: tick (1.000178 secs)
Jan 17 09:36:36 srv04. multipathd[833]: tick (1.000195 secs)
Jan 17 09:36:37 srv04. multipathd[833]: tick (1.000193 secs)
Jan 17 09:36:37 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:38 srv04. multipathd[833]: tick (1.000232 secs)
Jan 17 09:36:39 srv04. multipathd[833]: tick (1.000228 secs)
Jan 17 09:36:40 srv04. multipathd[833]: tick (1.000201 secs)
Jan 17 09:36:41 srv04. multipathd[833]: tick (1.000119 secs)
Jan 17 09:36:42 srv04. multipathd[833]: tick (1.000132 secs)
Jan 17 09:36:43 srv04. multipathd[833]: tick (1.000173 secs)
Jan 17 09:36:43 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:44 srv04. multipathd[833]: tick (1.000221 secs)
Jan 17 09:36:45 srv04. multipathd[833]: tick (1.000226 secs)
Jan 17 09:36:46 srv04. multipathd[833]: tick (1.000136 secs)
Jan 17 09:36:47 srv04. multipathd[833]: tick (1.000168 secs)
Jan 17 09:36:48 srv04. multipathd[833]: tick (1.000186 secs)
Jan 17 09:36:49 srv04. multipathd[833]: tick (1.000226 secs)
Jan 17 09:36:49 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:50 srv04. multipathd[833]: tick (1.000191 secs)
Jan 17 09:36:51 srv04. multipathd[833]: tick (1.000211 secs)
Jan 17 09:36:52 srv04. multipathd[833]: tick (1.000121 secs)
Jan 17 09:36:53 srv04. multipathd[833]: tick (1.000164 secs)
Jan 17 09:36:54 srv04. multipathd[833]: tick (1.000192 secs)
Jan 17 09:36:55 srv04. multipathd[833]: tick (1.000220 secs)
Jan 17 09:36:55 srv04. multipathd[833]: map garbage collection
Jan 17 09:36:56 srv04. multipathd[833]: tick (1.000225 secs)
Jan 17 09:36:57 srv04. multipathd[833]: tick (1.000177 secs)
Jan 17 09:36:58 srv04. multipathd[833]: tick (1.000151 secs)
Jan 17 09:36:59 srv04. multipathd[833]: tick (1.000236 secs)
Jan 17 09:37:00 srv04. multipathd[833]: tick (1.000208 secs)
Jan 17 09:37:01 srv04. multipathd[833]: tick (1.000224 secs)
Jan 17 09:37:01 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:02 srv04. multipathd[833]: tick (1.000230 secs)
Jan 17 09:37:03 srv04. multipathd[833]: tick (1.000175 secs)
Jan 17 09:37:04 srv04. multipathd[833]: tick (1.000205 secs)
Jan 17 09:37:05 srv04. multipathd[833]: tick (1.000178 secs)
Jan 17 09:37:06 srv04. multipathd[833]: tick (1.000177 secs)
Jan 17 09:37:07 srv04. multipathd[833]: tick (1.000181 secs)
Jan 17 09:37:07 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:08 srv04. multipathd[833]: tick (1.000165 secs)
Jan 17 09:37:09 srv04. multipathd[833]: tick (1.000200 secs)
Jan 17 09:37:10 srv04. multipathd[833]: tick (1.000229 secs)
Jan 17 09:37:11 srv04. multipathd[833]: tick (1.000202 secs)
Jan 17 09:37:12 srv04. multipathd[833]: tick (1.000149 secs)
Jan 17 09:37:13 srv04. multipathd[833]: tick (1.000198 secs)
Jan 17 09:37:13 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:14 srv04. multipathd[833]: tick (1.000206 secs)
Jan 17 09:37:15 srv04. multipathd[833]: tick (1.000200 secs)
Jan 17 09:37:16 srv04. multipathd[833]: tick (1.000219 secs)
Jan 17 09:37:17 srv04. multipathd[833]: tick (1.000177 secs)
Jan 17 09:37:18 srv04. systemd-udevd[819]: seq 5455 '/devices/virtual/block/dm-4' is taking a long time
Jan 17 09:37:18 srv04. multipathd[833]: tick (1.000215 secs)
Jan 17 09:37:19 srv04. multipathd[833]: tick (1.000211 secs)
Jan 17 09:37:19 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:20 srv04. multipathd[833]: tick (1.000214 secs)
Jan 17 09:37:21 srv04. multipathd[833]: tick (1.000203 secs)
Jan 17 09:37:22 srv04. multipathd[833]: tick (1.000209 secs)
Jan 17 09:37:23 srv04. multipathd[833]: tick (1.000127 secs)
Jan 17 09:37:24 srv04. multipathd[833]: tick (1.000198 secs)
Jan 17 09:37:25 srv04. multipathd[833]: tick (1.000234 secs)
Jan 17 09:37:25 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:26 srv04. multipathd[833]: tick (1.000234 secs)
Jan 17 09:37:27 srv04. multipathd[833]: tick (1.000202 secs)
Jan 17 09:37:28 srv04. multipathd[833]: tick (1.000221 secs)
Jan 17 09:37:29 srv04. multipathd[833]: tick (1.000204 secs)
Jan 17 09:37:30 srv04. multipathd[833]: tick (1.000202 secs)
Jan 17 09:37:31 srv04. multipathd[833]: tick (1.000216 secs)
Jan 17 09:37:31 srv04. multipathd[833]: map garbage collection
Jan 17 09:37:32 srv04. multipathd[833]: tick (1.000174 secs)
Jan 17 09:37:33 srv04. multipathd[833]: tick (1.000152 secs)
Jan 17 09:37:34 srv04. multipathd[833]: tick (1.000179 secs)
Do you have kworker(s) spinning on 100% CPU?
Hmm let us check
Issue Report
Bug
Container Linux Version
Environment
Bare Metal
Expected Behavior
When logging out of multiple iscsi sessions at once and multipathd is enabled the system should complete the logouts
Actual Behavior
When logging out of multiple iscsi sessions at once the second session will not complete logout and it is impossible to re run the logout as iscsiadm will give the error seen below
The same error happens occasionally if logging out of only one session.
Reproduction Steps
Other Information
This can be seen in multipathd logs