PC Review


Reply
Thread Tools Rate Thread

Unrecovered read error - auto reallocate failed

 
 
Joe Pfeiffer
Guest
Posts: n/a
 
      18th Feb 2011
I've got a disk drive which seems to have turned up a bad block, but for
which auto reallocation is failing; so I'm looking for advice....

The disk is:

babs:525$ sudo smartctl -i /dev/sda
smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF INFORMATION SECTION ===
Model Family: Western Digital Caviar Green family
Device Model: WDC WD10EACS-00D6B0

Here's what I was seeing in my logs:

Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Currently unreadable (pending) sectors
Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Offline uncorrectable sectors

Took a look at the attributes:

babs:524$ sudo smartctl -A /dev/sda
smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF READ SMART DATA SECTION ===
SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
1 Raw_Read_Error_Rate 0x002f 200 199 051 Pre-fail Always - 37
3 Spin_Up_Time 0x0027 180 160 021 Pre-fail Always - 5966
4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 92
5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
7 Seek_Error_Rate 0x002e 100 253 051 Old_age Always - 0
9 Power_On_Hours 0x0032 075 075 000 Old_age Always - 18712
10 Spin_Retry_Count 0x0032 100 253 051 Old_age Always - 0
11 Calibration_Retry_Count 0x0032 100 253 051 Old_age Always - 0
12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 91
192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 17
193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 92
194 Temperature_Celsius 0x0022 115 100 000 Old_age Always - 35
196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 1
198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 1
199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
200 Multi_Zone_Error_Rate 0x0008 200 200 051 Old_age Offline - 1

It's my understanding that attribute 5 is the actual count of
reallocated sectors on the disk -- in this case, that no sectors had
been reallocated, so all the spare sectors on the disk are available.

Went to find the bad sector:

babs:530$ sudo smartctl -l selftest /dev/sda
smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF READ SMART DATA SECTION ===
SMART Self-test log structure revision number 1
Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
# 1 Extended offline Completed: read failure 90% 18711 387454402

Translated the LBA to the block in my filesystem and verified I couldn't
read it:

babs:537$ sudo dd if=/dev/sda1 of=/dev/null ibs=4096 skip=48431792
dd: reading `/dev/sda1': Input/output error
0+0 records in
0+0 records out
0 bytes (0 B) copied, 18.5663 s, 0.0 kB/s

(found the file it was in and deleted the file)

Now comes the part that's got me puzzled: wrote over the block to force
a reallocation:

babs:545$ sudo dd if=/dev/zero of=/dev/sda1 obs=4096 seek=48431792 count=1
dd: writing `/dev/sda1': Input/output error
1+0 records in
0+0 records out
0 bytes (0 B) copied, 19.1174 s, 0.0 kB/s

and here's what turned up in my log when I tried it:

