ESX/ESXi hosts randomly drop and reconnect iSCSI connections to an EqualLogic array
search cancel

ESX/ESXi hosts randomly drop and reconnect iSCSI connections to an EqualLogic array

book

Article ID: 344843

calendar_today

Updated On:

Products

VMware vSphere ESXi

Issue/Introduction

Symptoms:
  • VMware ESX and VMware ESXi hosts randomly drop and reconnect iSCSI connections to an EqualLogic array.
  • The guest operating system complains about write errors.
  • Virtual machines pause momentarily.
  • VMware vCenter Server reports one or more of these alarms:

    [Event alarm expression: Lost Storage Connectivity] OR
    [Event alarm expression: Lost Storage Path Redundancy] OR
    [Event alarm expression: Degraded Storage Path Redundancy]

     
  • The /var/log/messages (ESXi) or /var/log/vmkernel and /var/log/vmkiscsid.log (ESX) files contain messages similar to:

    Aug 4 11:11:15 iscsid: Target requests logout within 3 seconds for connection on iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 if=iscsi_vmk@vmk4 addr=192.168.50.10:3260 (TPGT:1 ISID:0x2) (T16 C0)
    Aug 4 11:11:15 iscsid: Target requests logout within 3 seconds for connection on iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 if=iscsi_vmk@vmk5 addr=192.168.50.10:3260 (TPGT:1 ISID:0x3) (T16 C1)
    Aug 4 11:11:15 vmkernel: 96:23:14:25.707 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: vmhba33:CH:0 T:16 CN:0: Failed to receive data: Connection closed by peer
    Aug 4 11:11:15 vmkernel: 96:23:14:25.707 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Conn [CID: 0 L: 192.168.50.180:55088 R: 192.168.50.17:3260]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: vmhba33:CH:0 T:16 CN:0: Connection rx notifying failure: Failed to Receive. State=Online
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Conn [CID: 0 L: 192.168.50.180:55088 R: 192.168.50.17:3260]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba33:CH:0 T:16 CN:0: iSCSI connection is being marked "OFFLINE" (Event:6)
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu5:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 192.168.50.180:55088 R: 192.168.50.17:3260]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: vmhba33:CH:1 T:16 CN:0: Failed to receive data: Connection closed by peer
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Conn [CID: 0 L: 192.168.50.181:60274 R: 192.168.50.19:3260]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: vmhba33:CH:1 T:16 CN:0: Connection rx notifying failure: Failed to Receive. State=Online
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Conn [CID: 0 L: 192.168.50.181:60274 R: 192.168.50.19:3260]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba33:CH:1 T:16 CN:0: iSCSI connection is being marked "OFFLINE" (Event:6)
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:15 vmkernel: 96:23:14:25.708 cpu6:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 192.168.50.181:60274 R: 192.168.50.19:3260]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.968 cpu1:4811)iscsi_vmk: iscsivmk_ConnNetRegister: socket 0x4100a802d810 network resource pool netsched.pools.persist.iscsi associated
    Aug 4 11:11:18 vmkernel: 96:23:14:28.969 cpu3:4811)iscsi_vmk: iscsivmk_ConnNetRegister: socket 0x4100a81b3410 network resource pool netsched.pools.persist.iscsi associated
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: vmhba33:CH:0 T:16 CN:0: Failed to receive data: Connection closed by peer
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Conn [CID: 0 L: 192.168.50.180:52953 R: 192.168.50.10:3260]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: vmhba33:CH:0 T:16 CN:0: Connection rx notifying failure: Failed to Receive. State=Bound
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.985 cpu3:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Conn [CID: 0 L: 192.168.50.180:52953 R: 192.168.50.10:3260]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: vmhba33:CH:1 T:16 CN:0: Failed to receive data: Connection closed by peer
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_ConnReceiveAtomic: Conn [CID: 0 L: 192.168.50.181:61817 R: 192.168.50.10:3260]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: vmhba33:CH:1 T:16 CN:0: Connection rx notifying failure: Failed to Receive. State=Bound
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:18 vmkernel: 96:23:14:28.988 cpu4:4811)iscsi_vmk: iscsivmk_ConnRxNotifyFailure: Conn [CID: 0 L: 192.168.50.181:61817 R: 192.168.50.10:3260]
    Aug 4 11:11:19 iscsid: Login authentication failed with target iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15
    Aug 4 11:11:19 vmkernel: 96:23:14:29.239 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba33:CH:0 T:16 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
    Aug 4 11:11:19 vmkernel: 96:23:14:29.239 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:19 vmkernel: 96:23:14:29.239 cpu4:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 192.168.50.180:52953 R: 192.168.50.10:3260]
    Aug 4 11:11:19 iscsid: Login authentication failed with target iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15
    Aug 4 11:11:19 vmkernel: 96:23:14:29.239 cpu6:4811)iscsi_vmk: iscsivmk_ConnNetRegister: socket 0x4100a802d810 network resource pool netsched.pools.persist.iscsi associated
    Aug 4 11:11:19 vmkernel: 96:23:14:29.240 cpu13:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba33:CH:1 T:16 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
    Aug 4 11:11:19 vmkernel: 96:23:14:29.240 cpu13:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:19 vmkernel: 96:23:14:29.240 cpu13:4811)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 192.168.50.181:61817 R: 192.168.50.10:3260]
    Aug 4 11:11:19 vmkernel: 96:23:14:29.240 cpu15:4811)iscsi_vmk: iscsivmk_ConnNetRegister: socket 0x4100a8044b00 network resource pool netsched.pools.persist.iscsi associated
    Aug 4 11:11:25 iscsid: connection 33:0 (iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 if=iscsi_vmk@vmk4 addr=192.168.50.10:3260 (TPGT:1 ISID:0x2) (T16 C0)) has recovered (2 attempts)
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu8:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: vmhba33:CH:0 T:16 CN:0: iSCSI connection is being marked "ONLINE"
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu8:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: Sess [ISID: 00023d000002 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu8:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: Conn [CID: 0 L: 192.168.50.180:52003 R: 192.168.50.23:3260]
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu12:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: vmhba33:CH:1 T:16 CN:0: iSCSI connection is being marked "ONLINE"
    Aug 4 11:11:25 iscsid: connection 34:0 (iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 if=iscsi_vmk@vmk5 addr=192.168.50.10:3260 (TPGT:1 ISID:0x3) (T16 C1)) has recovered (2 attempts)
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu12:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: Sess [ISID: 00023d000003 TARGET: iqn.2001-05.com.equallogic:0-8a0906-55495a003-88300ae08cd4cdd4-vm-storage15 TPGT: 1 TSIH: 0]
    Aug 4 11:11:25 vmkernel: 96:23:14:35.808 cpu12:4811)WARNING: iscsi_vmk: iscsivmk_StartConnection: Conn [CID: 0 L: 192.168.50.181:54776 R: 192.168.50.14:3260]


    Note:
    • The preceding log excerpts are only examples. Date, time, and environmental variables may vary depending on your environment.
    • This excerpt is an example from ESX 4.1. Logging in other versions of ESX and in ESXi may be different.
       


