Unsolved
3 Posts
0
1179
May 22nd, 2023 23:00
R730/PERC H730P: Regular disk resets
Hi all,
More-or-less weekly, most often during the RAID controller's patrol read task over the weekend, we get an email alert from the iDRAC saying:
Event Message: Disk 1 in Backplane 1 of Integrated RAID Controller 1 was reset. Date/Time: Sat, 06 May 2023 18:13:58 +0000 Severity: Informational Detailed Description: The physical device was reset. This is a normal part of operations and is not a cause for concern. Recommended Action: No response action is required. Message ID: PDR87 System Model: PowerEdge R730
The reset situation has also happened a few times when a patrol read is not in progress.
It is the same basic issue as in the following thread, but it started spontaneously, and we are using the original disks that shipped with the server:
The PERC log showed the following messages corresponding to the above event:
05/06/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=00 05/06/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=01 05/06/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=02 05/06/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=03 05/06/23 3:00:00: C0:EVT#05060-05/06/23 3:00:00: 39=Patrol Read started 05/06/23 8:03:44: C0:Bad Block Count for LD 0 is 0 05/06/23 18:13:51: C0:FPE TW bucket x00d6 expired, number of timedout IOs = x1 05/06/23 18:13:51: C0:FP IO Timedout mid 7c5 devHandle a 05/06/23 18:13:51: C0:DM_SetTMReqForDevH: tm request for deviceHandle[a] devid[1] path[0] tmRequired[1], tmActive[0], countReqTM[1] countActiveTM:0 flags:f1400005 devState:20 tmReqAlt:0 tmActAlt:0 05/06/23 18:13:51: C0:EVT#05061-05/06/23 18:13:51: 267=Command timeout on PD 01(e0x20/s1) Path 5000cca2512010e1, CDB: 8f 00 00 00 00 03 7d 45 a0 00 00 00 10 00 00 00 05/06/23 18:13:51: C0:DM_PL_UpdateTimeOutInfoForMid : Mid=7c5 having the dm io context has timed out 05/06/23 18:13:51: C0:DM_PL_AllocateTaskMgmtFrame: TM mid=ca4 pTaskMgmt=c0168a00 05/06/23 18:13:51: C1:PmuProcessInvDebug: a task managment is being issued on primary. Clean up the dev 1 wait queue 05/06/23 18:13:51: C0:MPT_ProcessTaskMgmtQueue: Task Mgmt Start Addr c0168a00 DevId[1] Index ca4 chip 0 type 3 numCmdIssued 35 C0:cQDepth :31 C1:cQDepth :0 devFlags:f1482005 state:20 devHdl:a 05/06/23 18:13:51: C0:EVT#05062-05/06/23 18:13:51: 268=PD 01(e0x20/s1) Path 5000cca2512010e1 reset (Type 03) 05/06/23 18:13:51: C0:MPT_TaskMgmtPostRoutine: TMIdx ca4 DevID[1] IOCStatus 0000 MsgAddr c0168a00 type 3 chip 0 devhandle a numCmdIssued_C0 2 numCmdIssued_C1 0 Qdepth_C0 0 Qdepth_C1 0 TermCount 31 DevWQC_C0 31 De vWQC_C1 0 ChipWQC_C0 0 ChipWQC_C1 0 retryCount 0 tmDevHandle:a flags: f1480005 05/06/23 18:13:51: C0:DevId [1] Reduce Queue Depth to 1 from 40 05/06/23 18:13:51: C0:DM_DevPathRemoveSM : devHandle[a] devId[1], path [0], currState [3] nextState [5] state [3], devState[20], devFlags[f1400005] curPath:0 removalState:3 C0:curQDepth:0 C1:curQDepth:0 devState: 20 05/06/23 18:13:51: C0:EVT#05063-05/06/23 18:13:51: 113=Unexpected sense: PD 01(e0x20/s1) Path 5000cca2512010e1, CDB: 8f 00 00 00 00 03 7d 45 a0 00 00 00 10 00 00 00, Sense: 6/29/02 05/06/23 18:13:51: C0:Raw Sense for PD 1: 70 00 06 00 00 00 00 18 00 00 00 00 29 02 00 00 00 00 00 00 f5 17 00 00 00 00 00 00 00 00 00 00 05/06/23 18:13:51: C0:DevId [1] Reduce Queue Depth recursive retry: maxQDepth 1 : maxDepthChanged 1 : curQDepth 0 05/06/23 18:13:51: C0:DevId [1] Reduce Queue Depth recursive retry: maxQDepth 1 : maxDepthChanged 1 : curQDepth 0 05/06/23 18:13:52: C0:iopiDiscoveryComplete SubSystem 2 Count 5 InitState 1 05/06/23 18:13:52: C0:iopiEvent: EVENT_SAS_DISCOVERY 05/06/23 18:13:52: C0:DM_HandleDiscEvent: Discovery started on Port 0 05/06/23 18:13:52: C0:iopiEvent: MPI2_EVENT_SAS_TOPOLOGY_CHANGE_LIST 05/06/23 18:13:52: C0:DM_HandleTopologyChgEvnt: PhysicalPort=0 NumberOfPhys=x08 NumEntries=x01 StartPhy=x0 05/06/23 18:13:52: C0:ExpStatus=x00 PhysicalPort=0 EnclosureHandle=x0001 Expander devHandle=x0000 05/06/23 18:13:52: C0:Phy changed - phy 00 devHandle 000a linkRate bb curLinkRate b 05/06/23 18:13:52: C0:DM_HandleTopologyChgEvnt: curr_lr=0xb, prev_lr=0xb, DM_DevMgrIsReady=1 05/06/23 18:13:52: C0:iopiEvent: EVENT_SAS_DISCOVERY 05/06/23 18:13:52: C0:DM_HandleDiscEvent: Discovery Completed on Port 0 05/06/23 18:13:52: C0: DM_DevNotifyRAID: Notify Done. Check for Removal 05/06/23 18:13:52: C0:DISM Complete and at the devmgrstate = 0x1e 05/06/23 18:14:03: C0:FPE TW bucket x00e2 expired, number of timedout IOs = x1 05/06/23 18:14:03: C0:FP IO Timedout mid 425 devHandle a 05/06/23 18:14:03: C0:DM_SetTMReqForDevH: tm request for deviceHandle[a] devid[1] path[0] tmRequired[1], tmActive[0], countReqTM[1] countActiveTM:0 flags:f1400005 devState:20 tmReqAlt:0 tmActAlt:0 05/06/23 18:14:03: C0:EVT#05064-05/06/23 18:14:03: 267=Command timeout on PD 01(e0x20/s1) Path 5000cca2512010e1, CDB: 8f 00 00 00 00 03 7d 45 a0 00 00 00 10 00 00 00 05/06/23 18:14:03: C0:DM_PL_UpdateTimeOutInfoForMid : Mid=425 having the dm io context has timed out 05/06/23 18:14:03: C0:DM_PL_AllocateTaskMgmtFrame: TM mid=ca5 pTaskMgmt=c0168b00 05/06/23 18:14:03: C1:PmuProcessInvDebug: a task managment is being issued on primary. Clean up the dev 1 wait queue 05/06/23 18:14:03: C0:MPT_ProcessTaskMgmtQueue: Task Mgmt Start Addr c0168b00 DevId[1] Index ca5 chip 0 type 3 numCmdIssued 2 C0:cQDepth :1 C1:cQDepth :0 devFlags:f1482005 state:20 devHdl:a 05/06/23 18:14:03: C0:EVT#05065-05/06/23 18:14:03: 268=PD 01(e0x20/s1) Path 5000cca2512010e1 reset (Type 03) 05/06/23 18:14:03: C0:prCallback: PR stopped on pd=01, msgStat=f0 05/06/23 18:14:03: C0:EVT#05066-05/06/23 18:14:03: 445=Patrol Read aborted on PD 01(e0x20/s1) 05/06/23 18:14:03: C0:MPT_TaskMgmtPostRoutine: TMIdx ca5 DevID[1] IOCStatus 0000 MsgAddr c0168b00 type 3 chip 0 devhandle a numCmdIssued_C0 1 numCmdIssued_C1 0 Qdepth_C0 0 Qdepth_C1 0 TermCount 1 DevWQC_C0 30 DevWQC_C1 0 ChipWQC_C0 0 ChipWQC_C1 0 retryCount 0 tmDevHandle:a flags: f1480005 05/06/23 18:14:03: C0:DevId [1] Reduce Queue Depth recursive retry: maxQDepth 1 : maxDepthChanged 1 : curQDepth 0 05/06/23 18:14:03: C0:DM_DevPathRemoveSM : devHandle[a] devId[1], path [0], currState [3] nextState [5] state [3], devState[20], devFlags[f1400005] curPath:0 removalState:3 C0:curQDepth:0 C1:curQDepth:0 devState:20 05/06/23 18:14:03: C0:EVT#05067-05/06/23 18:14:03: 113=Unexpected sense: PD 01(e0x20/s1) Path 5000cca2512010e1, CDB: 8a 00 00 00 00 02 c1 12 8f 80 00 00 00 78 00 00, Sense: 6/29/02 05/06/23 18:14:03: C0:Raw Sense for PD 1: 70 00 06 00 00 00 00 18 00 00 00 00 29 02 00 00 00 00 00 00 f5 17 00 00 00 00 00 00 00 00 00 00 05/06/23 18:14:03: C0:DevId [1] Reduce Queue Depth recursive retry: maxQDepth 1 : maxDepthChanged 1 : curQDepth 0 05/06/23 18:14:04: C0:DevId [1] Reduce Queue Depth recursive retry: maxQDepth 1 : maxDepthChanged 1 : curQDepth 0 05/06/23 18:14:04: C0:DevId [1] Restore Queue Depth to 40 05/06/23 18:14:04: C0:DM_RecRestoreQueueDepthOnSuccess :: Enabling FP on devHandle = a 05/06/23 18:14:04: C0:iopiDiscoveryComplete SubSystem 2 Count 6 InitState 1 05/06/23 18:14:04: C0:iopiEvent: EVENT_SAS_DISCOVERY 05/06/23 18:14:04: C0:DM_HandleDiscEvent: Discovery started on Port 0 05/06/23 18:14:04: C0:iopiEvent: MPI2_EVENT_SAS_TOPOLOGY_CHANGE_LIST 05/06/23 18:14:04: C0:DM_HandleTopologyChgEvnt: PhysicalPort=0 NumberOfPhys=x08 NumEntries=x01 StartPhy=x0 05/06/23 18:14:04: C0:ExpStatus=x00 PhysicalPort=0 EnclosureHandle=x0001 Expander devHandle=x0000 05/06/23 18:14:04: C0:Phy changed - phy 00 devHandle 000a linkRate bb curLinkRate b 05/06/23 18:14:04: C0:DM_HandleTopologyChgEvnt: curr_lr=0xb, prev_lr=0xb, DM_DevMgrIsReady=1 05/06/23 18:14:04: C0:iopiEvent: EVENT_SAS_DISCOVERY 05/06/23 18:14:04: C0:DM_HandleDiscEvent: Discovery Completed on Port 0 05/06/23 18:14:04: C0: DM_DevNotifyRAID: Notify Done. Check for Removal 05/06/23 18:14:04: C0:DISM Complete and at the devmgrstate = 0x1e 05/06/23 20:28:13: C0:prCallback: PR completed for pd=03 05/06/23 20:28:13: C0:Bad Block Count for PD 3 is 0 05/06/23 21:04:01: C0:prCallback: PR completed for pd=00 05/06/23 21:04:01: C0:Bad Block Count for PD 0 is 0 05/06/23 21:21:14: C0:prCallback: PR completed for pd=02 05/06/23 21:21:14: C0:Bad Block Count for PD 2 is 0 05/06/23 21:21:14: C0:PR cycle complete 05/06/23 21:21:14: C0:EVT#05068-05/06/23 21:21:14: 35=Patrol Read complete
Note that at that time the patrol read did not complete for the affected disk, but the next patrol read was completely successful:
05/13/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=00 05/13/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=01 05/13/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=02 05/13/23 3:00:00: C0:prDiskStart: starting Patrol Read on PD=03 05/13/23 3:00:00: C0:EVT#05069-05/13/23 3:00:00: 39=Patrol Read started 05/13/23 8:03:44: C0:Bad Block Count for LD 0 is 0 05/13/23 21:23:06: C0:prCallback: PR completed for pd=03 05/13/23 21:23:06: C0:Bad Block Count for PD 3 is 0 05/13/23 21:59:23: C0:prCallback: PR completed for pd=00 05/13/23 21:59:23: C0:Bad Block Count for PD 0 is 0 05/13/23 22:09:47: C0:prCallback: PR completed for pd=02 05/13/23 22:09:47: C0:Bad Block Count for PD 2 is 0 05/14/23 0:54:16: C0:prCallback: PR completed for pd=01 05/14/23 0:54:16: C0:Bad Block Count for PD 1 is 0 05/14/23 0:54:16: C0:PR cycle complete 05/14/23 0:54:16: C0:EVT#05070-05/14/23 0:54:16: 35=Patrol Read complete
Do these particular PERC log messages show cause for concern? Is there a suggested course of action to take?
This server is not currently under a support contract.
Any input would be much appreciated!
No Events found!
DELL-Erman O
Moderator
•
3K Posts
•
14.9K Points
0
May 23rd, 2023 05:00
Hi, please check your PERC H730P RAID controller, backplane, and disk firmware updates. Please check loose or faulty connections can cause intermittent issues. Make sure environmental conditions such as ambient temperature and dust are optimal. There may be an issue on PD01 or it's physical connection. Reset events stated PERC faced communicating with drive.
illogical_unit
3 Posts
0
June 13th, 2023 01:00
Thanks for your guidance, Erman.
So far we have tried re-seating the drive, but no luck. I think we'll try moving it to another bay next.
DELL-Erman O
Moderator
•
3K Posts
•
14.9K Points
0
June 13th, 2023 02:00
thanks for the info please update our community on how it goes.
illogical_unit
3 Posts
0
July 23rd, 2023 18:00
Despite one instance on the day after re-seating the drive, we've now gone 6 weeks without a drive reset, so it's looking good.
So it seems there was a bad connection, or maybe it was just the power cycle that resolved it (after several months of uptime).
illogical_unit2
1 Rookie
•
5 Posts
0
October 4th, 2023 01:45
After the 6 good weeks we had gone without receiving the mentioned notification, it started coming back weekly, until about two weeks ago, where we are receiving it almost every other day now.
We are thinking of moving the drive to another bay, after shutting the server down. Is there any other action to be taken after doing that, or would it be a plug-and-play?
After guidance would be appreciated!
illogical_unit2
1 Rookie
•
5 Posts
0
October 4th, 2023 04:35
Upon taking a deeper inspection at the iDRAC console, I can see that we have a total of 4 physical disks.
The one that is complaining has the following stats:
9123.50 GB
9123.50 GB
Whereas the remaining 3 disks have the following stats:
9123.50 GB
0 GB
I wonder if the discrepancy in "Available RAID Disk Space" between the complaining disk and the other has to do with the disk reset?
(edited)
illogical_unit2
1 Rookie
•
5 Posts
0
October 5th, 2023 06:10
@DELL-Young E
Hi Young,
I have just checked and as far as I can tell, all 4 of them are used in the RAID-6 configuration.
Thanks.
illogical_unit2
1 Rookie
•
5 Posts
0
October 6th, 2023 02:43
Hi @DELL-Marco B,
I am looking to move the hard drive to another slot. Before I do that, I would like to know if there's any other action needs to be taken, before and after moving, to ensure RAID continues to work, keeping the virtual drive intact?
Looking forward to your guidance, thanks.