Feb 18 10:55:07 babs kernel: [583184.036616] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:07 babs kernel: [583184.036622] ata1.00: BMDMA stat 0x24
Feb 18 10:55:07 babs kernel: [583184.036627] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:07 babs kernel: [583184.036636] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:07 babs kernel: [583184.036639] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:07 babs kernel: [583184.036644] ata1.00: status: { DRDY ERR }
Feb 18 10:55:07 babs kernel: [583184.036647] ata1.00: error: { UNC }
Feb 18 10:55:07 babs kernel: [583184.052596] ata1.00: configured for UDMA/133
Feb 18 10:55:07 babs kernel: [583184.052607] ata1: EH complete
Feb 18 10:55:10 babs kernel: [583186.992593] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:10 babs kernel: [583186.992598] ata1.00: BMDMA stat 0x24
Feb 18 10:55:10 babs kernel: [583186.992603] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:10 babs kernel: [583186.992612] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:10 babs kernel: [583186.992615] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:10 babs kernel: [583186.992619] ata1.00: status: { DRDY ERR }
Feb 18 10:55:10 babs kernel: [583186.992623] ata1.00: error: { UNC }
Feb 18 10:55:10 babs kernel: [583187.008573] ata1.00: configured for UDMA/133
Feb 18 10:55:10 babs kernel: [583187.008588] ata1: EH complete
Feb 18 10:55:13 babs kernel: [583189.947567] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:13 babs kernel: [583189.947573] ata1.00: BMDMA stat 0x24
Feb 18 10:55:13 babs kernel: [583189.947578] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:13 babs kernel: [583189.947586] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:13 babs kernel: [583189.947589] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:13 babs kernel: [583189.947594] ata1.00: status: { DRDY ERR }
Feb 18 10:55:13 babs kernel: [583189.947597] ata1.00: error: { UNC }
Feb 18 10:55:13 babs kernel: [583189.960532] ata1.00: configured for UDMA/133
Feb 18 10:55:13 babs kernel: [583189.960546] ata1: EH complete
Feb 18 10:55:16 babs kernel: [583192.903546] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:16 babs kernel: [583192.903552] ata1.00: BMDMA stat 0x24
Feb 18 10:55:16 babs kernel: [583192.903557] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:16 babs kernel: [583192.903565] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:16 babs kernel: [583192.903568] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:16 babs kernel: [583192.903573] ata1.00: status: { DRDY ERR }
Feb 18 10:55:16 babs kernel: [583192.903576] ata1.00: error: { UNC }
Feb 18 10:55:16 babs kernel: [583192.916509] ata1.00: configured for UDMA/133
Feb 18 10:55:16 babs kernel: [583192.916524] ata1: EH complete
Feb 18 10:55:19 babs kernel: [583196.002650] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:19 babs kernel: [583196.002656] ata1.00: BMDMA stat 0x24
Feb 18 10:55:19 babs kernel: [583196.002660] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:19 babs kernel: [583196.002669] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:19 babs kernel: [583196.002672] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:19 babs kernel: [583196.002676] ata1.00: status: { DRDY ERR }
Feb 18 10:55:19 babs kernel: [583196.002680] ata1.00: error: { UNC }
Feb 18 10:55:19 babs kernel: [583196.016642] ata1.00: configured for UDMA/133
Feb 18 10:55:19 babs kernel: [583196.016657] ata1: EH complete
Feb 18 10:55:22 babs kernel: [583198.958629] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 18 10:55:22 babs kernel: [583198.958634] ata1.00: BMDMA stat 0x24
Feb 18 10:55:22 babs kernel: [583198.958639] ata1.00: failed command: READ DMA EXT
Feb 18 10:55:22 babs kernel: [583198.958648] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
Feb 18 10:55:22 babs kernel: [583198.958651] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
Feb 18 10:55:22 babs kernel: [583198.958656] ata1.00: status: { DRDY ERR }
Feb 18 10:55:22 babs kernel: [583198.958659] ata1.00: error: { UNC }
Feb 18 10:55:22 babs kernel: [583198.972618] ata1.00: configured for UDMA/133
Feb 18 10:55:22 babs kernel: [583198.972632] sd 0:0:0:0: [sda] Unhandled sense code
Feb 18 10:55:22 babs kernel: [583198.972636] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Feb 18 10:55:22 babs kernel: [583198.972640] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor]
Feb 18 10:55:22 babs kernel: [583198.972646] Descriptor sense data with sense descriptors (in hex):
Feb 18 10:55:22 babs kernel: [583198.972649] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00
Feb 18 10:55:22 babs kernel: [583198.972659] 17 18 15 c2
Feb 18 10:55:22 babs kernel: [583198.972663] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed
Feb 18 10:55:22 babs kernel: [583198.972669] sd 0:0:0:0: [sda] CDB: Read(10): 28 00 17 18 15 bf 00 00 08 00
Feb 18 10:55:22 babs kernel: [583198.972679] end_request: I/O error, dev sda, sector 387454402
Feb 18 10:55:22 babs kernel: [583198.972697] ata1: EH complete
Feb 18 10:55:32 babs kernel: [583209.040031] powernow-k8: failing targ, change pending bit set

The line saying "Add. Sense: Unrecovered read error - auto reallocate
failed" is, of course, the most interesting....

And the -A attributes are unchanged. So... any thoughts?
--
This sig block for rent
 
Reply With Quote
 
 
 
 
Arno
Guest
Posts: n/a
 
      19th Feb 2011
I think it is the following:
387454402/8 = 48431800.25, i.e. I think you are not writing
the bad block at all, just the 8 sectors directly in front of it.
The OS or drive may then do an automated readahead from the write
position onwards (no additional commands in queue, so it has time
to optimize things) and get the error.

I would recommend overwriting 10MB or so around the error,
starting 5MB before or so.

Arno



Joe Pfeiffer <(E-Mail Removed)> wrote:
> I've got a disk drive which seems to have turned up a bad block, but for
> which auto reallocation is failing; so I'm looking for advice....


> The disk is:


> babs:525$ sudo smartctl -i /dev/sda
> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>
> === START OF INFORMATION SECTION ===
> Model Family: Western Digital Caviar Green family
> Device Model: WDC WD10EACS-00D6B0
>
> Here's what I was seeing in my logs:
>
> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Currently unreadable (pending) sectors
> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Offline uncorrectable sectors


> Took a look at the attributes:


> babs:524$ sudo smartctl -A /dev/sda
> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>
> === START OF READ SMART DATA SECTION ===
> SMART Attributes Data Structure revision number: 16
> Vendor Specific SMART Attributes with Thresholds:
> ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
> 1 Raw_Read_Error_Rate 0x002f 200 199 051 Pre-fail Always - 37
> 3 Spin_Up_Time 0x0027 180 160 021 Pre-fail Always - 5966
> 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 92
> 5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
> 7 Seek_Error_Rate 0x002e 100 253 051 Old_age Always - 0
> 9 Power_On_Hours 0x0032 075 075 000 Old_age Always - 18712
> 10 Spin_Retry_Count 0x0032 100 253 051 Old_age Always - 0
> 11 Calibration_Retry_Count 0x0032 100 253 051 Old_age Always - 0
> 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 91
> 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 17
> 193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 92
> 194 Temperature_Celsius 0x0022 115 100 000 Old_age Always - 35
> 196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
> 197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 1
> 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 1
> 199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
> 200 Multi_Zone_Error_Rate 0x0008 200 200 051 Old_age Offline - 1


