vSphere Hypervisor with iSCSI FreeNAS - Connectivity Issues

mune3b

Cadet
Joined
May 7, 2019
Messages
5
Greetings,
This is a lab environment. ESXi 6.7 version is running on Dell R710 SFF Server. We created a storage on another Dell R710 LFF with a capacity of 8 TB one volume and 5 TB one volume as virtual disks. Using 5 TB virtual disk and FreeNAS we created an iSCSI Target on top of it. Now we are trying to setup the iSCSI storage and datastore as one Dell R710 SFF is acting as initiator and other Dell R710 LFF acting as a target.

Initiator (10.39.130.35) Dell R710 SFF specifications:
vCPUs 12 with 96 GB RAM
VMKernal2 with MTU 9000 and vDS with MTU of 9000

Target (10.39.130.222 iqn.2005-10.org.freenas.ctl:all-esxi) Dell R710 LFF specifications:
vCPUs 8 and 128 GB RAM
FreeNAS with em1 and MTU of 9000

Issue: The iSCSI Target is getting timeout and Disk is getting ONLINE and OFFLINE intermittently
Below are the logs of esxi vmkernal.log



[root@esxi1:~] cat /var/log/vmkernel.log
2019-05-07T17:48:32.912Z cpu4:2247842)Vol3: 1255: Could not open device '5cc6f8b0-8e513860-6903-0026b93f7b73' for volume open: Failure
2019-05-07T17:48:32.912Z cpu4:2247842)LVM: 5919: Could not open device naa.6589cfc000000f7547481ec53d72549e:1, vol [5cc6f8b0-8e513860-6903-0026b93f7b73, 5cc6f8b0-8e513860-6903-0026b93f7b73, 1]: LVM device unreachable
2019-05-07T17:48:32.912Z cpu4:2247842)Vol3: 1255: Could not open device '5cc6f8b0-8e513860-6903-0026b93f7b73' for volume open: Failure
2019-05-07T17:48:32.912Z cpu4:2247842)LVM: 5919: Could not open device naa.6589cfc000000f7547481ec53d72549e:1, vol [5cc6f8b0-8e513860-6903-0026b93f7b73, 5cc6f8b0-8e513860-6903-0026b93f7b73, 1]: LVM device unreachable
2019-05-07T17:48:32.912Z cpu4:2247842)FSS: 6092: No FS driver claimed device '5cc6f8b0-8e513860-6903-0026b93f7b73': No filesystem on the device
2019-05-07T17:48:32.918Z cpu0:2098497)PLOG: PLOGOpenDevice:4346: Disk handle open failure for device naa.6782bcb05bcabf0021f7e31c06bb079d:2, status:Busy
2019-05-07T17:48:32.919Z cpu0:2098497)PLOG: PLOGInitAndAnnounceMD:7958: Successfully announced VSAN MD (naa.6782bcb05bcabf0021f7e31c06bb079d:2) with UUID: 5259f2c5-80bd-17b5-20c5-77b4fd68b317. kt 1, en 0, enC 0.
2019-05-07T17:48:32.922Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.922Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.922Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16b2 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.933Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.933Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.933Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16b4 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.942Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.942Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.942Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16b6 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.954Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.954Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.954Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16b8 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.965Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.965Z cpu9:2247840)WARNING: NFS: 1227: Invalid volume UUID mpx.vmhba1:C0:T0:L0
2019-05-07T17:48:32.965Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.965Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16ba from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.976Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.977Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.977Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16bc from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:32.995Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:32.995Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:32.995Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16be from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.005Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.005Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:33.005Z cpu4:2097199)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16c5 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.017Z cpu4:2097199)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.017Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:33.017Z cpu9:2097204)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16c7 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.026Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.026Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:33.026Z cpu9:2097204)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16c9 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.038Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.038Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:33.038Z cpu9:2097204)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16cb from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.047Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.047Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x9e (0x459b98d365c0, 0) to dev "mpx.vmhba1:C0:T0:L0" on path "vmhba1:C0:T0:L0" Failed: H:0x7 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:48:33.047Z cpu9:2097204)ScsiDeviceIO: 3082: Cmd(0x459b98d365c0) 0x9e, CmdSN 0x16cd from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x7 D:0x0 P:0x0 Invalid sense data: 0x73 0x65 0x20.
2019-05-07T17:48:33.055Z cpu9:2097204)NMP: nmp_ThrottleLogForDevice:3727: last error status from device mpx.vmhba1:C0:T0:L0 repeated 2 times
2019-05-07T17:48:33.059Z cpu4:2247840)FSS: 6092: No FS driver claimed device 'mpx.vmhba1:C0:T0:L0': No filesystem on the device
2019-05-07T17:48:34.438Z cpu1:2097196)ScsiDeviceIO: 3068: Cmd(0x459b98d97dc0) 0x1a, CmdSN 0x1716 from world 0 to dev "t10.SanDisk00Ultra_USB_3.00000004C530000261203102470" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x24 0x0.
2019-05-07T17:48:34.543Z cpu4:2100460 opID=46e20a1f)VC: 4616: Device rescan time 10157 msec (total number of devices 6)
2019-05-07T17:48:34.543Z cpu4:2100460 opID=46e20a1f)VC: 4619: Filesystem probe time 1628 msec (devices probed 5 of 6)
2019-05-07T17:48:34.543Z cpu4:2100460 opID=46e20a1f)VC: 4621: Refresh open volume time 4 msec
2019-05-07T17:49:04.106Z cpu13:2097835)NMP: nmp_ResetDeviceLogThrottling:3569: Error status H:0x0 D:0x2 P:0x0 Sense Data: 0x2 0x3a 0x1 from dev "mpx.vmhba1:C0:T0:L0" occurred 1 times(of 1 commands)
2019-05-07T17:49:19.107Z cpu2:2098823)SunRPC: 1099: Destroying world 0x224cfe
2019-05-07T17:49:34.107Z cpu7:2097507)ScsiVmas: 804: Inquiry for VPD page 00 to device naa.6589cfc000000f7547481ec53d72549e failed with error No connection
2019-05-07T17:49:34.963Z cpu6:2097201)ScsiDeviceIO: 3068: Cmd(0x459b8aafa700) 0x1a, CmdSN 0x1722 from world 0 to dev "mpx.vmhba1:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x5 0x20 0x0.
2019-05-07T17:50:22.108Z cpu1:2098823)SunRPC: 1099: Destroying world 0x224dfd
2019-05-07T17:51:17.038Z cpu17:2097726)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1197: vmhba65:CH:0 T:1 CN:0: Connection tx notifying failure: Network Send Error. State=Online
2019-05-07T17:51:17.038Z cpu17:2097726)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1198: Sess [ISID: 00023d000001 TARGET: iqn.2005-10.org.freenas.ctl:all-esxi TPGT: 1 TSIH: 0]
2019-05-07T17:51:17.038Z cpu17:2097726)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1199: Conn [CID: 0 L: 10.39.130.35:10848 R: 10.39.130.222:3260]
2019-05-07T17:51:17.038Z cpu16:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:699: vmhba65:CH:0 T:1 CN:0: iSCSI connection is being marked "OFFLINE" (Event:6)
2019-05-07T17:51:17.038Z cpu16:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:700: Sess [ISID: 00023d000001 TARGET: iqn.2005-10.org.freenas.ctl:all-esxi TPGT: 1 TSIH: 0]
2019-05-07T17:51:17.038Z cpu16:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:701: Conn [CID: 0 L: 10.39.130.35:10848 R: 10.39.130.222:3260]
2019-05-07T17:51:17.041Z cpu18:2097547)WARNING: iscsi_vmk: iscsivmk_TaskMgmtIssue:633: vmhba65:CH:0 T:1 L:70 : Task mgmt "Abort Task" with itt=0xa47 (refITT=0xa3e) timed out.
2019-05-07T17:51:17.041Z cpu18:2097547)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x89 (0x459a40c1d280, 2097185) to dev "naa.6589cfc0000002975052862c22403cca" on path "vmhba65:C0:T1:L70" Failed: H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:51:17.041Z cpu18:2097547)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.6589cfc0000002975052862c22403cca" state in doubt; requested fast path state update...
2019-05-07T17:51:17.041Z cpu16:2097705)NMP: nmp_ThrottleLogForDevice:3781: Cmd 0x28 (0x45a37d996b40, 2098280) to dev "naa.6589cfc0000002975052862c22403cca" on path "vmhba65:C0:T1:L70" Failed: H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2019-05-07T17:51:17.041Z cpu18:2097547)ScsiDeviceIO: 3082: Cmd(0x459a40c1d280) 0x89, CmdSN 0x6d from world 2097185 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x35 0x20.
2019-05-07T17:51:17.041Z cpu16:2097705)ScsiDeviceIO: 3047: Cmd(0x45a37d996b40) 0x28, CmdSN 0x6c from world 2098280 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x78 0x32 0x20.
2019-05-07T17:51:17.042Z cpu16:2097211)ScsiDeviceIO: 3047: Cmd(0x459b98c86580) 0x28, CmdSN 0x6e from world 2100138 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x9 0x1a 0x45.
2019-05-07T17:51:17.106Z cpu16:2097705)NMP: nmp_ThrottleLogForDevice:3710: last error status from device naa.6589cfc0000002975052862c22403cca repeated 10 times
2019-05-07T17:51:17.110Z cpu8:2097505)LVM: 5748: Received APD EventType: APD_START (3) for device <naa.6589cfc0000002975052862c22403cca:3> (gen 17)
2019-05-07T17:51:17.110Z cpu8:2097505)LVM: 5356: Handling APD EventType: APD_START (3) for device <naa.6589cfc0000002975052862c22403cca:3> (unlocked, gen 17, cur apd state UNKNOWN, cur dev state 1)
2019-05-07T17:51:17.110Z cpu8:2097505)HBX: 6287: APD EventType: APD_START (3) for vol 'SAN-PRODUCTION'
2019-05-07T17:51:17.110Z cpu8:2097505)ScsiDevice: 5978: Device state of naa.6589cfc0000002975052862c22403cca set to APD_START; token num:1
2019-05-07T17:51:17.110Z cpu8:2097505)StorageApdHandler: 1203: APD start for 0x4304183eeea0 [naa.6589cfc0000002975052862c22403cca]
2019-05-07T17:51:17.110Z cpu0:2097490)StorageApdHandler: 419: APD start event for 0x4304183eeea0 [naa.6589cfc0000002975052862c22403cca]
2019-05-07T17:51:17.110Z cpu0:2097490)StorageApdHandlerEv: 110: Device or filesystem with identifier [naa.6589cfc0000002975052862c22403cca] has entered the All Paths Down state.
2019-05-07T17:51:17.112Z cpu2:2098234)WARNING: NMP: nmp_IssueCommandToDevice:5082: I/O could not be issued to device "naa.6589cfc0000002975052862c22403cca" due to Not found
2019-05-07T17:51:17.112Z cpu2:2098234)WARNING: NMP: nmp_DeviceRetryCommand:133: Device "naa.6589cfc0000002975052862c22403cca": awaiting fast path state update for failover with I/O blocked. No prior reservation exists on the device.
2019-05-07T17:51:17.112Z cpu2:2098234)WARNING: NMP: nmp_DeviceStartLoop:729: NMP Device "naa.6589cfc0000002975052862c22403cca" is blocked. Not starting I/O from device.
2019-05-07T17:51:18.040Z cpu12:2097547)ScsiDeviceIO: 3082: Cmd(0x459b98ce9f40) 0x89, CmdSN 0x6f from world 2097185 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x18 0x4 0x43.
2019-05-07T17:51:18.040Z cpu12:2097547)WARNING: NMP: nmp_DeviceStartLoop:729: NMP Device "naa.6589cfc0000002975052862c22403cca" is blocked. Not starting I/O from device.
2019-05-07T17:51:18.040Z cpu9:2097204)ScsiDeviceIO: 3032: Cmd(0x45a37d996b40) 0x28, CmdSN 0x6c from world 2098280 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x8 D:0x0 P:0x0
2019-05-07T17:51:18.041Z cpu9:2097204)ScsiDeviceIO: 3032: Cmd(0x459b98c86580) 0x28, CmdSN 0x6e from world 2100138 to dev "naa.6589cfc0000002975052862c22403cca" failed H:0x8 D:0x0 P:0x0
2019-05-07T17:51:18.041Z cpu12:2098281)HBX: 3033: 'SAN-PRODUCTION': HB at offset 3407872 - Waiting for timed out HB:
2019-05-07T17:51:18.041Z cpu12:2098281) [HB state abcdef02 offset 3407872 gen 37 stampUS 24703934162 uuid 5cd16571-5dd95f1e-0244-782bcb396c1f jrnl <FB 4> drv 24.82 lockImpl 4 ip 172.16.0.35]
2019-05-07T17:51:18.110Z cpu0:2097836)WARNING: NMP: nmpDeviceAttemptFailover:603: Retry world restore device "naa.6589cfc0000002975052862c22403cca" - no more commands to retry
2019-05-07T17:51:19.331Z cpu11:2248652)HBX: 3033: 'SAN-PRODUCTION': HB at offset 3407872 - Waiting for timed out HB:
2019-05-07T17:51:19.331Z cpu11:2248652) [HB state abcdef02 offset 3407872 gen 37 stampUS 24703934162 uuid 5cd16571-5dd95f1e-0244-782bcb396c1f jrnl <FB 4> drv 24.82 lockImpl 4 ip 172.16.0.35]
2019-05-07T17:51:20.146Z cpu22:2098046)iscsi_vmk: iscsivmk_ConnNetRegister:2170: socket 0x430bd54cc9f0 network resource pool netsched.pools.persist.iscsi associated
2019-05-07T17:51:20.146Z cpu22:2098046)iscsi_vmk: iscsivmk_ConnNetRegister:2198: socket 0x430bd54cc9f0 network tracker id 45045162 tracker.iSCSI.10.39.130.222 associated
2019-05-07T17:51:20.398Z cpu22:2098046)WARNING: iscsi_vmk: iscsivmk_StartConnection:880: vmhba65:CH:0 T:1 CN:0: iSCSI connection is being marked "ONLINE"
2019-05-07T17:51:20.398Z cpu22:2098046)WARNING: iscsi_vmk: iscsivmk_StartConnection:881: Sess [ISID: 00023d000001 TARGET: iqn.2005-10.org.freenas.ctl:all-esxi TPGT: 1 TSIH: 0]
2019-05-07T17:51:20.398Z cpu22:2098046)WARNING: iscsi_vmk: iscsivmk_StartConnection:882: Conn [CID: 0 L: 10.39.130.35:56605 R: 10.39.130.222:3260]
2019-05-07T17:51:20.541Z cpu2:2100195)WARNING: NMP: nmp_IssueCommandToDevice:5082: I/O could not be issued to device "naa.6589cfc0000002975052862c22403cca" due to Not found
2019-05-07T17:51:20.541Z cpu2:2100195)WARNING: NMP: nmp_DeviceRetryCommand:133: Device "naa.6589cfc0000002975052862c22403cca": awaiting fast path state update for failover with I/O blocked. No prior reservation exists on the device.
2019-05-07T17:51:20.542Z cpu2:2100195)WARNING: NMP: nmp_DeviceStartLoop:729: NMP Device "naa.6589cfc0000002975052862c22403cca" is blocked. Not starting I/O from device.
2019-05-07T17:51:21.114Z cpu5:2097505)ScsiDevice: 6000: Setting Device naa.6589cfc0000002975052862c22403cca state back to 0x2
2019-05-07T17:51:21.114Z cpu5:2097505)LVM: 5748: Received APD EventType: APD_EXIT (4) for device <naa.6589cfc0000002975052862c22403cca:3> (gen 18)
2019-05-07T17:51:21.114Z cpu5:2097505)LVM: 5356: Handling APD EventType: APD_EXIT (4) for device <naa.6589cfc0000002975052862c22403cca:3> (unlocked, gen 18, cur apd state APD_START, cur dev state 1)
2019-05-07T17:51:21.114Z cpu5:2097505)ScsiDevice: 6021: Device naa.6589cfc0000002975052862c22403cca is Out of APD; token num:1
2019-05-07T17:51:21.114Z cpu0:2097255)LVM: 5356: Handling APD EventType: APD_EXIT (4) for device <naa.6589cfc0000002975052862c22403cca:3> (locked, gen 18, cur apd state APD_START, cur dev state 1)
2019-05-07T17:51:21.114Z cpu1:2097836)WARNING: NMP: nmpDeviceAttemptFailover:640: Retry world failover device "naa.6589cfc0000002975052862c22403cca" - issuing command 0x459a40d93740
2019-05-07T17:51:24.463Z cpu16:2097211)NMP: nmpCompleteRetryForPath:327: Retry world recovered device "naa.6589cfc0000002975052862c22403cca"
2019-05-07T17:51:25.110Z cpu0:2098823)SunRPC: 3303: Synchronous RPC abort for client 0x4305cc2271c0 IP 10.39.115.222.0.111 proc 3 xid 0x439cd42c attempt 3 of 3
2019-05-07T17:51:25.110Z cpu0:2098823)SunRPC: 1099: Destroying world 0x224fd9
2019-05-07T17:51:29.332Z cpu1:2248652)HBX: 3033: 'SAN-PRODUCTION': HB at offset 3407872 - Waiting for timed out HB:
2019-05-07T17:51:29.332Z cpu1:2248652) [HB state abcdef02 offset 3407872 gen 37 stampUS 24703934162 uuid 5cd16571-5dd95f1e-0244-782bcb396c1f jrnl <FB 4> drv 24.82 lockImpl 4 ip 172.16.0.35]
2019-05-07T17:51:33.390Z cpu13:2098820)WARNING: LSOM: LSOMVsiGetVirstoInstanceStats:800: Throttled: Attempt to get Virsto stats on unsupported disk52256481-aa44-4783-d2f0-625461b41dfe
2019-05-07T17:51:39.335Z cpu1:2248652)HBX: 3033: 'SAN-PRODUCTION': HB at offset 3407872 - Waiting for timed out HB:
2019-05-07T17:51:39.335Z cpu1:2248652) [HB state abcdef02 offset 3407872 gen 37 stampUS 24703934162 uuid 5cd16571-5dd95f1e-0244-782bcb396c1f jrnl <FB 4> drv 24.82 lockImpl 4 ip 172.16.0.35]
2019-05-07T17:51:46.272Z cpu20:2097729)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1197: vmhba65:CH:0 T:1 CN:0: Connection tx notifying failure: Network Send Error. State=Online
2019-05-07T17:51:46.272Z cpu20:2097729)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1198: Sess [ISID: 00023d000001 TARGET: iqn.2005-10.org.freenas.ctl:all-esxi TPGT: 1 TSIH: 0]
2019-05-07T17:51:46.272Z cpu20:2097729)iscsi_vmk: iscsivmk_ConnTxNotifyFailure:1199: Conn [CID: 0 L: 10.39.130.35:56605 R: 10.39.130.222:3260]
2019-05-07T17:51:46.272Z cpu18:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:699: vmhba65:CH:0 T:1 CN:0: iSCSI connection is being marked "OFFLINE" (Event:6)
2019-05-07T17:51:46.272Z cpu18:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:700: Sess [ISID: 00023d000001 TARGET: iqn.2005-10.org.freenas.ctl:all-esxi TPGT: 1 TSIH: 0]
2019-05-07T17:51:46.272Z cpu18:2097688)WARNING: iscsi_vmk: iscsivmk_StopConnection:701: Conn [CID: 0 L: 10.39.130.35:56605 R: 10.39.130.222:3260]
2019-05-07T17:51:46.281Z cpu18:2097707)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.6589cfc0000002975052862c22403cca" state in doubt; requested fast path state update...
 

HoneyBadger

actually does care
Administrator
Moderator
iXsystems
Joined
Feb 6, 2014
Messages
5,112
It's Dell PERC H700 Integrated

As I suggested in a similar thread, the PERC H700 hardware RAID card is not a good match for ZFS and is likely the source of some/all of your woes with disk timeouts. I suggest using a PERC H200 or similar HBA.
 

mune3b

Cadet
Joined
May 7, 2019
Messages
5
Thanks for your input. Is there any reference link that you can share. Actually, I am looking forward towards the limiting factor that is causing this so it can become a proper evidence of H700 limitations
 

HoneyBadger

actually does care
Administrator
Moderator
iXsystems
Joined
Feb 6, 2014
Messages
5,112
Thanks for your input. Is there any reference link that you can share. Actually, I am looking forward towards the limiting factor that is causing this so it can become a proper evidence of H700 limitations

The "FreeNAS Worst Practices Guide" is probably a good executive summary of why not to use hardware RAID since that's #1 on the list.

https://www.ixsystems.com/blog/freenas-worst-practices/
 

mune3b

Cadet
Joined
May 7, 2019
Messages
5
Got it. What strange to me is that if the initator and target is same (on the same host). The datastores are visible and readable.
 
Top