vMware 6.5出现存储链路掉线，多路径失效，需要重新插拔光纤跳线才能恢复，求大神分析日志。。。

Question

某用户，使用ibm x3650 x5服务器运行esxi6.5虚拟化系统，后端NETAPP存储双控，中间两台博科6505，在服务器中多路径没问题，每条线两条路径正常。但是稳定运行一个月后，就会出现虚拟机丢失，链路断开，业务不能访问情况，需要重新插拔hba卡跳线才能恢复。
可疑情况：
1.esxi装在存储上
2.服务器两块hba卡，一块插在pcie x8 一块插在pcie x16 
3.hba卡固件冲突，升级固件程序（我研究了一下午不知道如何升级hba卡固件，请问升级驱动程序是否可以？）
hba卡型号是 emulex lpe12000 8GB 
附件是vmkernel.log和syslog,希望懂行的老哥帮忙瞧瞧是什么问题。
还有升级过hba卡的同学也给个思路。

Answer 1

T01:33:19.032Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x12 (0x439d009d6240, 0) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba2:C0:T0:L0" Failed: H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2018-05-09T01:33:19.032Z cpu10:66313)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T01:33:20.032Z cpu5:236419)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x12 failed <0/216> sid x010200, did x010400, oxid xffff iotag x8ff Time Out Returning Host Busy
2018-05-09T01:33:23.031Z cpu5:68735)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x28 failed <0/0> sid x010200, did x010400, oxid xffff iotag x8fc Time Out Returning Host Busy
2018-05-09T01:33:23.031Z cpu10:66313)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T01:33:29.401Z cpu5:236419)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd xa3 failed <0/0> sid x010200, did x010400, oxid xffff iotag x919 Abort Requested Host Abort Req
2018-05-09T01:33:29.401Z cpu17:430805)VMW_SATP_ALUA: satp_alua_issueCommandOnPath:669: Path "vmhba2:C0:T0:L0" (UP) command 0xa3 failed with status Timeout. H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:33:29.402Z cpu5:236419)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x12 failed <0/0> sid x010200, did x010400, oxid xffff iotag x931 Abort Requested Host Abort Req
2018-05-09T01:33:29.402Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3563: last error status from device naa.60a98000383035396e2b4942356a742f repeated 1 times
2018-05-09T01:33:29.402Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x12 (0x439d009d6240, 0) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba2:C0:T0:L0" Failed: H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2018-05-09T01:33:29.402Z cpu10:66313)ScsiDeviceIO: 2962: Cmd(0x439d009d6240) 0x12, CmdSN 0x5923e from world 0 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x22 0x76 0x6d.
2018-05-09T01:33:30.447Z cpu5:236419)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x12 failed <0/216> sid x010200, did x010400, oxid xffff iotag x910 Abort Requested Host Abort Req
2018-05-09T01:33:31.606Z cpu2:65792)HBX: 2958: 'NETAPP2': HB at offset 3821568 - Waiting for timed out HB:
2018-05-09T01:33:31.606Z cpu2:65792)  [HB state abcdef02 offset 3821568 gen 63 stampUS 2660590716643 uuid 5ac9921a-9b9d8d10-0323-5cf3fcdc3d4c jrnl <FB 13371200> drv 14.81 lockImpl 4 ip 192.168.13.8]
2018-05-09T01:33:33.202Z cpu5:69084)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x28 failed <0/0> sid x010200, did x010400, oxid xffff iotag x91e Abort Requested Host Abort Req
2018-05-09T01:33:33.202Z cpu10:66313)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T01:33:33.202Z cpu10:66313)ScsiDeviceIO: 2962: Cmd(0x439d00928ac0) 0x28, CmdSN 0xa3bb70 from world 0 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:33:33.855Z cpu15:432992)HBX: 2958: 'NETAPP2': HB at offset 3821568 - Waiting for timed out HB:
2018-05-09T01:33:33.855Z cpu15:432992)  [HB state abcdef02 offset 3821568 gen 63 stampUS 2660590716643 uuid 5ac9921a-9b9d8d10-0323-5cf3fcdc3d4c jrnl <FB 13371200> drv 14.81 lockImpl 4 ip 192.168.13.8]
2018-05-09T01:33:40.400Z cpu5:69084)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd xa3 failed <0/0> sid x010200, did x010400, oxid xffff iotag x8dc Abort Requested Host Abort Req
2018-05-09T01:33:40.400Z cpu24:430808)VMW_SATP_ALUA: satp_alua_issueCommandOnPath:669: Path "vmhba2:C0:T0:L0" (UP) command 0xa3 failed with status Timeout. H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:33:51.401Z cpu5:68956)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd xa3 failed <0/0> sid x010200, did x010400, oxid xffff iotag x94a Abort Requested Host Abort Req
2018-05-09T01:33:51.401Z cpu19:65885)VMW_SATP_ALUA: satp_alua_issueCommandOnPath:669: Path "vmhba2:C0:T0:L0" (UP) command 0xa3 failed with status Timeout. H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:33:51.884Z cpu16:67944)HBX: 2958: 'NETAPP2': HB at offset 3821568 - Waiting for timed out HB:
2018-05-09T01:33:51.884Z cpu16:67944)  [HB state abcdef02 offset 3821568 gen 63 stampUS 2660590716643 uuid 5ac9921a-9b9d8d10-0323-5cf3fcdc3d4c jrnl <FB 13371200> drv 14.81 lockImpl 4 ip 192.168.13.8]
2018-05-09T01:33:56.780Z cpu25:69398)Fil3: 8094: Max timeout retries (10) exceeded for caller Fil3_FileIO after 527 ms (status 'Timeout')
2018-05-09T01:33:56.780Z cpu25:69398)Cow: 1990: Sync IO issued on cow disk 'Vcenter-000001-delta.vmdk' failed with Timeout
2018-05-09T01:33:57.247Z cpu25:69398)HBX: 2958: 'NETAPP2': HB at offset 3821568 - Waiting for timed out HB:
2018-05-09T01:33:57.247Z cpu25:69398)  [HB state abcdef02 offset 3821568 gen 63 stampUS 2660590716643 uuid 5ac9921a-9b9d8d10-0323-5cf3fcdc3d4c jrnl <FB 13371200> drv 14.81 lockImpl 4 ip 192.168.13.8]
2018-05-09T01:34:02.029Z cpu5:68736)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x12 failed <0/217> sid x010200, did x010400, oxid xffff iotag x913 Time Out Returning Host Busy
2018-05-09T01:34:03.029Z cpu5:68735)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x28 failed <0/0> sid x010200, did x010400, oxid xffff iotag x8d4 Time Out Returning Host Busy
2018-05-09T01:34:03.029Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3563: last error status from device naa.60a98000383035396e2b4942356a742f repeated 1 times
2018-05-09T01:34:03.029Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x28 (0x43950bd1e2c0, 0) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba2:C0:T0:L0" Failed: H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2018-05-09T01:34:03.029Z cpu10:66313)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T01:34:03.029Z cpu10:66313)ScsiDeviceIO: 2927: Cmd(0x43950bd1e2c0) 0x28, CmdSN 0xa3bb71 from world 0 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:34:12.450Z cpu5:68956)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x12 failed <0/217> sid x010200, did x010400, oxid xffff iotag x904 Abort Requested Host Abort Req
2018-05-09T01:34:13.213Z cpu5:68956)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd x28 failed <0/0> sid x010200, did x010400, oxid xffff iotag x903 Abort Requested Host Abort Req
2018-05-09T01:34:13.213Z cpu10:66313)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x28 (0x43950bd1e2c0, 0) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba2:C0:T0:L0" Failed: H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2018-05-09T01:34:13.213Z cpu10:66313)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T01:34:13.213Z cpu10:66313)ScsiDeviceIO: 2962: Cmd(0x43950bd1e2c0) 0x28, CmdSN 0xa3bb71 from world 0 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:34:13.400Z cpu5:68956)lpfc: lpfc_handle_status:4937: 1:(0):3271: FCP cmd xa3 failed <0/0> sid x010200, did x010400, oxid xffff iotag x8d6 Abort Requested Host Abort Req
2018-05-09T01:34:13.400Z cpu23:430283)VMW_SATP_ALUA: satp_alua_issueCommandOnPath:669: Path "vmhba2:C0:T0:L0" (UP) command 0xa3 failed with status Timeout. H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T01:34:21.609Z cpu2:65792)Fil3: 8094: Max timeout retries (10) exceeded for caller Fil3_FileIO after 527 ms (status 'Timeout')
2018-05-09T01:34:21.609Z cpu2:65792)HBX: 2958: 'NETAPP2': HB at offset 3821568 - Waiting for timed out HB:

