MSA Storage
cancel
Showing results for 
Search instead for 
Did you mean: 

P2000 - SQL Server could not connect to SAN

 
HPP2000HELP
Occasional Visitor

P2000 - SQL Server could not connect to SAN

Hi, We had a period where our SQL Server could not connect to its DB hosted on our P2000 SAN.

 

We were getting iSCSI Errors like this on the SQL Server:

 

"Provider Name: iScsiPrt

The description for Event ID 129 from source iScsiPrt cannot be found.
Either the component that raises this event is not installed on your local
computer or the installation is corrupted. You can install or repair the
component on the local computer.

If the event originated on another computer, the display information had to
be saved with the event.

The following information was included with the event:

\Device\RaidPort1"

 

This outage lasted approx 17 minutes. Below are the logs from the controller during this period:

 

"10/27 14:47:18.049548 [0]TMF IId x0,pT x037e18e0,Lun x0001,Tag x3,CSN x0,pFcIob x039cb1e4
10/27 14:47:18.049592 w[0] Lun Reset - mid 0
10/27 14:47:18.049631 w[0]received TMF from id 0xEF: w[0]LUN_RESET
10/27 14:47:18.049713 scsi0 p0 DoTMF 11h i0 hl1 il2
10/27 14:47:18.049749 scsi0 LUR l2
10/27 14:47:18.049796 scsi0 qd=0 oqd=0
10/27 14:47:18.049832 scsi2 LUR l2
10/27 14:47:18.049875 scsi2 qd=0 oqd=0
10/27 14:47:18.049909 scsi4 LUR l2
10/27 14:47:18.049953 scsi4 qd=0 oqd=0
10/27 14:47:18.049987 scsi6 LUR l2
10/27 14:47:18.050030 scsi6 qd=0 oqd=0
10/27 14:47:18.050067 TMF: sent tmf=17 p0 native 0793e23a
10/27 14:47:18.050599 TMF: sent tmf done p0 native 0793e23a
10/27 14:47:18.050641 [0]TMF response 0x00, pTask 037e18e0
10/27 14:47:18.064809 [0]CmdSn Retry Discard2 IId x0 csn xffffffff Expsn x0 imm 1 op x42
10/27 14:47:18.064849 [0]TMF Completion pFcIob 039cb2a8 pTask 037e18e0
10/27 14:47:19.063243 [0]CmdSn Retry Discard2 IId x0 csn xffffffff Expsn x0 imm 0 op x1
10/27 14:47:19.063350 [1]U [0]FreeDDE x0 S:x21 C:xf0000 F:x0 Oid:x0 #Active:x1:x0
10/27 14:47:37.936267 [0] iqn.1991-05.com.microsoft:ded3168
10/27 14:47:37.936305 w[0]FCP LOGO Abort
10/27 14:47:37.936517 EIM invalidate oid=0 ch=0
10/27 14:47:37.938724 UpdateCfglimsInfo(0x1CE)
10/27 14:47:37.938961 UpdateCfglimsInfo totals: snaps=0 MVs=0 BSs=0 MSs=0 SBSs=0 PSPs=0
10/27 14:47:37.981754 DMS_RaidStateChange: start failover/initialization process
10/27 14:47:37.981987 dms_failoverThreadEntryFunctions: initialization start
10/27 14:47:37.982667 dms_failoverThreadEntryFunctions: initialization end
10/27 14:47:37.983928 BldCtrlrStruct update, 2 vdisk, 4 vol, 8 drvs
10/27 14:47:37.984165 CAPI CONFIGURATION CHANGE - reason = 31, ConfigSequenceNumber = 6567
10/27 14:47:37.984369 EMP0.0 500c0ff014d4633c LEDsOff
10/27 14:47:37.986392 [0]NewDDE x0 S:x23 C:x0 F:x0 Oid:xc0 #Active:x1:x0
10/27 14:47:37.988279 [0]CmdSn Initial2 IId x0 csn x0 Expsn x0 imm 1 op x43
10/27 14:47:37.988340 [0]Oid xc0->x0 DDE x0 #Active:x2:x0
10/27 14:47:37.988380 [0]DDE 0x0:Oid 0x0:Mid 0:Normal:IP 10.10.30.101 Isid 40 0001 37 0001
10/27 14:47:37.988417 [0] iqn.1991-05.com.microsoft:ded3168
10/27 14:47:37.989311 [0]New Initiator oid=0x0 ID=0x0000EF mid=0
10/27 14:47:37.989363 EIM iSCSI ch0 oid=0 nat=1 unknown
10/27 14:47:37.990722 [0]U UpdateCfglimsInfo(0x1CE)
10/27 14:47:37.993169 UpdateCfglimsInfo totals: snaps=0 MVs=0 BSs=0 MSs=0 SBSs=0 PSPs=0
10/27 14:47:38.009704 DMS_RaidStateChange: start failover/initialization process
10/27 14:47:38.009938 dms_failoverThreadEntryFunctions: initialization start
10/27 14:47:38.010620 dms_failoverThreadEntryFunctions: initialization end
10/27 14:47:38.011882 BldCtrlrStruct update, 2 vdisk, 4 vol, 8 drvs
10/27 14:47:38.012118 CAPI CONFIGURATION CHANGE - reason = 30, ConfigSequenceNumber = 6569
10/27 14:47:38.040857 [1]U [1]U [1]U [1]U [1]U [1]U [1]U [0]U [0]U [0]U [0]U [0]U [0]U [0]U EMP1.1 500c0ff01adfe13c LEDsOff
10/27 14:47:38.471371 EMP0.0 500c0ff014d4633c LEDsOff
10/27 14:47:38.714655 EMP1.1 500c0ff01adfe13c LEDsOff
10/27 14:48:00.345147 SpareDriveArrayUpdate - updating spares list...
10/27 14:48:00.345199 SpareDriveArrayUpdate - END - SpareDriveCount:0
10/27 15:00:02.650181 SCAP: bad running time 612607 (capPercent=94)
10/27 15:00:02.650244 SCAP: Percent=94, tT=612640, sT=33 at avT=19
10/27 15:00:18.021080 [1]TMF IId x1,pT x03a14080,Lun x0001,Tag x2,CSN x0,pFcIob x03c0dcec
10/27 15:00:18.021124 w[1] Lun Reset - mid 0
10/27 15:00:18.021163 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:00:18.021245 scsi2 p1 DoTMF 11h i0 hl1 il2
10/27 15:00:18.021281 scsi2 LUR l2
10/27 15:00:18.021328 scsi2 qd=0 oqd=0
10/27 15:00:18.021364 scsi0 LUR l2
10/27 15:00:18.021407 scsi0 qd=0 oqd=0
10/27 15:00:18.021441 scsi4 LUR l2
10/27 15:00:18.021485 scsi4 qd=0 oqd=0
10/27 15:00:18.021519 scsi6 LUR l2
10/27 15:00:18.021563 scsi6 qd=0 oqd=0
10/27 15:00:18.021598 TMF: sent tmf=17 p1 native 07c1254e
10/27 15:00:18.022166 TMF: sent tmf done p1 native 07c1254e
10/27 15:00:18.022207 [1]TMF response 0x00, pTask 03a14080
10/27 15:00:18.223748 [1]TMF Completion pFcIob 03c0ddb0 pTask 03a14080
10/27 15:00:19.035039 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:00:27.038391 [1]TMF IId x1,pT x03a14da0,Lun x0003,Tag x4,CSN x0,pFcIob x03c0c92c
10/27 15:00:27.038434 w[1] Lun Reset - mid 0
10/27 15:00:27.038473 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:00:27.038556 scsi2 p1 DoTMF 11h i0 hl3 il4
10/27 15:00:27.038591 scsi2 LUR l4
10/27 15:00:27.038639 scsi2 qd=0 oqd=0
10/27 15:00:27.038675 scsi0 LUR l4
10/27 15:00:27.038718 scsi0 qd=0 oqd=0
10/27 15:00:27.038753 scsi4 LUR l4
10/27 15:00:27.038797 scsi4 qd=0 oqd=0
10/27 15:00:27.038831 scsi6 LUR l4
10/27 15:00:27.038874 scsi6 qd=0 oqd=0
10/27 15:00:27.038910 TMF: sent tmf=17 p1 native 07b4fa46
10/27 15:00:27.039563 TMF: sent tmf done p1 native 07b4fa46
10/27 15:00:27.039605 [1]TMF response 0x00, pTask 03a14da0
10/27 15:00:27.256669 [1]TMF Completion pFcIob 03c0c9f0 pTask 03a14da0
10/27 15:00:28.052118 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:01:19.018727 [1]TMF IId x1,pT x03a15940,Lun x0001,Tag x6,CSN x0,pFcIob x03c00624
10/27 15:01:19.018772 w[1] Lun Reset - mid 0
10/27 15:01:19.018811 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:01:19.018895 scsi2 p1 DoTMF 11h i0 hl1 il2
10/27 15:01:19.018931 scsi2 LUR l2
10/27 15:01:19.018978 scsi2 qd=0 oqd=0
10/27 15:01:19.019014 scsi0 LUR l2
10/27 15:01:19.019057 scsi0 qd=0 oqd=0
10/27 15:01:19.019092 scsi4 LUR l2
10/27 15:01:19.019136 scsi4 qd=0 oqd=0
10/27 15:01:19.019170 scsi6 LUR l2
10/27 15:01:19.019213 scsi6 qd=0 oqd=0
10/27 15:01:19.019250 TMF: sent tmf=17 p1 native 07ba6f26
10/27 15:01:19.019826 TMF: sent tmf done p1 native 07ba6f26
10/27 15:01:19.019867 [1]TMF response 0x00, pTask 03a15940
10/27 15:01:19.221191 [1]TMF Completion pFcIob 03c006e8 pTask 03a15940
10/27 15:01:19.609429 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:01:28.035706 [1]TMF IId x1,pT x03a159a0,Lun x0003,Tag x8,CSN x0,pFcIob x03c35274
10/27 15:01:28.035750 w[1] Lun Reset - mid 0
10/27 15:01:28.035789 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:01:28.035871 scsi2 p1 DoTMF 11h i0 hl3 il4
10/27 15:01:28.035907 scsi2 LUR l4
10/27 15:01:28.035955 scsi2 qd=0 oqd=0
10/27 15:01:28.035990 scsi0 LUR l4
10/27 15:01:28.036034 scsi0 qd=0 oqd=0
10/27 15:01:28.036068 scsi4 LUR l4
10/27 15:01:28.036112 scsi4 qd=0 oqd=0
10/27 15:01:28.036146 scsi6 LUR l4
10/27 15:01:28.036189 scsi6 qd=0 oqd=0
10/27 15:01:28.036226 TMF: sent tmf=17 p1 native 07bcc7ce
10/27 15:01:28.036758 TMF: sent tmf done p1 native 07bcc7ce
10/27 15:01:28.036799 [1]TMF response 0x00, pTask 03a159a0
10/27 15:01:28.253790 [1]TMF Completion pFcIob 03c35338 pTask 03a159a0
10/27 15:01:29.049588 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:02:19.033863 [1]TMF IId x1,pT x03a19960,Lun x0001,Tag xa,CSN x0,pFcIob x03c247d4
10/27 15:02:19.033909 w[1] Lun Reset - mid 0
10/27 15:02:19.033948 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:02:19.034031 scsi2 p1 DoTMF 11h i0 hl1 il2
10/27 15:02:19.034067 scsi2 LUR l2
10/27 15:02:19.034114 scsi2 qd=0 oqd=0
10/27 15:02:19.034150 scsi0 LUR l2
10/27 15:02:19.034193 scsi0 qd=0 oqd=0
10/27 15:02:19.034228 scsi4 LUR l2
10/27 15:02:19.034272 scsi4 qd=0 oqd=0
10/27 15:02:19.034306 scsi6 LUR l2
10/27 15:02:19.034350 scsi6 qd=0 oqd=0
10/27 15:02:19.034386 TMF: sent tmf=17 p1 native 07abc18e
10/27 15:02:19.034958 TMF: sent tmf done p1 native 07abc18e
10/27 15:02:19.034999 [1]TMF response 0x00, pTask 03a19960
10/27 15:02:19.235840 [1]TMF Completion pFcIob 03c24898 pTask 03a19960
10/27 15:02:20.047069 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:02:29.048488 [1]TMF IId x1,pT x03a199c0,Lun x0003,Tag xc,CSN x0,pFcIob x03bf6f8c
10/27 15:02:29.048533 w[1] Lun Reset - mid 0
10/27 15:02:29.048572 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:02:29.048655 scsi2 p1 DoTMF 11h i0 hl3 il4
10/27 15:02:29.048691 scsi2 LUR l4
10/27 15:02:29.048739 scsi2 qd=0 oqd=0
10/27 15:02:29.048774 scsi0 LUR l4
10/27 15:02:29.048818 scsi0 qd=0 oqd=0
10/27 15:02:29.048853 scsi4 LUR l4
10/27 15:02:29.048896 scsi4 qd=0 oqd=0
10/27 15:02:29.048931 scsi6 LUR l4
10/27 15:02:29.048974 scsi6 qd=0 oqd=0
10/27 15:02:29.049010 TMF: sent tmf=17 p1 native 07ba5336
10/27 15:02:29.049547 TMF: sent tmf done p1 native 07ba5336
10/27 15:02:29.049589 [1]TMF response 0x00, pTask 03a199c0
10/27 15:02:29.267155 [1]TMF Completion pFcIob 03bf7050 pTask 03a199c0
10/27 15:02:30.062468 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:03:20.030529 [1]TMF IId x1,pT x03a1aa40,Lun x0001,Tag xe,CSN x0,pFcIob x03bfe60c
10/27 15:03:20.030573 w[1] Lun Reset - mid 0
10/27 15:03:20.030612 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:03:20.030696 scsi2 p1 DoTMF 11h i0 hl1 il2
10/27 15:03:20.030731 scsi2 LUR l2
10/27 15:03:20.030779 scsi2 qd=0 oqd=0
10/27 15:03:20.030815 scsi0 LUR l2
10/27 15:03:20.030858 scsi0 qd=0 oqd=0
10/27 15:03:20.030893 scsi4 LUR l2
10/27 15:03:20.030936 scsi4 qd=0 oqd=0
10/27 15:03:20.030970 scsi6 LUR l2
10/27 15:03:20.031014 scsi6 qd=0 oqd=0
10/27 15:03:20.031050 TMF: sent tmf=17 p1 native 07c014ea
10/27 15:03:20.031622 TMF: sent tmf done p1 native 07c014ea
10/27 15:03:20.031662 [1]TMF response 0x00, pTask 03a1aa40
10/27 15:03:20.032001 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:03:20.032041 [1]TMF Completion pFcIob 03bfe6d0 pTask 03a1aa40
10/27 15:03:30.046303 [1]TMF IId x1,pT x03a1aaa0,Lun x0003,Tag x10,CSN x0,pFcIob x03c0d094
10/27 15:03:30.046348 w[1] Lun Reset - mid 0
10/27 15:03:30.046387 w[1]received TMF from id 0xEF: w[1]LUN_RESET
10/27 15:03:30.046471 scsi2 p1 DoTMF 11h i0 hl3 il4
10/27 15:03:30.046506 scsi2 LUR l4
10/27 15:03:30.046554 scsi2 qd=0 oqd=0
10/27 15:03:30.046589 scsi0 LUR l4
10/27 15:03:30.046632 scsi0 qd=0 oqd=0
10/27 15:03:30.046667 scsi4 LUR l4
10/27 15:03:30.046710 scsi4 qd=0 oqd=0
10/27 15:03:30.046745 scsi6 LUR l4
10/27 15:03:30.046788 scsi6 qd=0 oqd=0
10/27 15:03:30.046824 TMF: sent tmf=17 p1 native 07b1bb22
10/27 15:03:30.047358 TMF: sent tmf done p1 native 07b1bb22
10/27 15:03:30.047400 [1]TMF response 0x00, pTask 03a1aaa0
10/27 15:03:30.264603 [1]TMF Completion pFcIob 03c0d158 pTask 03a1aaa0
10/27 15:03:31.059942 [1]CmdSn Retry Discard2 IId x1 csn xffffffff Expsn x0 imm 0 op x1
10/27 15:04:20.029857 [1]FreeDDE x1 S:x21 C:xf0000 F:x0 Oid:x0 #Active:x1:x0
10/27 15:04:20.029899 [1] iqn.1991-05.com.microsoft:ded3168
10/27 15:04:20.029936 w[1]FCP LOGO Abort
10/27 15:04:20.030137 EIM invalidate oid=0 ch=1
10/27 15:04:20.032335 UpdateCfglimsInfo(0x1CE)
10/27 15:04:20.032570 UpdateCfglimsInfo totals: snaps=0 MVs=0 BSs=0 MSs=0 SBSs=0 PSPs=0
10/27 15:04:20.032716 [1]NewDDE x1 S:x23 C:x0 F:x0 Oid:xc0 #Active:x1:x0
10/27 15:04:20.033845 [1]CmdSn Initial2 IId x1 csn x0 Expsn x0 imm 1 op x43
10/27 15:04:20.033915 [1]Oid xc0->x0 DDE x1 #Active:x2:x0
10/27 15:04:20.033955 [1]DDE 0x1:Oid 0x0:Mid 0:Normal:IP 10.10.40.102 Isid 40 0001 37 0005
10/27 15:04:20.033992 [1] iqn.1991-05.com.microsoft:ded3168
10/27 15:04:20.034872 [1]New Initiator oid=0x0 ID=0x0000EF mid=0
10/27 15:04:20.034921 EIM iSCSI ch1 oid=0 nat=1 unknown
10/27 15:04:20.035372 [1]U [1]U BldCtrlrStruct update, 2 vdisk, 4 vol, 8 drvs
10/27 15:04:20.077210 DMS_RaidStateChange: start failover/initialization process
10/27 15:04:20.077438 dms_failoverThreadEntryFunctions: initialization start
10/27 15:04:20.078120 dms_failoverThreadEntryFunctions: initialization end
10/27 15:04:20.079378 BldCtrlrStruct update, 2 vdisk, 4 vol, 8 drvs
10/27 15:04:20.079616 CAPI CONFIGURATION CHANGE - reason = 31, ConfigSequenceNumber = 6571
10/27 15:04:20.081841 UpdateCfglimsInfo(0x1CE)
10/27 15:04:20.082077 UpdateCfglimsInfo totals: snaps=0 MVs=0 BSs=0 MSs=0 SBSs=0 PSPs=0
10/27 15:04:20.082382 EMP0.0 500c0ff014d4633c LEDsOff
10/27 15:04:20.098655 DMS_RaidStateChange: start failover/initialization process
10/27 15:04:20.099036 dms_failoverThreadEntryFunctions: initialization start
10/27 15:04:20.099714 dms_failoverThreadEntryFunctions: initialization end
10/27 15:04:20.109926 BldCtrlrStruct update, 2 vdisk, 4 vol, 8 drvs
10/27 15:04:20.110166 CAPI CONFIGURATION CHANGE - reason = 30, ConfigSequenceNumber = 6573
10/27 15:04:20.110411 [1]U [1]U [1]U [1]U [1]U [1]U EMP1.1 500c0ff01adfe13c LEDsOff
10/27 15:04:20.563849 EMP0.0 500c0ff014d4633c LEDsOff
10/27 15:04:20.804359 EMP1.1 500c0ff01adfe13c LEDsOff
10/27 15:04:30.420478 SpareDriveArrayUpdate - updating spares list...
10/27 15:04:30.420530 SpareDriveArrayUpdate - END - SpareDriveCount:0"

 

Please can someone take a look and help. If you need any further info just let me know.

 

Thanks