syslog DRDY ERR errors & smart Offline_Uncorrectable on my parity disk

April 18, 201115 yr

Hi Everyone,

My first post on here & im reaching out for someone to provide me some advice. I have been running unraid for a couple of years now.

I have an unraid 4.6 box with 4x sata hdds attached

HP DC7100 SFF workstation (2gb Ram - P4 2.8 w/ hyper threading enabled)

4x HDD running of a stand alone ATX power supply.

2x sata on motherboard headers

2x sata on 2 port PCI-E card (sil 3132 chipset - non raid firmware)

Drives:

md: import disk0: [8,48] (sdd) WDC WD10EADS-00P WD-WMAVU0430604 offset: 63 size: 976762552

md: import disk1: [8,16] (sdb) ST3500418AS 6VM09PAH offset: 63 size: 488386552

md: import disk2: [8,64] (sde) WDC WD10EARS-003 WD-WCAV5M522692 offset: 63 size: 976762552

md: import disk3: [8,0] (sda) ST3500418AS 6VM0QQZN offset: 63 size: 488386552

This rig had been humming along quite nicely until the other day when it suddenly went down - no console output, wouldnt respond to ping - nothing. Reluctantly I had to power it off - which I knew wouldnt save the syslogs (next in list of things to do is a central syslog server).

I have been running a parity check on the disks:

[pre]

STARTED; 4 disks in array.

Parity Check in progress

Total Size 976,762,552 KB

Current 324,056,144 (33.2%)

Speed 37,298 KB/sec

Finish 291.6 minutes

Sync Errors 0 (corrected)

[/pre]

And all looked to be humming along nicely - no sync errors, drive temps ok etc, but I am seeing reads & writes on the disks .... not sure if this is normal - I would assume that if all was ok, it wouldnt need to be writing data back to the disk ?

[pre]

Status Disk Mounted Device Model/Serial Temp Reads Writes Errors Size Used %Used Free

OK parity /dev/sdd 00P8B0_WD-WMAVU0430604 26°C 1359879 13882

OK /dev/md1 /mnt/disk1 /dev/sdb ST3500418AS_6VM09PAH 24°C 987768 5 500.09G 446.09G 90% 54.01G

OK /dev/md2 /mnt/disk2 /dev/sde 003_WD-WCAV5M522692 26°C 1675803 13769 1.00T 442.78G 45% 557.39G

OK /dev/md3 /mnt/disk3 /dev/sda ST3500418AS_6VM0QQZN 26°C 990024 5 500.09G 434.77G 87% 65.32G

Total: 2.00T 1.32T 66% 676.72G

[/pre]

If this writing is normal - im not too fussed about it & I will trust your advice on the data integrity if you tell me its ok.

My main concern on this is the syslog entries I am seeing

[pre]

Apr 18 19:42:37 storage kernel: ata3.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0

Apr 18 19:42:37 storage kernel: ata3.00: BMDMA stat 0x25

Apr 18 19:42:37 storage kernel: ata3.00: failed command: READ DMA EXT

Apr 18 19:42:37 storage kernel: ata3.00: cmd 25/00:f0:ef:fa:05/00:02:19:00:00/e0 tag 0 dma 385024 in

Apr 18 19:42:37 storage kernel: res 51/40:7f:5e:fc:05/40:01:19:00:00/e0 Emask 0x9 (media error)

Apr 18 19:42:37 storage kernel: ata3.00: status: { DRDY ERR }

Apr 18 19:42:37 storage kernel: ata3.00: error: { UNC }

Apr 18 19:42:37 storage kernel: ata3.00: configured for UDMA/133

Apr 18 19:42:37 storage kernel: ata3: EH complete

Apr 18 19:56:14 storage kernel: ata3.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0

Apr 18 19:56:14 storage kernel: ata3.00: BMDMA stat 0x25

Apr 18 19:56:14 storage kernel: ata3.00: failed command: READ DMA EXT

Apr 18 19:56:14 storage kernel: ata3.00: cmd 25/00:58:8f:c0:24/00:03:1c:00:00/e0 tag 0 dma 438272 in

Apr 18 19:56:14 storage kernel: res 51/40:17:c0:c3:24/40:00:1c:00:00/e0 Emask 0x9 (media error)

Apr 18 19:56:14 storage kernel: ata3.00: status: { DRDY ERR }

Apr 18 19:56:14 storage kernel: ata3.00: error: { UNC }

Apr 18 19:56:14 storage kernel: ata3.00: configured for UDMA/133

Apr 18 19:56:14 storage kernel: ata3: EH complete

Apr 18 20:34:17 storage kernel: ata3.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0

Apr 18 20:34:17 storage kernel: ata3.00: BMDMA stat 0x25

Apr 18 20:34:17 storage kernel: ata3.00: failed command: READ DMA EXT

Apr 18 20:34:17 storage kernel: ata3.00: cmd 25/00:58:0f:a3:f3/00:02:24:00:00/e0 tag 0 dma 307200 in

Apr 18 20:34:17 storage kernel: res 51/40:f7:6a:a4:f3/40:00:24:00:00/e0 Emask 0x9 (media error)

Apr 18 20:34:17 storage kernel: ata3.00: status: { DRDY ERR }

Apr 18 20:34:17 storage kernel: ata3.00: error: { UNC }

Apr 18 20:34:17 storage kernel: ata3.00: configured for UDMA/133

Apr 18 20:34:17 storage kernel: ata3: EH complete

[/pre]