> It's my understanding that attribute 5 is the actual count of
> reallocated sectors on the disk -- in this case, that no sectors had
> been reallocated, so all the spare sectors on the disk are available.


> Went to find the bad sector:


> babs:530$ sudo smartctl -l selftest /dev/sda
> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>
> === START OF READ SMART DATA SECTION ===
> SMART Self-test log structure revision number 1
> Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
> # 1 Extended offline Completed: read failure 90% 18711 387454402


> Translated the LBA to the block in my filesystem and verified I couldn't
> read it:
>
> babs:537$ sudo dd if=/dev/sda1 of=/dev/null ibs=4096 skip=48431792
> dd: reading `/dev/sda1': Input/output error
> 0+0 records in
> 0+0 records out
> 0 bytes (0 B) copied, 18.5663 s, 0.0 kB/s


> (found the file it was in and deleted the file)


> Now comes the part that's got me puzzled: wrote over the block to force
> a reallocation:


> babs:545$ sudo dd if=/dev/zero of=/dev/sda1 obs=4096 seek=48431792 count=1
> dd: writing `/dev/sda1': Input/output error
> 1+0 records in
> 0+0 records out
> 0 bytes (0 B) copied, 19.1174 s, 0.0 kB/s


> and here's what turned up in my log when I tried it:


> Feb 18 10:55:07 babs kernel: [583184.036616] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:07 babs kernel: [583184.036622] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:07 babs kernel: [583184.036627] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:07 babs kernel: [583184.036636] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:07 babs kernel: [583184.036639] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:07 babs kernel: [583184.036644] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:07 babs kernel: [583184.036647] ata1.00: error: { UNC }
> Feb 18 10:55:07 babs kernel: [583184.052596] ata1.00: configured for UDMA/133
> Feb 18 10:55:07 babs kernel: [583184.052607] ata1: EH complete
> Feb 18 10:55:10 babs kernel: [583186.992593] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:10 babs kernel: [583186.992598] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:10 babs kernel: [583186.992603] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:10 babs kernel: [583186.992612] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:10 babs kernel: [583186.992615] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:10 babs kernel: [583186.992619] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:10 babs kernel: [583186.992623] ata1.00: error: { UNC }
> Feb 18 10:55:10 babs kernel: [583187.008573] ata1.00: configured for UDMA/133
> Feb 18 10:55:10 babs kernel: [583187.008588] ata1: EH complete
> Feb 18 10:55:13 babs kernel: [583189.947567] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:13 babs kernel: [583189.947573] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:13 babs kernel: [583189.947578] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:13 babs kernel: [583189.947586] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:13 babs kernel: [583189.947589] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:13 babs kernel: [583189.947594] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:13 babs kernel: [583189.947597] ata1.00: error: { UNC }
> Feb 18 10:55:13 babs kernel: [583189.960532] ata1.00: configured for UDMA/133
> Feb 18 10:55:13 babs kernel: [583189.960546] ata1: EH complete
> Feb 18 10:55:16 babs kernel: [583192.903546] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:16 babs kernel: [583192.903552] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:16 babs kernel: [583192.903557] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:16 babs kernel: [583192.903565] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:16 babs kernel: [583192.903568] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:16 babs kernel: [583192.903573] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:16 babs kernel: [583192.903576] ata1.00: error: { UNC }
> Feb 18 10:55:16 babs kernel: [583192.916509] ata1.00: configured for UDMA/133
> Feb 18 10:55:16 babs kernel: [583192.916524] ata1: EH complete
> Feb 18 10:55:19 babs kernel: [583196.002650] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:19 babs kernel: [583196.002656] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:19 babs kernel: [583196.002660] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:19 babs kernel: [583196.002669] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:19 babs kernel: [583196.002672] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:19 babs kernel: [583196.002676] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:19 babs kernel: [583196.002680] ata1.00: error: { UNC }
> Feb 18 10:55:19 babs kernel: [583196.016642] ata1.00: configured for UDMA/133
> Feb 18 10:55:19 babs kernel: [583196.016657] ata1: EH complete
> Feb 18 10:55:22 babs kernel: [583198.958629] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Feb 18 10:55:22 babs kernel: [583198.958634] ata1.00: BMDMA stat 0x24
> Feb 18 10:55:22 babs kernel: [583198.958639] ata1.00: failed command: READ DMA EXT
> Feb 18 10:55:22 babs kernel: [583198.958648] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
> Feb 18 10:55:22 babs kernel: [583198.958651] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
> Feb 18 10:55:22 babs kernel: [583198.958656] ata1.00: status: { DRDY ERR }
> Feb 18 10:55:22 babs kernel: [583198.958659] ata1.00: error: { UNC }
> Feb 18 10:55:22 babs kernel: [583198.972618] ata1.00: configured for UDMA/133
> Feb 18 10:55:22 babs kernel: [583198.972632] sd 0:0:0:0: [sda] Unhandled sense code
> Feb 18 10:55:22 babs kernel: [583198.972636] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
> Feb 18 10:55:22 babs kernel: [583198.972640] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor]
> Feb 18 10:55:22 babs kernel: [583198.972646] Descriptor sense data with sense descriptors (in hex):
> Feb 18 10:55:22 babs kernel: [583198.972649] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00
> Feb 18 10:55:22 babs kernel: [583198.972659] 17 18 15 c2
> Feb 18 10:55:22 babs kernel: [583198.972663] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed
> Feb 18 10:55:22 babs kernel: [583198.972669] sd 0:0:0:0: [sda] CDB: Read(10): 28 00 17 18 15 bf 00 00 08 00
> Feb 18 10:55:22 babs kernel: [583198.972679] end_request: I/O error, dev sda, sector 387454402
> Feb 18 10:55:22 babs kernel: [583198.972697] ata1: EH complete
> Feb 18 10:55:32 babs kernel: [583209.040031] powernow-k8: failing targ, change pending bit set


