[Bug 234654] bad iSCSI/ctld interaction after network failures (timeouts)
bugzilla-noreply at freebsd.org
bugzilla-noreply at freebsd.org
Sun Jan 6 07:25:57 UTC 2019
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=234654
Bug ID: 234654
Summary: bad iSCSI/ctld interaction after network failures
(timeouts)
Product: Base System
Version: 12.0-RELEASE
Hardware: Any
OS: Any
Status: New
Severity: Affects Only Me
Priority: ---
Component: kern
Assignee: bugs at FreeBSD.org
Reporter: d8zNeCFG at aon.at
Scenario:
- Machine A ("hal")
. runs FreeBSD 12.0
. runs as VirtualBox host
. exports virtual disks via iSCSI (ctld)
. Because of sometimes poor network connectivity (overload on a 1 Gbps
network), sysctl kern.cam.ctl.iscsi.ping_timeout=30 has been set (from previous
experience with 11.2)
- Machine V ("v903")
. runs 12.0
. runs as VirtualBox client on A
. mounts a UFS filesystem from a virtual disk exported by A
. has the default kern.iscsi.ping_timeout: 5 set
- Due to network overload, machine V runs into the ping timeout (5 seconds)
Result:
- V cannot access the disk exported from A anymore, with the following messages
appearing in the respective syslogs as shown below.
Likely cause:
- The likely cause seems to be a poor handling of reconnects initiated from V
while A thinks that the old connection is still valid.
Syslog output:
- On machine V:
Jan 5 22:35:09 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 8a
40 00 01 00 00
Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:35:15 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 8a
40 00 01 00 00
Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:35:22 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 8a
40 00 01 00 00
Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:35:29 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 8a
40 00 01 00 00
Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:35:35 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 8a
40 00 01 00 00
Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): Error 5, Retries exhausted
Jan 5 22:35:35 v903 kernel:
g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=4697849856,
length=131072)]error = 5
Jan 5 22:36:46 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 7b
00 00 00 c0 00
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:39:25 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 7b
00 00 00 c0 00
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:39:25 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 7b
00 00 00 c0 00
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:39:25 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 7b
00 00 00 c0 00
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): Retrying command (per sense
data)
Jan 5 22:39:25 v903 kernel: WARNING: hal.xyzzy
(iqn.1995-06.xyzzy.hal:disk925): no ping reply (NOP-In) after 5 seconds;
reconnecting
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): WRITE(10). CDB: 2a 00 00 8c 7b
00 00 00 c0 00
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Error
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Condition
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI sense: UNIT ATTENTION
asc:29,7 (I_T nexus loss occurred)
Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): Error 5, Retries exhausted
Jan 5 22:39:25 v903 kernel:
g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=4619042816,
length=12288)]error = 5
Jan 5 22:39:25 v903 kernel:
g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=4669407232,
length=32768)]error = 5
Jan 5 22:39:25 v903 kernel:
g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=4734410752,
length=8192)]error = 5
...
repeating ad infinitum
- On machine A:
Jan 5 22:35:10 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 9 tasks
Jan 5 22:35:10 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:35:16 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 10 tasks
Jan 5 22:35:16 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:35:23 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 10 tasks
Jan 5 22:35:23 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:35:30 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 8 tasks
Jan 5 22:35:30 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:35:36 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 7 tasks
Jan 5 22:35:36 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:36:47 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 23 tasks
Jan 5 22:36:47 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:36:53 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 20 tasks
Jan 5 22:36:53 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:02 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:37:02 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:10 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:37:10 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:16 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 20 tasks
Jan 5 22:37:16 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:22 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 21 tasks
Jan 5 22:37:22 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:31 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 19 tasks
Jan 5 22:37:31 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:38 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 19 tasks
Jan 5 22:37:38 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:44 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:37:44 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:37:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:37:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:00 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:38:00 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:09 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 22 tasks
Jan 5 22:38:09 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:18 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 20 tasks
Jan 5 22:38:18 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:25 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 20 tasks
Jan 5 22:38:25 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:30 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 18 tasks
Jan 5 22:38:30 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:38 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 25 tasks
Jan 5 22:38:38 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:45 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 19 tasks
Jan 5 22:38:45 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 20 tasks
Jan 5 22:38:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:38:57 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 26 tasks
Jan 5 22:38:57 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:39:04 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 30 tasks
Jan 5 22:39:04 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:39:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 41 tasks
Jan 5 22:39:51 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:39:58 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 26 tasks
Jan 5 22:39:58 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:40:05 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 28 tasks
Jan 5 22:40:05 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:40:12 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 29 tasks
Jan 5 22:40:12 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): tasks terminated
Jan 5 22:40:20 hal kernel: WARNING: 192.168.1.195
(iqn.1995-06.xyzzy.hal:v903): waiting for CTL to terminate 26 tasks
...
likewise repeating forever
--
You are receiving this mail because:
You are the assignee for the bug.
More information about the freebsd-bugs
mailing list