Date: Sun, 06 Jan 2019 07:25:55 +0000 From: bugzilla-noreply@freebsd.org To: bugs@FreeBSD.org Subject: [Bug 234654] bad iSCSI/ctld interaction after network failures (timeouts) Message-ID: <bug-234654-227@https.bugs.freebsd.org/bugzilla/>
next in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D234654 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@FreeBSD.org Reporter: d8zNeCFG@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=3D30 has been set (from pr= evious 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 mess= ages 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 8= c 8a 40 00 01 00 00=20 Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:35:09 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 8a 40 00 01 00 00=20 Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:35:15 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 8a 40 00 01 00 00=20 Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:35:22 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 8a 40 00 01 00 00=20 Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:35:29 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 8a 40 00 01 00 00=20 Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:35:35 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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=3D4697849856, length=3D131072)]error =3D 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 8= c 7b 00 00 00 c0 00=20 Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 7b 00 00 00 c0 00=20 Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 7b 00 00 00 c0 00=20 Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 7b 00 00 00 c0 00=20 Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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 8= c 7b 00 00 00 c0 00=20 Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): CAM status: SCSI Status Er= ror Jan 5 22:39:25 v903 kernel: (da0:iscsi1:0:0:0): SCSI status: Check Conditi= on 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=3D4619042816, length=3D12288)]error =3D 5 Jan 5 22:39:25 v903 kernel: g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=3D4669407232, length=3D32768)]error =3D 5 Jan 5 22:39:25 v903 kernel: g_vfs_done():diskid/DISK-HAL_00925s2a[WRITE(offset=3D4734410752, length=3D8192)]error =3D 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 --=20 You are receiving this mail because: You are the assignee for the bug.=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-234654-227>