> The line saying "Add. Sense: Unrecovered read error - auto reallocate
> failed" is, of course, the most interesting....


> And the -A attributes are unchanged. So... any thoughts?
> --
> This sig block for rent


--
Arno Wagner, Dr. sc. techn., Dipl. Inform., CISSP -- Email: (E-Mail Removed)
GnuPG: ID: 1E25338F FP: 0C30 5782 9D93 F785 E79C 0296 797F 6B50 1E25 338F
----
Cuddly UI's are the manifestation of wishful thinking. -- Dylan Evans
 
Reply With Quote
 
 
 
 
Joe Pfeiffer
Guest
Posts: n/a
 
      19th Feb 2011
Arno <(E-Mail Removed)> writes:

> I think it is the following:
> 387454402/8 = 48431800.25, i.e. I think you are not writing
> the bad block at all, just the 8 sectors directly in front of it.
> The OS or drive may then do an automated readahead from the write
> position onwards (no additional commands in queue, so it has time
> to optimize things) and get the error.


That shouldn't be it -- (387454402-63)/8 = 48431792.375
(the partition starts on sector 63, according to cfdisk). And, after
all, the write clearly fails, and I get a specific error message saying
it tried and failed to reallocate.

After I posted, it occurred to me that the drive may still be under
warranty. It turned out it is, so a new one is on its way. I'm still
curious about exactly what's going on, but the curiosity is much more
academic now!

> I would recommend overwriting 10MB or so around the error,
> starting 5MB before or so.
>
> Arno
>
>
>
> Joe Pfeiffer <(E-Mail Removed)> wrote:
>> I've got a disk drive which seems to have turned up a bad block, but for
>> which auto reallocation is failing; so I'm looking for advice....

>
>> The disk is:

>
>> babs:525$ sudo smartctl -i /dev/sda
>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>
>> === START OF INFORMATION SECTION ===
>> Model Family: Western Digital Caviar Green family
>> Device Model: WDC WD10EACS-00D6B0
>>
>> Here's what I was seeing in my logs:
>>
>> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Currently unreadable (pending) sectors
>> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Offline uncorrectable sectors

>
>> Took a look at the attributes:

>
>> babs:524$ sudo smartctl -A /dev/sda
>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>
>> === START OF READ SMART DATA SECTION ===
>> SMART Attributes Data Structure revision number: 16
>> Vendor Specific SMART Attributes with Thresholds:
>> ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
>> 1 Raw_Read_Error_Rate 0x002f 200 199 051 Pre-fail Always - 37
>> 3 Spin_Up_Time 0x0027 180 160 021 Pre-fail Always - 5966
>> 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 92
>> 5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
>> 7 Seek_Error_Rate 0x002e 100 253 051 Old_age Always - 0
>> 9 Power_On_Hours 0x0032 075 075 000 Old_age Always - 18712
>> 10 Spin_Retry_Count 0x0032 100 253 051 Old_age Always - 0
>> 11 Calibration_Retry_Count 0x0032 100 253 051 Old_age Always - 0
>> 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 91
>> 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 17
>> 193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 92
>> 194 Temperature_Celsius 0x0022 115 100 000 Old_age Always - 35
>> 196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
>> 197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 1
>> 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 1
>> 199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
>> 200 Multi_Zone_Error_Rate 0x0008 200 200 051 Old_age Offline - 1

