<html><body><div style="font-family: arial,helvetica,sans-serif; font-size: 10pt; color: #000000"><div>Hello, I find strange behavior of zpool import when accessing a pool via iscsi: It either completes quickly, takes 61-72 s or 121-127 s. Using dtrace I found 2 ioctl syscalls (fd = 3, cmd = 5a06, arg = 804237c) which either return quickly (< 10 s) or take about 60 s. I have no idea what ioctl command 5a06 is supposed to do or even where to look for that information.</div><div> While the ioctl command hangs there is no CPU load on both head and backends (idle 99-100%). I don't think there is any dependency on the number of devices in the pool, because there are always 2 ioctl-5a06 syscalls. Also during zpool import a lot of SCSI errors are reported in fmdump, but I do not see any difference whether or not the affected ioctls run normally. No SCSI errors occur during the hanging ioctls. </div><div>The reported errors are either generic write errors (key 0x3 asc 0xc ascq 0x0) or bus resets (key 0x6 asc 0x29 ascq 0x0). There are no SCSI errors once the pool is imported and used for normal IO. On the backends there are no errors reported in fmdump and no problems with long running syscalls. I also tried the following without any success: - Run the tests in both stable (r151014) and bloody (20160422) release. - Configure target-params timeout of the initiator to 3 seconds - Reconfigure io_time and retries of the sd driver to 3 s / 1 retry. Any help to find/resolve the root cause of those sysctl hangs would be greatly appreciated. Kind Regards harald My test setups are: A: VMware Workstation 12 (laptop with i7@2.5GHz, 16GB RAM, fast SSD disk): - 3 backends with 768MB RAM, 1 vCPU, stable release (r151014) - 1 head with 2GB RAM, 1 vCPU, stable release (r151014) - 1 alternative head with 2GB RAM, 1 vCPU, bloody release (20160422) B: VMware ESXi 6 (server with E5620@2.4GHz, 24GB RAM, RAID 0 over 3 300GB 15K SAS disks) - 3 backends with 1GB RAM, 1 vCPU, stable release (r151014) - 1 head with 6GB RAM, 2 vCPU, stable release (r151014) Each backend presents 2 virtual disks as LUNs. On the head I have created a zpool consiting of 2 raidz1 vdevs spanning the backends: pool: pool1 id: 12810568181218589176 state: ONLINE status: Some supported features are not enabled on the pool. action: The pool can be imported using its name or numeric identifier, though some features will not be available without an explicit 'zpool upgrade'. config: pool1 ONLINE raidz1-0 ONLINE c3t600144F03AB7625F00005723BE320001d0 ONLINE c3t600144F03AB7625F00005723BEFB0001d0 ONLINE c3t600144F03AB7625F00005723BF1E0001d0 ONLINE raidz1-1 ONLINE c3t600144F03AB7625F00005723BE320002d0 ONLINE c3t600144F03AB7625F00005723BEFB0002d0 ONLINE c3t600144F03AB7625F00005723BF1E0002d0 ONLINE There is no iSCSI authentication configured, no host or target groups are used. I did run zpool import in a loop on both virtual setups using the following script: for i in {1..100}; do sudo dtrace -n ' syscall::ioctl:entry /pid == $target/ { self->ts = timestamp; } syscall::ioctl:return /pid == $target && self->ts/ { @time = sum(timestamp - self->ts); self->ts = 0; } END { printa(@time); }' -c "zpool import" sleep 30; done After 100 test runs on 2 test setups I got 3 groups of runtimes: - below 16 sec - between 61 and 72 sec - between 121 and 127 sec Setup A B Result <=16 s +1 min +2 min <=16 s +1 min +2 min Count 36 49 15 53 38 9 Min 5.8 61.0 121.6 1.0 61.2 121.8 Max 15.9 71.9 126.9 11.2 71.3 127.0 Avg 10.8 66.6 122.4 4.2 65.3 123.1 StDev 0.9 0.9 0.7 2.7 2.1 1.1 Setup B is on faster hardware and does suffer less often from the problem. But still there is something going very wrong here. So I used dtrace to find out where the additional 1 or 2 minutes come from: sudo dtrace -qn ' BEGIN { printf("\n"); } syscall::ioctl:entry /pid == $target/ { self->ts = timestamp; self->arg0 = arg0; self->arg1 = arg1; self->arg2 = arg2; } syscall::ioctl:return /pid == $target && self->ts/ { printf("time = %Y, fd = %d, cmd = %lx, arg = %lx, runtime %d s\n", walltimestamp, self->arg0, self->arg1, self->arg2, (timestamp - self->ts) / 1000000000); @time[probefunc] = lquantize((timestamp - self->ts) / 1000000000, 0, 180, 60); self->ts = 0; } END { printa(@time); }' -c "zpool import" Example 1 (normal run): fmdump output: May 26 14:11:24.4887 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:24.5464 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:11:24.5464 ereport.io.scsi.cmd.disk.recovered May 26 14:11:24.8359 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.dev.serr May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.dev.serr May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:11:24.8395 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:24.8397 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:24.9291 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.recovered May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.recovered May 26 14:11:24.8366 ereport.io.scsi.cmd.disk.recovered May 26 14:11:29.8392 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:11:29.8392 ereport.io.scsi.cmd.disk.dev.rqs.merr dtrace output: time = 2016 May 26 14:11:19, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 403, arg = fe2ce9cc, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:11:19, fd = 9, cmd = 403, arg = fe1cf9cc, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:11:19, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:11:19, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:11:24, fd = 3, cmd = 5a06, arg = 804237c, runtime 5 s time = 2016 May 26 14:11:29, fd = 3, cmd = 5a06, arg = 804237c, runtime 5 s time = 2016 May 26 14:11:29, fd = 1, cmd = 5401, arg = 8042bbe, runtime 0 s time = 2016 May 26 14:11:29, fd = 3, cmd = 5a3f, arg = 80429d0, runtime 0 s ioctl value ------------- Distribution ------------- count < 0 | 0 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 40 60 | 0 Example 2 (2 additional minutes): fmdump output: May 26 14:13:27.6296 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:13:27.6395 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:13:27.6400 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:13:28.4369 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:13:28.4369 ereport.io.scsi.cmd.disk.recovered May 26 14:14:27.8696 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:27.9694 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:27.9695 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:28.2196 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:28.2230 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:28.2235 ereport.io.scsi.cmd.disk.dev.serr May 26 14:14:28.2235 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:14:28.2256 ereport.io.scsi.cmd.disk.dev.serr May 26 14:14:28.3194 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:28.4767 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:14:28.4767 ereport.io.scsi.cmd.disk.recovered May 26 14:14:28.2256 ereport.io.scsi.cmd.disk.recovered May 26 14:14:28.2256 ereport.io.scsi.cmd.disk.recovered May 26 14:14:28.2235 ereport.io.scsi.cmd.disk.recovered May 26 14:14:33.2385 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:14:33.3183 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:15:28.8692 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:15:28.9333 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:15:28.9333 ereport.io.scsi.cmd.disk.recovered dtrace output: time = 2016 May 26 14:13:27, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 403, arg = fe2ce9cc, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:13:27, fd = 9, cmd = 403, arg = fe1cf9cc, runtime 0 s time = 2016 May 26 14:13:27, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:13:27, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:13:27, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:14:28, fd = 3, cmd = 5a06, arg = 804237c, runtime 60 s time = 2016 May 26 14:15:29, fd = 3, cmd = 5a06, arg = 804237c, runtime 61 s time = 2016 May 26 14:15:29, fd = 1, cmd = 5401, arg = 8042bbe, runtime 0 s time = 2016 May 26 14:15:29, fd = 3, cmd = 5a3f, arg = 80429d0, runtime 0 s ioctl value ------------- Distribution ------------- count < 0 | 0 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 38 60 |@@ 2 120 | 0 Example 3 (1 addional minute in first 0x5a06-ioctl): fmdump output: May 26 14:19:16.6490 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:19:16.7392 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:19:16.7393 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:19:16.7400 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:19:16.7401 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.0794 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.1439 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:20:17.1439 ereport.io.scsi.cmd.disk.recovered May 26 14:20:17.4295 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.4303 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.4390 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.4457 ereport.io.scsi.cmd.disk.tran May 26 14:20:17.4457 ereport.io.scsi.cmd.disk.tran May 26 14:20:17.5292 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.4457 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:20:17.5394 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:20:17.4457 ereport.io.scsi.cmd.disk.recovered May 26 14:20:17.4457 ereport.io.scsi.cmd.disk.recovered May 26 14:20:17.6890 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:20:17.6890 ereport.io.scsi.cmd.disk.recovered May 26 14:20:22.4392 ereport.io.scsi.cmd.disk.dev.rqs.merr dtrace output: time = 2016 May 26 14:19:16, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 403, arg = fe2ce9cc, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:19:16, fd = 9, cmd = 403, arg = fe1cf9cc, runtime 0 s time = 2016 May 26 14:19:16, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:19:16, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:19:16, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:20:17, fd = 3, cmd = 5a06, arg = 804237c, runtime 60 s time = 2016 May 26 14:20:22, fd = 3, cmd = 5a06, arg = 804237c, runtime 5 s time = 2016 May 26 14:20:22, fd = 1, cmd = 5401, arg = 8042bbe, runtime 0 s time = 2016 May 26 14:20:22, fd = 3, cmd = 5a3f, arg = 80429d0, runtime 0 s ioctl value ------------- Distribution ------------- count < 0 | 0 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 39 60 |@ 1 120 | 0 Example 4 (1 addional minute in second 0x5a06-ioctl): fmdump output: May 26 14:23:12.8093 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:12.8099 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:12.8099 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:17.8093 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:17.8094 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:17.9194 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:17.9383 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:23:17.9383 ereport.io.scsi.cmd.disk.recovered May 26 14:23:18.2694 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:18.2893 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:18.2898 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:23:18.8060 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:23:18.8060 ereport.io.scsi.cmd.disk.recovered May 26 14:23:23.3696 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:24:18.8897 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:24:18.9897 ereport.io.scsi.cmd.disk.dev.rqs.merr May 26 14:24:19.0218 ereport.io.scsi.cmd.disk.dev.rqs.derr May 26 14:24:19.0218 ereport.io.scsi.cmd.disk.recovered dtrace output: time = 2016 May 26 14:23:12, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 403, arg = fe2ce9cc, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 403, arg = fe1cf974, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 42a, arg = fe1cf9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 417, arg = fe2ceb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 403, arg = fe2ce974, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 42a, arg = fe2ce9d0, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 412, arg = fe1cf9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 417, arg = fe1cfb58, runtime 0 s time = 2016 May 26 14:23:12, fd = 9, cmd = 403, arg = fe1cf9cc, runtime 0 s time = 2016 May 26 14:23:12, fd = 8, cmd = 412, arg = fe2ce9b8, runtime 0 s time = 2016 May 26 14:23:12, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:23:12, fd = 3, cmd = 5a05, arg = 80422f0, runtime 0 s time = 2016 May 26 14:23:18, fd = 3, cmd = 5a06, arg = 804237c, runtime 5 s time = 2016 May 26 14:24:19, fd = 3, cmd = 5a06, arg = 804237c, runtime 61 s time = 2016 May 26 14:24:19, fd = 1, cmd = 5401, arg = 8042bbe, runtime 0 s time = 2016 May 26 14:24:19, fd = 3, cmd = 5a3f, arg = 80429d0, runtime 0 s ioctl value ------------- Distribution ------------- count < 0 | 0 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 39 60 |@ 1 120 | 0 Configure target-params timeout of the initiator to 3 seconds: sysadm@head1:/export/home/sysadm$ pfexec iscsiadm list target-param -v Target: iqn.2010-08.org.illumos:02:74d64faf-ebe7-e811-c715-f427f6bd76f9 Alias: backend3 Bi-directional Authentication: disabled Authentication Type: NONE Login Parameters (Default/Configured): Data Sequence In Order: yes/- Data PDU In Order: yes/- Default Time To Retain: 20/- Default Time To Wait: 2/- Error Recovery Level: 0/- First Burst Length: 65536/- Immediate Data: yes/- Initial Ready To Transfer (R2T): yes/- Max Burst Length: 262144/- Max Outstanding R2T: 1/- Max Receive Data Segment Length: 8192/- Max Connections: 1/- Header Digest: NONE/- Data Digest: NONE/- Tunable Parameters (Default/Configured): Session Login Response Time: 60/3 Maximum Connection Retry Time: 180/3 Login Retry Time Interval: 60/3 Configured Sessions: 1 Target: iqn.2010-08.org.illumos:02:43ccef91-f911-4c16-c4df-8d99967c3a29 Alias: backend2 Bi-directional Authentication: disabled Authentication Type: NONE Login Parameters (Default/Configured): Data Sequence In Order: yes/- Data PDU In Order: yes/- Default Time To Retain: 20/- Default Time To Wait: 2/- Error Recovery Level: 0/- First Burst Length: 65536/- Immediate Data: yes/- Initial Ready To Transfer (R2T): yes/- Max Burst Length: 262144/- Max Outstanding R2T: 1/- Max Receive Data Segment Length: 8192/- Max Connections: 1/- Header Digest: NONE/- Data Digest: NONE/- Tunable Parameters (Default/Configured): Session Login Response Time: 60/3 Maximum Connection Retry Time: 180/3 Login Retry Time Interval: 60/3 Configured Sessions: 1 Target: iqn.2010-08.org.illumos:02:3e79a87e-125f-c11c-ef19-e30aa9d5fd54 Alias: backend1 Bi-directional Authentication: disabled Authentication Type: NONE Login Parameters (Default/Configured): Data Sequence In Order: yes/- Data PDU In Order: yes/- Default Time To Retain: 20/- Default Time To Wait: 2/- Error Recovery Level: 0/- First Burst Length: 65536/- Immediate Data: yes/- Initial Ready To Transfer (R2T): yes/- Max Burst Length: 262144/- Max Outstanding R2T: 1/- Max Receive Data Segment Length: 8192/- Max Connections: 1/- Header Digest: NONE/- Data Digest: NONE/- Tunable Parameters (Default/Configured): Session Login Response Time: 60/3 Maximum Connection Retry Time: 180/3 Login Retry Time Interval: 60/3 Configured Sessions: 1 Configure io_time and retries for the sd driver: echo 'set sd:sd_io_time=3' >> /etc/system echo 'sd-config-list = "SUN COMSTAR", "retries-timeout:1";' >> /kernel/drv/sd.conf shutdown -i6 -g0 -y </div><div> </div><div data-marker="__SIG_PRE__"><div> </div> <div><div> <div><div><div><table class="mceItemTable" border="0" cellpadding="0" cellspacing="0"><tbody><tr><td style="padding-right: 10px;" data-mce-style="padding-right: 10px;" align="left" valign="middle"><div><div><a target="_blank" href="http://www.pawaq.com/" data-mce-href="http://www.pawaq.com/"><img doc="Briefcase/Public/logo_pawaq_mail.png" alt="Logo PAWAQ GmbH" style="border: 0;" src="cid:9b235c741df31ce9bbd7d5ce2b1bdf370d5ba843@zimbra" data-mce-src="https://mx.zsuite.at/home/hp@pawaq.at/Briefcase/Public/logo_pawaq_mail.png" data-mce-style="border: 0;"></a> </div></div></td><td style="padding-left: 10px; padding-right: 10px; border-left-width: 1px; border-left-style: solid; border-right-width: 1px; border-right-style: solid;" data-mce-style="padding-left: 10px; padding-right: 10px; border-left-width: 1px; border-left-style: solid; border-right-width: 1px; border-right-style: solid;" align="left" valign="middle">Harald Paier<div>PAWAQ GmbH </div><div>+43 1 2365078 10 hp@pawaq.at - www.pawaq.com</div></td><td style="padding-left: 10px;" data-mce-style="padding-left: 10px;" align="left" valign="middle"><div><img doc="Briefcase/Public/PARTNER_SOLUTION_PROVIDER_ENT.png" src="cid:096470416687d303e9289886e454ea7f76b4dd8b@zimbra" data-mce-src="https://mx.zsuite.at/home/hp@pawaq.at/Briefcase/Public/PARTNER_SOLUTION_PROVIDER_ENT.png"> <img doc="Briefcase/Public/PARTNER_SERVICE_PROVIDER_PRO.png" alt="VMware Partner - Professional Service Provider" src="cid:e36e03e295165669da7c9eb95cc39561e6f4c794@zimbra" data-mce-src="https://mx.zsuite.at/home/hp@pawaq.at/Briefcase/Public/PARTNER_SERVICE_PROVIDER_PRO.png"> <a target="_blank" href="http://mylearn.vmware.com/eCert.cfm?id_reg=13247170&rGUID=faaf8ca1-c1e9-43e8-9db3-23d24b5e6049&ccid=VMW-00590783E-00449851" data-mce-href="http://mylearn.vmware.com/eCert.cfm?id_reg=13247170&rGUID=faaf8ca1-c1e9-43e8-9db3-23d24b5e6049&ccid=VMW-00590783E-00449851"><img doc="Briefcase/Public/VCP-DCV-s.png" alt="VMware Certified Professional 5 - Data Center Virtualization" src="cid:ed408d81b3aaa2933aae6891ff92255efd674005@zimbra" data-mce-src="https://mx.zsuite.at/home/hp@pawaq.at/Briefcase/Public/VCP-DCV-s.png"></a> </div></td></tr><tr><td colspan="3" style="padding-top: 5px;" data-mce-style="padding-top: 5px;" align="left" valign="middle"><div style="text-align: center;" data-mce-style="text-align: center;">Lerchenfelder Straße 36/2 - 1080 Wien - Austria - Fn312475y - ATU64308378 - office@pawaq.at - www.pawaq.com</div></td></tr></tbody></table></div><div> </div></div></div></div></div></div></div></body></html>