Answer 2

2018-05-09T03:48:56.814Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x2a (0x439d008d4e40, 236106) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba3:C0:T1:L0" Failed: H:0x2 D:0x8 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2018-05-09T03:48:56.814Z cpu16:66310)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.60a98000383035396e2b4942356a742f" state in doubt; requested fast path state update...
2018-05-09T03:48:56.814Z cpu16:66310)ScsiDeviceIO: 2927: Cmd(0x439d008d4e40) 0x2a, CmdSN 0x1 from world 236106 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x2 D:0x8 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T03:48:56.814Z cpu16:66310)ScsiDeviceIO: 2927: Cmd(0x439d0097f4c0) 0x2a, CmdSN 0x8000003e from world 69398 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0x2 D:0x8 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T03:48:56.822Z cpu16:66169)lpfc: lpfc_els_rcv_rscn:5700: 1:(0):0214 RSCN received Data: x220 x0 x4 x1
2018-05-09T03:48:56.822Z cpu16:66169)lpfc: lpfc_els_rcv_rscn:5710: 1:(0):5973 RSCN received event x0 : Address format x00 : DID x010400
2018-05-09T03:48:56.828Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3563: last error status from device naa.60a98000383035396e2b4942356a742f repeated 5 times
2018-05-09T03:48:56.828Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3617: Cmd 0x2a (0x439d008d4e40, 236106) to dev "naa.60a98000383035396e2b4942356a742f" on path "vmhba3:C0:T1:L0" Failed: H:0xc D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:NONE
2018-05-09T03:48:56.828Z cpu16:66310)ScsiDeviceIO: 2927: Cmd(0x439500f312c0) 0x2a, CmdSN 0x80000046 from world 68923 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0xc D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T03:48:56.828Z cpu16:66310)ScsiDeviceIO: 2927: Cmd(0x439d04c5d440) 0x28, CmdSN 0xa3f781 from world 69398 to dev "naa.60a98000383035396e2b4942356a742f" failed H:0xc D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2018-05-09T03:48:56.831Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 10 times
2018-05-09T03:48:56.848Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 20 times
2018-05-09T03:48:56.873Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 40 times
2018-05-09T03:48:56.928Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 80 times
2018-05-09T03:48:57.018Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 160 times
2018-05-09T03:48:57.177Z cpu16:66310)NMP: nmp_ThrottleLogForDevice:3546: last error status from device naa.60a98000383035396e2b4942356a742f repeated 320 times

Answer 3

http://www.talkwithtrend.com/Question/415607不知道如何上传附件，我在twt也提问了一样的问题，可以下载附件，附件为vmkernel全部日志。