Environment

VMware ESX 4.0.x
VMware vSphere ESXi 6.0
VMware ESX Server 3.5.x
VMware ESXi 4.0.x Installable
VMware ESX 4.1.x
VMware ESX Server 3.0.x
VMware ESXi 4.0.x Embedded
VMware ESXi 4.1.x Embedded
VMware ESXi 3.5.x Installable
VMware ESXi 4.1.x Installable
VMware vSphere ESXi 5.0
VMware ESXi 3.5.x Embedded
VMware vSphere ESXi 5.1
VMware vSphere ESXi 5.5

Resolution

By design, an EqualLogic array performs connect load balancing operations as one of several methods of increasing overall performance. The array continuously monitors the workload at several levels, including at the individual network port. If the workload results in a sustained imbalance in network port throughput, individual iSCSI sessions can be re-directed to other network ports to more evenly distribute the workload amongst all active controllers and network ports.

In the log file example shown above, the EqualLogic array is performing a connection load balancing operation. When such a load balancing operation occurs, the array instructs the session to logout. When the session logs back in, it is redirected to connect to a different network interface on the array. This results in the network workload been moved from one network interface to another.

In circumstances where the array controllers are utilized beyond the capabilities, it is possible for the iSCSI login requests not to be completed in a timely fashion. In some cases, the guest operating system may log errors or become briefly unresponsive. In extreme cases, there may be sufficient disruption of IO to virtual machines to cause them to become unavailable. To minimize such occurrences, VMware recommends using EqualLogic’s MEM on vSphere 4.1and above with Enterprise or Enterprise Plus licensing. For more information on the Multipathing Extension Module (MEM), see Configuring and Installing the Equallogic Multipathing Extension Module.
 

In such configuration, the situation of a temporary path down, does not impact virtual machine IO or host storage operations against that datastore.

In a properly configured vSphere environment, where sufficient resources are available to meet all the workloads, such load balancing operations are non-disruptive and occur seamlessly in the background. For more information, see the EqualLogic technical report Dell EqualLogic PS Series Architecture: Load Balancers.
 
Note: The preceding links were correct as of October 14, 2014. If you find a link is broken, provide feedback and a VMware employee will update the link.


Additional Information