>
>> It's my understanding that attribute 5 is the actual count of
>> reallocated sectors on the disk -- in this case, that no sectors had
>> been reallocated, so all the spare sectors on the disk are available.

>
>> Went to find the bad sector:

>
>> babs:530$ sudo smartctl -l selftest /dev/sda
>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>
>> === START OF READ SMART DATA SECTION ===
>> SMART Self-test log structure revision number 1
>> Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
>> # 1 Extended offline Completed: read failure 90% 18711 387454402

>
>> Translated the LBA to the block in my filesystem and verified I couldn't
>> read it:
>>
>> babs:537$ sudo dd if=/dev/sda1 of=/dev/null ibs=4096 skip=48431792
>> dd: reading `/dev/sda1': Input/output error
>> 0+0 records in
>> 0+0 records out
>> 0 bytes (0 B) copied, 18.5663 s, 0.0 kB/s

>
>> (found the file it was in and deleted the file)

>
>> Now comes the part that's got me puzzled: wrote over the block to force
>> a reallocation:

>
>> babs:545$ sudo dd if=/dev/zero of=/dev/sda1 obs=4096 seek=48431792 count=1
>> dd: writing `/dev/sda1': Input/output error
>> 1+0 records in
>> 0+0 records out
>> 0 bytes (0 B) copied, 19.1174 s, 0.0 kB/s

>
>> and here's what turned up in my log when I tried it:

>
>> Feb 18 10:55:07 babs kernel: [583184.036616] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:07 babs kernel: [583184.036622] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:07 babs kernel: [583184.036627] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:07 babs kernel: [583184.036636] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:07 babs kernel: [583184.036639] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:07 babs kernel: [583184.036644] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:07 babs kernel: [583184.036647] ata1.00: error: { UNC }
>> Feb 18 10:55:07 babs kernel: [583184.052596] ata1.00: configured for UDMA/133
>> Feb 18 10:55:07 babs kernel: [583184.052607] ata1: EH complete
>> Feb 18 10:55:10 babs kernel: [583186.992593] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:10 babs kernel: [583186.992598] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:10 babs kernel: [583186.992603] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:10 babs kernel: [583186.992612] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:10 babs kernel: [583186.992615] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:10 babs kernel: [583186.992619] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:10 babs kernel: [583186.992623] ata1.00: error: { UNC }
>> Feb 18 10:55:10 babs kernel: [583187.008573] ata1.00: configured for UDMA/133
>> Feb 18 10:55:10 babs kernel: [583187.008588] ata1: EH complete
>> Feb 18 10:55:13 babs kernel: [583189.947567] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:13 babs kernel: [583189.947573] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:13 babs kernel: [583189.947578] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:13 babs kernel: [583189.947586] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:13 babs kernel: [583189.947589] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:13 babs kernel: [583189.947594] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:13 babs kernel: [583189.947597] ata1.00: error: { UNC }
>> Feb 18 10:55:13 babs kernel: [583189.960532] ata1.00: configured for UDMA/133
>> Feb 18 10:55:13 babs kernel: [583189.960546] ata1: EH complete
>> Feb 18 10:55:16 babs kernel: [583192.903546] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:16 babs kernel: [583192.903552] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:16 babs kernel: [583192.903557] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:16 babs kernel: [583192.903565] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:16 babs kernel: [583192.903568] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:16 babs kernel: [583192.903573] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:16 babs kernel: [583192.903576] ata1.00: error: { UNC }
>> Feb 18 10:55:16 babs kernel: [583192.916509] ata1.00: configured for UDMA/133
>> Feb 18 10:55:16 babs kernel: [583192.916524] ata1: EH complete
>> Feb 18 10:55:19 babs kernel: [583196.002650] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:19 babs kernel: [583196.002656] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:19 babs kernel: [583196.002660] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:19 babs kernel: [583196.002669] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:19 babs kernel: [583196.002672] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:19 babs kernel: [583196.002676] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:19 babs kernel: [583196.002680] ata1.00: error: { UNC }
>> Feb 18 10:55:19 babs kernel: [583196.016642] ata1.00: configured for UDMA/133
>> Feb 18 10:55:19 babs kernel: [583196.016657] ata1: EH complete
>> Feb 18 10:55:22 babs kernel: [583198.958629] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> Feb 18 10:55:22 babs kernel: [583198.958634] ata1.00: BMDMA stat 0x24
>> Feb 18 10:55:22 babs kernel: [583198.958639] ata1.00: failed command: READ DMA EXT
>> Feb 18 10:55:22 babs kernel: [583198.958648] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>> Feb 18 10:55:22 babs kernel: [583198.958651] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>> Feb 18 10:55:22 babs kernel: [583198.958656] ata1.00: status: { DRDY ERR }
>> Feb 18 10:55:22 babs kernel: [583198.958659] ata1.00: error: { UNC }
>> Feb 18 10:55:22 babs kernel: [583198.972618] ata1.00: configured for UDMA/133
>> Feb 18 10:55:22 babs kernel: [583198.972632] sd 0:0:0:0: [sda] Unhandled sense code
>> Feb 18 10:55:22 babs kernel: [583198.972636] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
>> Feb 18 10:55:22 babs kernel: [583198.972640] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor]
>> Feb 18 10:55:22 babs kernel: [583198.972646] Descriptor sense data with sense descriptors (in hex):
>> Feb 18 10:55:22 babs kernel: [583198.972649] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00
>> Feb 18 10:55:22 babs kernel: [583198.972659] 17 18 15 c2
>> Feb 18 10:55:22 babs kernel: [583198.972663] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed
>> Feb 18 10:55:22 babs kernel: [583198.972669] sd 0:0:0:0: [sda] CDB: Read(10): 28 00 17 18 15 bf 00 00 08 00
>> Feb 18 10:55:22 babs kernel: [583198.972679] end_request: I/O error, dev sda, sector 387454402
>> Feb 18 10:55:22 babs kernel: [583198.972697] ata1: EH complete
>> Feb 18 10:55:32 babs kernel: [583209.040031] powernow-k8: failing targ, change pending bit set