*See attached syslog for more*

Now I have done a bit of googling & a lot of people have seen this with various linux kernels (including slackware) - but I just dont know if this is a bad issue or not ?

My thoughts on the server crash the other night are that if syslog was filling with all these errors - then maybe it ran out of memory & crashed the server ?

I have compared the smart values from a copy I had in January with the most recent one:

file diff below

[pre]

root@storage:/boot# diff devsdd_smart_20110108_1700 devsdd_smart_20110418_2100

13c13

< Local Time is: Sat Jan 8 06:02:10 2011 Local time zone must be set--see zic m

---

> Local Time is: Mon Apr 18 21:00:43 2011 EST

57,58c57,58

< 3 Spin_Up_Time 0x0027 183 180 021 Pre-fail Always - 5850

< 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 283

---

> 3 Spin_Up_Time 0x0027 182 180 021 Pre-fail Always - 5891

> 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 550

60,61c60,61

< 7 Seek_Error_Rate 0x002e 200 200 000 Old_age Always - 0

< 9 Power_On_Hours 0x0032 091 091 000 Old_age Always - 6707

---

> 7 Seek_Error_Rate 0x002e 100 253 000 Old_age Always - 0

> 9 Power_On_Hours 0x0032 088 088 000 Old_age Always - 8816

64,67c64,67

< 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 60

< 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 40

< 193 Load_Cycle_Count 0x0032 196 196 000 Old_age Always - 13678

< 194 Temperature_Celsius 0x0022 120 104 000 Old_age Always - 30

---

> 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 75

> 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 47

> 193 Load_Cycle_Count 0x0032 195 195 000 Old_age Always - 17257

> 194 Temperature_Celsius 0x0022 124 104 000 Old_age Always - 26

69,70c69,70

< 197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0

< 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 0

---

> 197 Current_Pending_Sector 0x0032 198 198 000 Old_age Always - 345

> 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 42

72c72

< 200 Multi_Zone_Error_Rate 0x0008 200 200 000 Old_age Offline - 0

---

> 200 Multi_Zone_Error_Rate 0x0008 170 139 000 Old_age Offline - 6135

75c75,105

< No Errors Logged

---

> Warning: ATA error count 37 inconsistent with error log pointer 1

>

> ATA Error Count: 37 (device log contains only the most recent five errors)

> CR = Command Register [HEX]

> FR = Features Register [HEX]

> SC = Sector Count Register [HEX]

> SN = Sector Number Register [HEX]

> CL = Cylinder Low Register [HEX]

> CH = Cylinder High Register [HEX]

> DH = Device/Head Register [HEX]

> DC = Device Command Register [HEX]

> ER = Error register [HEX]

> ST = Status register [HEX]

> Powered_Up_Time is measured from power on, and printed as

> DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,

> SS=sec, and sss=millisec. It "wraps" after 49.710 days.

>

> Error 37 occurred at disk power-on lifetime: 8814 hours (367 days + 6 hours)

> When the command that caused the error occurred, the device was active or idle.

>

> After command completion occurred, registers were:

> ER ST SC SN CL CH DH

> -- -- -- -- -- -- --

> 40 51 00 ff d8 0e ed Error: UNC at LBA = 0x0d0ed8ff = 219076863

>

> Commands leading to the command that caused the error were:

> CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name

> -- -- -- -- -- -- -- -- ---------------- --------------------

> c8 00 00 47 d8 0e ed 0a 01:06:03.593 READ DMA

> c8 00 f8 4f cf 0e ed 0a 01:06:03.532 READ DMA

> c8 00 d8 77 ce 0e ed 0a 01:06:03.531 READ DMA

[/pre]

If I read this correctly - I now have 42 bad sectors (up from 0 in Jan) .... bugger .... this green drive is only about a year old I think.

Seeing the bad sectors, and the syslog errors etc - im guessing its time to scrap this drive & get a shiny new one. This disk is my parity drive - which worries me more with the read & writes being performed during the current parity check - thoughts / comments ?

Well - if you have reached this part of the post, I thank you for your time & hope to have some feedback from the many expert unraid veterans that know far more than myself about the product.

syslog-2011-04-18.txt

devsdd_smart_20110108_1700.txt

devsdd_smart_20110418_2100.txt

Quote

April 18, 201115 yr

ata3=sdd. This disk appears to be having problems. I would replace it ASAP. Then you can pre-clear it a few times or run some other lengthy destructive test on it and see how it holds up.

Quote

April 19, 201115 yr

Author

Ok, so my parity check completed with no errors:

[pre]

STARTED, 4 disks in array. Parity is Valid:. Last parity check < 1 day ago with no sync errors.

(Last checked on 4/19/2011 4:23:22 AM, finding 0 errors.)

Model / Serial No. Temperature Size Free Reads Writes Errors

parity WDC_WD10EADS-00P_WD-WMAVU0430604 * 976,762,552 - 3,460,788 123,943 134

disk1 ST3500418AS_6VM09PAH * 488,386,552 52,740,104 1,391,068 5 0

disk2 WDC_WD10EARS-003_WD-WCAV5M522692 * 976,762,552 544,328,568 4,872,861 123,799 0

disk3 ST3500418AS_6VM0QQZN * 488,386,552 63,790,948 1,397,408 5 0

[/pre]

I am a little concerned about the number of writes ... 123,943 on the parity disk & 123,799 on the data disk.

The reason I am most concerned about this is in the syslog I also see a lot of read errors for my parity disk;

[pre]