>
>> The line saying "Add. Sense: Unrecovered read error - auto reallocate
>> failed" is, of course, the most interesting....

>
>> And the -A attributes are unchanged. So... any thoughts?
>> --
>> This sig block for rent


--
This sig block for rent
 
Reply With Quote
 
Arno
Guest
Posts: n/a
 
      19th Feb 2011
Joe Pfeiffer <(E-Mail Removed)> wrote:
> Arno <(E-Mail Removed)> writes:


>> I think it is the following:
>> 387454402/8 = 48431800.25, i.e. I think you are not writing
>> the bad block at all, just the 8 sectors directly in front of it.
>> The OS or drive may then do an automated readahead from the write
>> position onwards (no additional commands in queue, so it has time
>> to optimize things) and get the error.


> That shouldn't be it -- (387454402-63)/8 = 48431792.375
> (the partition starts on sector 63, according to cfdisk). And, after


Ah, I did miss that you overwrote on partition offset,
not disk offset.

Lets check:
- Error at 387454402
- Partition stat at 63
- Error at partition 387454402 - 63 = 387454339
- 8 sector block size: 387454339 / 48431792.375

Ok so far. This is the 4th sector of its 4096 byte block.

- You used offset 48431792 and count=1.

Looks correct to me.

> all, the write clearly fails, and I get a specific error message saying
> it tried and failed to reallocate.


Indeed, but you only have read errors in the error log:

- failed command: READ DMA EXT
^^^^^^^^ DMA read is for disk read
- [sda] Add. Sense: Unrecovered read error
^^^^^^^^^^

Somehow the area is read before being written. That
is the only possibility why there would be reads from
the disk at all. I also see not any write.

No idea why. This may be a bug in dd for small writes or
something else that does not behave quite as expected.
Maybe this write is done in 512 byte steps. Then
the FS layer woukd read 4986 bytes, modify 512 and write
4096. The read would fail, just as you see in your log.

Arno


> After I posted, it occurred to me that the drive may still be under
> warranty. It turned out it is, so a new one is on its way. I'm still
> curious about exactly what's going on, but the curiosity is much more
> academic now!




>> I would recommend overwriting 10MB or so around the error,
>> starting 5MB before or so.
>>
>> Arno
>>
>>
>>
>> Joe Pfeiffer <(E-Mail Removed)> wrote:
>>> I've got a disk drive which seems to have turned up a bad block, but for
>>> which auto reallocation is failing; so I'm looking for advice....

>>
>>> The disk is:

>>
>>> babs:525$ sudo smartctl -i /dev/sda
>>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>>
>>> === START OF INFORMATION SECTION ===
>>> Model Family: Western Digital Caviar Green family
>>> Device Model: WDC WD10EACS-00D6B0
>>>
>>> Here's what I was seeing in my logs:
>>>
>>> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Currently unreadable (pending) sectors
>>> Feb 18 09:26:20 babs smartd[4207]: Device: /dev/sda [SAT], 1 Offline uncorrectable sectors

>>
>>> Took a look at the attributes:

>>
>>> babs:524$ sudo smartctl -A /dev/sda
>>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>>
>>> === START OF READ SMART DATA SECTION ===
>>> SMART Attributes Data Structure revision number: 16
>>> Vendor Specific SMART Attributes with Thresholds:
>>> ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
>>> 1 Raw_Read_Error_Rate 0x002f 200 199 051 Pre-fail Always - 37
>>> 3 Spin_Up_Time 0x0027 180 160 021 Pre-fail Always - 5966
>>> 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 92
>>> 5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
>>> 7 Seek_Error_Rate 0x002e 100 253 051 Old_age Always - 0
>>> 9 Power_On_Hours 0x0032 075 075 000 Old_age Always - 18712
>>> 10 Spin_Retry_Count 0x0032 100 253 051 Old_age Always - 0
>>> 11 Calibration_Retry_Count 0x0032 100 253 051 Old_age Always - 0
>>> 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 91
>>> 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 17
>>> 193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 92
>>> 194 Temperature_Celsius 0x0022 115 100 000 Old_age Always - 35
>>> 196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
>>> 197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 1
>>> 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 1
>>> 199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
>>> 200 Multi_Zone_Error_Rate 0x0008 200 200 051 Old_age Offline - 1

>>
>>> It's my understanding that attribute 5 is the actual count of
>>> reallocated sectors on the disk -- in this case, that no sectors had
>>> been reallocated, so all the spare sectors on the disk are available.

>>
>>> Went to find the bad sector:

>>
>>> babs:530$ sudo smartctl -l selftest /dev/sda
>>> smartctl 5.40 2010-07-12 r3124 [i686-pc-linux-gnu] (local build)
>>> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>>>
>>> === START OF READ SMART DATA SECTION ===
>>> SMART Self-test log structure revision number 1
>>> Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
>>> # 1 Extended offline Completed: read failure 90% 18711 387454402

>>
>>> Translated the LBA to the block in my filesystem and verified I couldn't
>>> read it:
>>>
>>> babs:537$ sudo dd if=/dev/sda1 of=/dev/null ibs=4096 skip=48431792
>>> dd: reading `/dev/sda1': Input/output error
>>> 0+0 records in
>>> 0+0 records out
>>> 0 bytes (0 B) copied, 18.5663 s, 0.0 kB/s

>>
>>> (found the file it was in and deleted the file)

>>
>>> Now comes the part that's got me puzzled: wrote over the block to force
>>> a reallocation:

>>
>>> babs:545$ sudo dd if=/dev/zero of=/dev/sda1 obs=4096 seek=48431792 count=1
>>> dd: writing `/dev/sda1': Input/output error
>>> 1+0 records in
>>> 0+0 records out
>>> 0 bytes (0 B) copied, 19.1174 s, 0.0 kB/s

>>
>>> and here's what turned up in my log when I tried it:

>>
>>> Feb 18 10:55:07 babs kernel: [583184.036616] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:07 babs kernel: [583184.036622] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:07 babs kernel: [583184.036627] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:07 babs kernel: [583184.036636] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:07 babs kernel: [583184.036639] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:07 babs kernel: [583184.036644] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:07 babs kernel: [583184.036647] ata1.00: error: { UNC }
>>> Feb 18 10:55:07 babs kernel: [583184.052596] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:07 babs kernel: [583184.052607] ata1: EH complete
>>> Feb 18 10:55:10 babs kernel: [583186.992593] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:10 babs kernel: [583186.992598] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:10 babs kernel: [583186.992603] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:10 babs kernel: [583186.992612] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:10 babs kernel: [583186.992615] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:10 babs kernel: [583186.992619] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:10 babs kernel: [583186.992623] ata1.00: error: { UNC }
>>> Feb 18 10:55:10 babs kernel: [583187.008573] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:10 babs kernel: [583187.008588] ata1: EH complete
>>> Feb 18 10:55:13 babs kernel: [583189.947567] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:13 babs kernel: [583189.947573] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:13 babs kernel: [583189.947578] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:13 babs kernel: [583189.947586] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:13 babs kernel: [583189.947589] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:13 babs kernel: [583189.947594] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:13 babs kernel: [583189.947597] ata1.00: error: { UNC }
>>> Feb 18 10:55:13 babs kernel: [583189.960532] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:13 babs kernel: [583189.960546] ata1: EH complete
>>> Feb 18 10:55:16 babs kernel: [583192.903546] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:16 babs kernel: [583192.903552] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:16 babs kernel: [583192.903557] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:16 babs kernel: [583192.903565] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:16 babs kernel: [583192.903568] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:16 babs kernel: [583192.903573] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:16 babs kernel: [583192.903576] ata1.00: error: { UNC }
>>> Feb 18 10:55:16 babs kernel: [583192.916509] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:16 babs kernel: [583192.916524] ata1: EH complete
>>> Feb 18 10:55:19 babs kernel: [583196.002650] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:19 babs kernel: [583196.002656] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:19 babs kernel: [583196.002660] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:19 babs kernel: [583196.002669] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:19 babs kernel: [583196.002672] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:19 babs kernel: [583196.002676] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:19 babs kernel: [583196.002680] ata1.00: error: { UNC }
>>> Feb 18 10:55:19 babs kernel: [583196.016642] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:19 babs kernel: [583196.016657] ata1: EH complete
>>> Feb 18 10:55:22 babs kernel: [583198.958629] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> Feb 18 10:55:22 babs kernel: [583198.958634] ata1.00: BMDMA stat 0x24
>>> Feb 18 10:55:22 babs kernel: [583198.958639] ata1.00: failed command: READ DMA EXT
>>> Feb 18 10:55:22 babs kernel: [583198.958648] ata1.00: cmd 25/00:08:bf:15:18/00:00:17:00:00/e0 tag 0 dma 4096 in
>>> Feb 18 10:55:22 babs kernel: [583198.958651] res 51/40:00:c2:15:18/40:00:17:00:00/e0 Emask 0x9 (media error)
>>> Feb 18 10:55:22 babs kernel: [583198.958656] ata1.00: status: { DRDY ERR }
>>> Feb 18 10:55:22 babs kernel: [583198.958659] ata1.00: error: { UNC }
>>> Feb 18 10:55:22 babs kernel: [583198.972618] ata1.00: configured for UDMA/133
>>> Feb 18 10:55:22 babs kernel: [583198.972632] sd 0:0:0:0: [sda] Unhandled sense code
>>> Feb 18 10:55:22 babs kernel: [583198.972636] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
>>> Feb 18 10:55:22 babs kernel: [583198.972640] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor]
>>> Feb 18 10:55:22 babs kernel: [583198.972646] Descriptor sense data with sense descriptors (in hex):
>>> Feb 18 10:55:22 babs kernel: [583198.972649] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00
>>> Feb 18 10:55:22 babs kernel: [583198.972659] 17 18 15 c2
>>> Feb 18 10:55:22 babs kernel: [583198.972663] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed
>>> Feb 18 10:55:22 babs kernel: [583198.972669] sd 0:0:0:0: [sda] CDB: Read(10): 28 00 17 18 15 bf 00 00 08 00
>>> Feb 18 10:55:22 babs kernel: [583198.972679] end_request: I/O error, dev sda, sector 387454402
>>> Feb 18 10:55:22 babs kernel: [583198.972697] ata1: EH complete
>>> Feb 18 10:55:32 babs kernel: [583209.040031] powernow-k8: failing targ, change pending bit set

>>
>>> The line saying "Add. Sense: Unrecovered read error - auto reallocate
>>> failed" is, of course, the most interesting....

>>
>>> And the -A attributes are unchanged. So... any thoughts?
>>> --
>>> This sig block for rent


> --
> This sig block for rent


--
Arno Wagner, Dr. sc. techn., Dipl. Inform., CISSP -- Email: (E-Mail Removed)
GnuPG: ID: 1E25338F FP: 0C30 5782 9D93 F785 E79C 0296 797F 6B50 1E25 338F
----
Cuddly UI's are the manifestation of wishful thinking. -- Dylan Evans
 
Reply With Quote
 
New Member
Join Date: Aug 2012
Posts: 1
 
      22nd Aug 2012
Quote:
Originally Posted by Arno View Post
- failed command: READ DMA EXT
^^^^^^^^ DMA read is for disk read
- [sda] Add. Sense: Unrecovered read error
^^^^^^^^^^

Somehow the area is read before being written. That
is the only possibility why there would be reads from
the disk at all. I also see not any write.

No idea why. This may be a bug in dd for small writes or
something else that does not behave quite as expected.
Maybe this write is done in 512 byte steps. Then
the FS layer woukd read 4986 bytes, modify 512 and write
4096. The read would fail, just as you see in your log.

Arno
It's not a bug. I've just run into this problem right now with a WD20EARX, and when I read this I realized these disks do not use 512 byte LBA sectors, but 4K sectors instead.

So if you're trying to write 512 bytes, it will have to write a 4096 byte sector... which means reading the remaining bytes first, which will fail, and will never get to actually writing anything.

Instead, writing 4096 bytes corresponding to 4K sectors does the trick. I guess some FAQs should be updated for 4K sector disks and 512 sector LBA translation.
 
Reply With Quote
 
 
 
Reply

Thread Tools
Rate This Thread
Rate This Thread:

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off
Trackbacks are On
Pingbacks are On
Refbacks are Off


Similar Threads
Thread Thread Starter Forum Replies Last Post
How do I reallocate disk space after deleting a partition? =?Utf-8?B?Sm9obg==?= Windows XP Help 1 10th May 2006 09:40 AM
How do I reallocate a Meeting Organizer (myself to someone else)? =?Utf-8?B?TWF0dCBDcmFpZw==?= Microsoft Outlook Calendar 0 2nd Feb 2005 11:51 PM
Deleting a file didn't reallocate the space =?Utf-8?B?Q29uZnVzZWQ=?= Windows XP Help 2 19th Jan 2004 03:37 AM
How to reallocate an IRQ in XP Rock Windows XP Help 1 26th Aug 2003 01:39 PM
How to reallocate an IRQ in XP Rock Windows XP Hardware 1 26th Aug 2003 01:39 PM


Features
 

Advertising
 

Newsgroups
 


All times are GMT +1. The time now is 01:40 AM.