Need help understanding SATA error message.

Need help understanding SATA error message.

[Tomas Lund]

Hello,

I have a SuperMicro X7SBi with ICH9R SATA running 64bit linux 2.6.24.4. I 
have 4 1TB disks connected to the motherboard, and one of the disks is 
logging an error message. Everything is brand new, and hooked up just a 
few weeks ago.

S.M.A.R.T. shows no errors (see output from "smartctl -a" at the bottom of 
this email) after running both a short and long offline selftest, and my 
question is if its possible to tell from this error message what the 
problem is. The result "51/04:00:0a:24:f9" is a bit crypting to me, and it 
would be nice to know what the problem actually is before returning the 
disk.

The box is a 1U SuperMicro chassi with 4 SATA hotplug bays in the front, 
and I tried moving the disk from one slot to another, and the problem 
moved with the disk, so I do not suspect a problem with the hotswap bay or 
the cable.


Error message:


ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
          res 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
ata2.00: status: { DRDY ERR }
ata2.00: error: { ABRT }
ata2.00: configured for UDMA/133
ata2: EH complete
sd 1:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA


I put the entire dmesg at http://tlund.pp.se/envy4_dmesg.txt but I think 
these are the relevant lines about the SATA chipset and the disks from 
booting:


ata2.00: ATA-8: WDC WD1000FYPS-01ZKB0, 02.01B01, max UDMA/133
ata2.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata2.00: configured for UDMA/133
ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata3.00: ATA-8: WDC WD1000FYPS-01ZKB0, 02.01B01, max UDMA/133
ata3.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata3.00: configured for UDMA/133
ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata4.00: ATA-8: WDC WD1000FYPS-01ZKB0, 02.01B01, max UDMA/133
ata4.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata4.00: configured for UDMA/133
scsi 0:0:0:0: Direct-Access     ATA      WDC WD1000FYPS-0 02.0 PQ: 0 ANSI: 5
sd 0:0:0:0: [sda] 1953525168 512-byte hardware sectors (1000205 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 1953525168 512-byte hardware sectors (1000205 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sda: sda1
sd 0:0:0:0: [sda] Attached SCSI disk
sd 0:0:0:0: Attached scsi generic sg0 type 0
scsi 1:0:0:0: Direct-Access     ATA      WDC WD1000FYPS-0 02.0 PQ: 0 ANSI: 5
sd 1:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 1:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdb: sdb1
sd 1:0:0:0: [sdb] Attached SCSI disk
sd 1:0:0:0: Attached scsi generic sg1 type 0
scsi 2:0:0:0: Direct-Access     ATA      WDC WD1000FYPS-0 02.0 PQ: 0 ANSI: 5
sd 2:0:0:0: [sdc] 1953525168 512-byte hardware sectors (1000205 MB)
sd 2:0:0:0: [sdc] Write Protect is off
sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 2:0:0:0: [sdc] 1953525168 512-byte hardware sectors (1000205 MB)
sd 2:0:0:0: [sdc] Write Protect is off
sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdc: sdc1
sd 2:0:0:0: [sdc] Attached SCSI disk
sd 2:0:0:0: Attached scsi generic sg2 type 0
scsi 3:0:0:0: Direct-Access     ATA      WDC WD1000FYPS-0 02.0 PQ: 0 ANSI: 5
sd 3:0:0:0: [sdd] 1953525168 512-byte hardware sectors (1000205 MB)
sd 3:0:0:0: [sdd] Write Protect is off
sd 3:0:0:0: [sdd] Mode Sense: 00 3a 00 00
sd 3:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 3:0:0:0: [sdd] 1953525168 512-byte hardware sectors (1000205 MB)
sd 3:0:0:0: [sdd] Write Protect is off
sd 3:0:0:0: [sdd] Mode Sense: 00 3a 00 00
sd 3:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdd: sdd1
sd 3:0:0:0: [sdd] Attached SCSI disk
sd 3:0:0:0: Attached scsi generic sg3 type 0


output from "smartctl -d ata -a /dev/sdb" here:


smartctl version 5.36 [x86_64-unknown-linux-gnu] Copyright (C) 2002-6 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     WDC WD1000FYPS-01ZKB0
Serial Number:    WD-WCASJ0656706
Firmware Version: 02.01B01
User Capacity:    1,000,204,886,016 bytes
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   8
ATA Standard is:  Exact ATA specification draft version not indicated
Local Time is:    Thu Mar 27 16:49:50 2008 CET
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x84)	Offline data collection activity
 					was suspended by an interrupting command from host.
 					Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0)	The previous self-test routine completed
 					without error or no self-test has ever
 					been run.
Total time to complete Offline 
data collection: 		 (26400) seconds.
Offline data collection
capabilities: 			 (0x7b) SMART execute Offline immediate.
 					Auto Offline data collection on/off support.
 					Suspend Offline collection upon new
 					command.
 					Offline surface scan supported.
 					Self-test supported.
 					Conveyance Self-test supported.
 					Selective Self-test supported.
SMART capabilities:            (0x0003)	Saves SMART data before entering
 					power-saving mode.
 					Supports SMART auto save timer.
Error logging capability:        (0x01)	Error logging supported.
 					General Purpose Logging supported.
Short self-test routine 
recommended polling time: 	 (   2) minutes.
Extended self-test routine
recommended polling time: 	 ( 255) minutes.
Conveyance self-test routine
recommended polling time: 	 (   5) minutes.

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     0x000f   200   200   051    Pre-fail  Always       -       0
   3 Spin_Up_Time            0x0003   193   187   021    Pre-fail  Always       -       7325
   4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       194
   5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
   7 Seek_Error_Rate         0x000e   200   200   000    Old_age   Always       -       0
   9 Power_On_Hours          0x0032   100   100   000    Old_age   Always       -       392
  10 Spin_Retry_Count        0x0012   100   100   000    Old_age   Always       -       0
  11 Calibration_Retry_Count 0x0012   100   253   000    Old_age   Always       -       0
  12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       15
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       11
193 Load_Cycle_Count        0x0032   200   200   000    Old_age   Always       -       799
194 Temperature_Celsius     0x0022   124   114   000    Old_age   Always       -       28
196 Reallocated_Event_Count 0x0032   200   200   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0012   200   200   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0010   200   200   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x003e   200   200   000    Old_age   Always       -       0
200 Multi_Zone_Error_Rate   0x0008   200   200   000    Old_age   Offline      -       0

SMART Error Log Version: 1
ATA Error Count: 108 (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 108 occurred at disk power-on lifetime: 392 hours (16 days + 8 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
   -- -- -- -- -- -- --
   04 51 00 0a 24 f9 a9

   Commands leading to the command that caused the error were:
   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
   -- -- -- -- -- -- -- --  ----------------  --------------------
   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:56:15.157  [RESERVED FOR SERIAL ATA]
   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
   ea 00 00 00 00 00 00 08      03:56:00.377  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:56:00.377  [RESERVED FOR SERIAL ATA]

Error 107 occurred at disk power-on lifetime: 392 hours (16 days + 8 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
   -- -- -- -- -- -- --
   04 51 00 0a 24 f9 a9

   Commands leading to the command that caused the error were:
   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
   -- -- -- -- -- -- -- --  ----------------  --------------------
   ea 00 00 00 00 00 00 08      03:55:34.813  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:55:34.813  [RESERVED FOR SERIAL ATA]
   ea 00 00 00 00 00 00 08      03:55:34.813  FLUSH CACHE EXIT
   ea 00 00 00 00 00 00 08      03:55:10.043  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:55:10.043  [RESERVED FOR SERIAL ATA]

Error 106 occurred at disk power-on lifetime: 392 hours (16 days + 8 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
   -- -- -- -- -- -- --
   04 51 00 0a 24 f9 a9

   Commands leading to the command that caused the error were:
   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
   -- -- -- -- -- -- -- --  ----------------  --------------------
   ea 00 00 00 00 00 00 08      03:54:47.336  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:54:47.336  [RESERVED FOR SERIAL ATA]
   ea 00 00 00 00 00 00 08      03:54:47.336  FLUSH CACHE EXIT
   ea 00 00 00 00 00 00 08      03:54:32.555  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:54:32.555  [RESERVED FOR SERIAL ATA]

Error 105 occurred at disk power-on lifetime: 392 hours (16 days + 8 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
   -- -- -- -- -- -- --
   04 51 00 0a 24 f9 a9

   Commands leading to the command that caused the error were:
   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
   -- -- -- -- -- -- -- --  ----------------  --------------------
   ea 00 00 00 00 00 00 08      03:24:22.514  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:24:22.514  [RESERVED FOR SERIAL ATA]
   ea 00 00 00 00 00 00 08      03:24:22.514  FLUSH CACHE EXIT
   ea 00 00 00 00 00 00 08      03:23:52.777  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:23:52.777  [RESERVED FOR SERIAL ATA]

Error 104 occurred at disk power-on lifetime: 392 hours (16 days + 8 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
   -- -- -- -- -- -- --
   04 51 00 0a 24 f9 a9

   Commands leading to the command that caused the error were:
   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
   -- -- -- -- -- -- -- --  ----------------  --------------------
   ea 00 00 00 00 00 00 08      03:13:33.191  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:13:33.191  [RESERVED FOR SERIAL ATA]
   ea 00 00 00 00 00 00 08      03:13:33.191  FLUSH CACHE EXIT
   ea 00 00 00 00 00 00 08      03:13:03.453  FLUSH CACHE EXIT
   61 08 00 3f 59 70 74 08      03:13:03.453  [RESERVED FOR SERIAL ATA]

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Extended offline    Completed without error       00%       373         -
# 2  Short offline       Completed without error       00%       369         -

SMART Selective self-test log data structure revision number 1
  SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
     1        0        0  Not_testing
     2        0        0  Not_testing
     3        0        0  Not_testing
     4        0        0  Not_testing
     5        0        0  Not_testing
Selective self-test flags (0x0):
   After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.


Best regards,
Tomas

Re: Need help understanding SATA error message.

[Jeff Garzik]

Tomas Lund wrote:
> Hello,
> 
> I have a SuperMicro X7SBi with ICH9R SATA running 64bit linux 2.6.24.4. 
> I have 4 1TB disks connected to the motherboard, and one of the disks is 
> logging an error message. Everything is brand new, and hooked up just a 
> few weeks ago.
> 
> S.M.A.R.T. shows no errors (see output from "smartctl -a" at the bottom 
> of this email) after running both a short and long offline selftest, and 
> my question is if its possible to tell from this error message what the 
> problem is. The result "51/04:00:0a:24:f9" is a bit crypting to me, and 
> it would be nice to know what the problem actually is before returning 
> the disk.

What a coincidence :)  The ata wiki, just created yesterday, had a new 
page added yesterday:

	http://ata.wiki.kernel.org/index.php/Libata_error_messages

Regards,

	Jeff

Re: Need help understanding SATA error message.

[Tomas Lund]

On Fri, 28 Mar 2008, Jeff Garzik wrote:

> Tomas Lund wrote:
>> 
>> I have a SuperMicro X7SBi with ICH9R SATA running 64bit linux 2.6.24.4. 
>> I have 4 1TB disks connected to the motherboard, and one of the disks 
>> is logging an error message. Everything is brand new, and hooked up 
>> just a few weeks ago.
>> 
>> S.M.A.R.T. shows no errors (see output from "smartctl -a" at the bottom 
>> of this email) after running both a short and long offline selftest, 
>> and my question is if its possible to tell from this error message what 
>> the problem is. The result "51/04:00:0a:24:f9" is a bit crypting to me, 
>> and it would be nice to know what the problem actually is before 
>> returning the disk.
>
> What a coincidence :)  The ata wiki, just created yesterday, had a new 
> page added yesterday:
>
> 	http://ata.wiki.kernel.org/index.php/Libata_error_messages

Heh, yeah, now I know that the controller sent the command "ea" to the 
disk, and that the disk has indicated a device error, but I am afraid it 
doesnt really tell me alot more than i already knew, ie: not alot. :)

All arguments to this "ea" command seems to have been 0? And the error has 
"status = 0x51" listing som LBA location on the disk where the error 
occured?

Sorry, but I dont know enough about the protocol to understand most of 
this, could you please help me decode it futher?

Best regards,
Tomas

Re: Need help understanding SATA error message.

[Mark Lord]

Tomas Lund wrote:
> Hello,
> 
> I have a SuperMicro X7SBi with ICH9R SATA running 64bit linux 2.6.24.4. 
> I have 4 1TB disks connected to the motherboard, and one of the disks is 
> logging an error message. Everything is brand new, and hooked up just a 
> few weeks ago.
..
> ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> ata2.00: irq_stat 0x40000001
> ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
>          res 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
> ata2.00: status: { DRDY ERR }
> ata2.00: error: { ABRT }
..
>   Commands leading to the command that caused the error were:
>   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
>   -- -- -- -- -- -- -- --  ----------------  --------------------
>   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
>   61 08 00 3f 59 70 74 08      03:56:15.157  [RESERVED FOR SERIAL ATA]
>   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
>   ea 00 00 00 00 00 00 08      03:56:00.377  FLUSH CACHE EXIT
>   61 08 00 3f 59 70 74 08      03:56:00.377  [RESERVED FOR SERIAL ATA]
..

The SMART log shows that 0xea was a "FLUSH CACHE EXT" (not "EXIT", duh..)
command, which is what libata issues when it wants to ensure that all
cached data has been written to the drive.

This particular drive is reporting that it doesn't understand the command.
Peculiar that, because all modern large drives implement it.

What does hdparm --Istdout give for that specific drive,
and then again for one of your three "good" drives ?

Cheers

Re: Need help understanding SATA error message.

[Mark Lord]

Mark Lord wrote:
> Tomas Lund wrote:
>> Hello,
>>
>> I have a SuperMicro X7SBi with ICH9R SATA running 64bit linux 
>> 2.6.24.4. I have 4 1TB disks connected to the motherboard, and one of 
>> the disks is logging an error message. Everything is brand new, and 
>> hooked up just a few weeks ago.
> ..
>> ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> ata2.00: irq_stat 0x40000001
>> ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
>>          res 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
>> ata2.00: status: { DRDY ERR }
>> ata2.00: error: { ABRT }
> ..
>>   Commands leading to the command that caused the error were:
>>   CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
>>   -- -- -- -- -- -- -- --  ----------------  --------------------
>>   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
>>   61 08 00 3f 59 70 74 08      03:56:15.157  [RESERVED FOR SERIAL ATA]
>>   ea 00 00 00 00 00 00 08      03:56:15.157  FLUSH CACHE EXIT
>>   ea 00 00 00 00 00 00 08      03:56:00.377  FLUSH CACHE EXIT
>>   61 08 00 3f 59 70 74 08      03:56:00.377  [RESERVED FOR SERIAL ATA]
> ..
> 
> The SMART log shows that 0xea was a "FLUSH CACHE EXT" (not "EXIT", duh..)
> command, which is what libata issues when it wants to ensure that all
> cached data has been written to the drive.
> 
> This particular drive is reporting that it doesn't understand the command.
..

Duh..  actually, we were just discussing this very error in another thread.
The drive is really telling us that it hit an unrecoverable WRITE error
at sector 0a:24:f9 on the drive.  Bad sector.

There are patches queued up for 2.6.26 to automatically resume the cache
flush after the failed sector, but you'll still lose data at that sector.

Time for a low-level reformat, if the manufacturer has a utility for that.
Otherwise, RMA it.

Cheers

Re: Need help understanding SATA error message.

[Tomas Lund]

On Fri, 28 Mar 2008, Mark Lord wrote:

> Mark Lord wrote:
>
> Duh..  actually, we were just discussing this very error in another 
> thread. The drive is really telling us that it hit an unrecoverable 
> WRITE error at sector 0a:24:f9 on the drive.  Bad sector.

Aha, ok :(

> There are patches queued up for 2.6.26 to automatically resume the cache 
> flush after the failed sector, but you'll still lose data at that 
> sector.

Lucky for me, there is no data yet on the system yet!

> Time for a low-level reformat, if the manufacturer has a utility for 
> that. Otherwise, RMA it.

The drive is brand spanking new, less than 3 weeks, its going back!

I do however wonder, what is an "unrecoverable write error", does it mean 
it even failed to re-allocate it? Reallocated_Sector_Ct is still 0 
according to smartcl...

//tlund

Re: Need help understanding SATA error message.

[Mark Lord]

Tomas Lund wrote:
> On Fri, 28 Mar 2008, Mark Lord wrote:
> 
>> Mark Lord wrote:
>>
>> Duh..  actually, we were just discussing this very error in another 
>> thread. The drive is really telling us that it hit an unrecoverable 
>> WRITE error at sector 0a:24:f9 on the drive.  Bad sector.
> 
> Aha, ok :(
> 
>> There are patches queued up for 2.6.26 to automatically resume the 
>> cache flush after the failed sector, but you'll still lose data at 
>> that sector.
> 
> Lucky for me, there is no data yet on the system yet!
> 
>> Time for a low-level reformat, if the manufacturer has a utility for 
>> that. Otherwise, RMA it.
> 
> The drive is brand spanking new, less than 3 weeks, its going back!
> 
> I do however wonder, what is an "unrecoverable write error", does it 
> mean it even failed to re-allocate it? Reallocated_Sector_Ct is still 0 
> according to smartcl...
..

Mmm.. it does seem rather unlikely there, doesn't it ?

One thing to try, if you have 12000 seconds to spare, :)
is to simply try this:

   cat /dev/zero > /dev/sdX
   sync
   hdparm -F /dev/sdX

And see if that completes without error.
If it does, then the drive may be fine.

Software bugs are always possible, but do seem unlikely in this case.
But then, so does a hardware failure seem unlikely on a new drive.

Cheers

Re: Need help understanding SATA error message.

[Tomas Lund]

On Fri, 28 Mar 2008, Mark Lord wrote:

> One thing to try, if you have 12000 seconds to spare, :) is to simply 
> try this:
>
>  cat /dev/zero > /dev/sdX
>  sync
>  hdparm -F /dev/sdX
>
> And see if that completes without error. If it does, then the drive may 
> be fine.
>
> Software bugs are always possible, but do seem unlikely in this case. 
> But then, so does a hardware failure seem unlikely on a new drive.

completed without errors, no sectors reallocated...

//tlund

Re: Need help understanding SATA error message.

[Tejun Heo]

Tomas Lund wrote:
> On Fri, 28 Mar 2008, Mark Lord wrote:
> 
>> One thing to try, if you have 12000 seconds to spare, :) is to simply 
>> try this:
>>
>>  cat /dev/zero > /dev/sdX
>>  sync
>>  hdparm -F /dev/sdX
>>
>> And see if that completes without error. If it does, then the drive 
>> may be fine.
>>
>> Software bugs are always possible, but do seem unlikely in this case. 
>> But then, so does a hardware failure seem unlikely on a new drive.
> 
> completed without errors, no sectors reallocated...

Can you put the driver under IO load test involving lots of writes and 
flushes (mounting as ext3 w/ barrier=1 and doing lots of copying should 
achieve it) and see whether the error is still reproducible?

-- 
tejun

Re: Need help understanding SATA error message.

[Mark Lord]

> XXXXX wrote (by private email):
> On Fri, Mar 28, 2008 at 9:59 AM, Mark Lord <liml@rtr.ca> wrote:
>> >  Duh..  actually, we were just discussing this very error in another thread.
>> >  The drive is really telling us that it hit an unrecoverable WRITE error
>> >  at sector 0a:24:f9 on the drive.  Bad sector.
>> >
>> >  There are patches queued up for 2.6.26 to automatically resume the cache
>> >  flush after the failed sector, but you'll still lose data at that sector.
>> >
>> >  Time for a low-level reformat, if the manufacturer has a utility for that.
>> >  Otherwise, RMA it.
> 
> The response to an unrecoverable sector shouldn't be 51/04 if the
> flush fails, it should be 51/10 or 51/40.
> 
> 51/04 would be the response if the FLUSH CACHE command was issued when
> there were still outstanding NCQ commands active.
..

Tejun:  I see we have another thread as well with FLUSH errors.
I really doubt that these are bad drives.
There's very likely a bug in libata / LLD there someplace.

-ml

Re: Need help understanding SATA error message.

[Tejun Heo]

Mark Lord wrote:
>> The response to an unrecoverable sector shouldn't be 51/04 if the
>> flush fails, it should be 51/10 or 51/40.
>>
>> 51/04 would be the response if the FLUSH CACHE command was issued when
>> there were still outstanding NCQ commands active.
> ..
> 
> Tejun:  I see we have another thread as well with FLUSH errors.
> I really doubt that these are bad drives.
> There's very likely a bug in libata / LLD there someplace.

Possibly.  The only thing I can think of which can screw FLUSH is 
issuing it when NCQ phase is still in progress as was in the case for 
ADMA.  FLUSH being a non-data command, it's pretty difficult to get it 
wrong otherwise.  The thing is that sata_sil24 does its own command 
sequencing and even if libata slips there a bit, the silicon won't issue 
FLUSH if NCQ is in progress, so I'm a bit skeptical.  Any other ideas?

-- 
tejun

Re: Need help understanding SATA error message.

[Mark Lord]

Tejun Heo wrote:
> Mark Lord wrote:
>>> The response to an unrecoverable sector shouldn't be 51/04 if the
>>> flush fails, it should be 51/10 or 51/40.
>>>
>>> 51/04 would be the response if the FLUSH CACHE command was issued when
>>> there were still outstanding NCQ commands active.
>> ..
>>
>> Tejun:  I see we have another thread as well with FLUSH errors.
>> I really doubt that these are bad drives.
>> There's very likely a bug in libata / LLD there someplace.
> 
> Possibly.  The only thing I can think of which can screw FLUSH is 
> issuing it when NCQ phase is still in progress as was in the case for 
> ADMA.  FLUSH being a non-data command, it's pretty difficult to get it 
> wrong otherwise.  The thing is that sata_sil24 does its own command 
> sequencing and even if libata slips there a bit, the silicon won't issue 
> FLUSH if NCQ is in progress, so I'm a bit skeptical.  Any other ideas?
..

Mmm.. the one Tomas Lund has is on what appears to be AHCI (ICH9R).

Tomas, if you move the "problem drive" to another port, does the error
follow the drive, or stay with the same port?

(Hopefully you can try that)

Re: Need help understanding SATA error message.

[Tomas Lund]

On Mon, 31 Mar 2008, Mark Lord wrote:

> Mmm.. the one Tomas Lund has is on what appears to be AHCI (ICH9R).

Yes, indeed:

# lspci -v -nn -s 00:1f.2
00:1f.2 SATA controller [0106]: Intel Corporation 82801IR/IO/IH (ICH9R/DO/DH) 6 port SATA AHCI Controller [8086:2922] (rev 02) (prog-if 01 [AHCI 1.0])
         Subsystem: Super Micro Computer Inc Unknown device [15d9:d180]
         Flags: bus master, 66MHz, medium devsel, latency 0, IRQ 379
         I/O ports at 1c30 [size=8]
         I/O ports at 1c24 [size=4]
         I/O ports at 1c28 [size=8]
         I/O ports at 1c20 [size=4]
         I/O ports at 18e0 [size=32]
         Memory at d8601000 (32-bit, non-prefetchable) [size=2K]
         Capabilities: [80] Message Signalled Interrupts: Mask- 64bit- Queue=0/4 Enable+
         Capabilities: [70] Power Management version 3
         Capabilities: [a8] #12 [0010]
         Capabilities: [b0] #13 [0306]

(dmesg output available at http://tlund.pp.se/envy4_dmesg.txt)

> Tomas, if you move the "problem drive" to another port, does the error 
> follow the drive, or stay with the same port?
>
> (Hopefully you can try that)

Yes, the drive has already been moved, and the problem did indeed move 
with the drive. However, I am currently stressing the drives by copying 
large amounts of files, in paralel sessions, and issuing "sync" every 30 
seconds, and I have not seen the error since Mar 28 18:17 (current time 
here is Apr 1 09:10).

The system does not have any data on it yet, and I am not really in a 
hurry to get it into production. Willing to try anything to track this 
problem down.

//tlund

Re: Need help understanding SATA error message.

[Mark Lord]

Tomas Lund wrote:
> On Mon, 31 Mar 2008, Mark Lord wrote:
> 
>> Mmm.. the one Tomas Lund has is on what appears to be AHCI (ICH9R).
> 
> Yes, indeed:
> 
> # lspci -v -nn -s 00:1f.2
> 00:1f.2 SATA controller [0106]: Intel Corporation 82801IR/IO/IH 
> (ICH9R/DO/DH) 6 port SATA AHCI Controller [8086:2922] (rev 02) (prog-if 
> 01 [AHCI 1.0])
>         Subsystem: Super Micro Computer Inc Unknown device [15d9:d180]
.. 
> (dmesg output available at http://tlund.pp.se/envy4_dmesg.txt)
> 
>> Tomas, if you move the "problem drive" to another port, does the error 
>> follow the drive, or stay with the same port?
..
> Yes, the drive has already been moved, and the problem did indeed move 
> with the drive. However, I am currently stressing the drives by copying 
> large amounts of files, in paralel sessions, and issuing "sync" every 30 
> seconds, and I have not seen the error since Mar 28 18:17 (current time 
> here is Apr 1 09:10).
> 
> The system does not have any data on it yet, and I am not really in a 
> hurry to get it into production. Willing to try anything to track this 
> problem down.
..

Mmm.. I suppose the thing to do, is to move it back to the port it was
on when it failed, if you haven't already done that.

If things continue to go well there now, it would not be unreasonable
to perhaps assume that a flaky cable connection was the culprit,
and that simply rearranging the drives/cables produced a better connection.

But I do really dislike pushing things aside without being 100% sure.  :(

Re: Need help understanding SATA error message.

[Tejun Heo]

Hello,

Mark Lord wrote:
>>> Mmm.. the one Tomas Lund has is on what appears to be AHCI (ICH9R).
>>
>> Yes, indeed:
>>
>> # lspci -v -nn -s 00:1f.2
>> 00:1f.2 SATA controller [0106]: Intel Corporation 82801IR/IO/IH 
>> (ICH9R/DO/DH) 6 port SATA AHCI Controller [8086:2922] (rev 02) 
>> (prog-if 01 [AHCI 1.0])
>>         Subsystem: Super Micro Computer Inc Unknown device [15d9:d180]
> ..
>> (dmesg output available at http://tlund.pp.se/envy4_dmesg.txt)

Right.

>>> Tomas, if you move the "problem drive" to another port, does the 
>>> error follow the drive, or stay with the same port?
> ..
>> Yes, the drive has already been moved, and the problem did indeed move 
>> with the drive. However, I am currently stressing the drives by 
>> copying large amounts of files, in paralel sessions, and issuing 
>> "sync" every 30 seconds, and I have not seen the error since Mar 28 
>> 18:17 (current time here is Apr 1 09:10).
>>
>> The system does not have any data on it yet, and I am not really in a 
>> hurry to get it into production. Willing to try anything to track this 
>> problem down.
> ..
> 
> Mmm.. I suppose the thing to do, is to move it back to the port it was
> on when it failed, if you haven't already done that.
> 
> If things continue to go well there now, it would not be unreasonable
> to perhaps assume that a flaky cable connection was the culprit,
> and that simply rearranging the drives/cables produced a better connection.

I've never really seen transmission errors resulting in FLUSH failure. 
All that needs to be transferred is the opcode and according to the 
SMART log, the drive got the command right but still aborted it.  The 
only thing I can think of right now is that dd over the whole disk put 
sanity into the disk but it's just a wild speculation.  Yeap, I would 
love to see whether the problem reproduces itself when moved back to the 
original port.

Thanks.

-- 
tejun

Re: Need help understanding SATA error message.

[Tomas Lund]

On Wed, 2 Apr 2008, Tejun Heo wrote:

> I've never really seen transmission errors resulting in FLUSH failure. 
> All that needs to be transferred is the opcode and according to the 
> SMART log, the drive got the command right but still aborted it.  The 
> only thing I can think of right now is that dd over the whole disk put 
> sanity into the disk but it's just a wild speculation.

The entire disk was overwriten from /dev/zero once, no errors and no 
re-allocated sectors.

> Yeap, I would love to see whether the problem reproduces itself when 
> moved back to the original port.

Please note that this problem did start with the disk on the third port, 
and that it is currently on the second port. same errors on both port, but 
only with this specific disk. the three other disks have not logged any 
errors.

I got 3 errors during the night, first one (same again) pasted here:

Apr  2 04:14:17 envy kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Apr  2 04:14:17 envy kernel: ata2.00: irq_stat 0x40000001
Apr  2 04:14:17 envy kernel: ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Apr  2 04:14:17 envy kernel:          res 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
Apr  2 04:14:17 envy kernel: ata2.00: status: { DRDY ERR }
Apr  2 04:14:17 envy kernel: ata2.00: error: { ABRT }
Apr  2 04:14:17 envy kernel: ata2.00: configured for UDMA/133
Apr  2 04:14:18 envy kernel: ata2: EH complete
Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write Protect is off
Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA

There has been some other errors aswell, i am uploading the entire 
"kern.log" to http://tlund.pp.se/envy4_kern.txt

//tlund

Re: Need help understanding SATA error message.

[Tomas Lund]

On Wed, 2 Apr 2008, Tomas Lund wrote:

> Apr  2 04:14:17 envy kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> Apr  2 04:14:17 envy kernel: ata2.00: irq_stat 0x40000001
> Apr  2 04:14:17 envy kernel: ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
> Apr  2 04:14:17 envy kernel:          res 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
> Apr  2 04:14:17 envy kernel: ata2.00: status: { DRDY ERR }
> Apr  2 04:14:17 envy kernel: ata2.00: error: { ABRT }
> Apr  2 04:14:17 envy kernel: ata2.00: configured for UDMA/133
> Apr  2 04:14:18 envy kernel: ata2: EH complete
> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write Protect is off
> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA

The errors continue to occur at random interval, even after i stoped the 
copy-alot-of-files-and-sync stresstest.

Any other ideas or things to try?

//tlund

Re: Need help understanding SATA error message.

[Tejun Heo]

Tomas Lund wrote:
> On Wed, 2 Apr 2008, Tomas Lund wrote:
> 
>> Apr  2 04:14:17 envy kernel: ata2.00: exception Emask 0x0 SAct 0x0 
>> SErr 0x0 action 0x0
>> Apr  2 04:14:17 envy kernel: ata2.00: irq_stat 0x40000001
>> Apr  2 04:14:17 envy kernel: ata2.00: cmd 
>> ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
>> Apr  2 04:14:17 envy kernel:          res 
>> 51/04:00:0a:24:f9/00:00:00:00:00/a9 Emask 0x1 (device error)
>> Apr  2 04:14:17 envy kernel: ata2.00: status: { DRDY ERR }
>> Apr  2 04:14:17 envy kernel: ata2.00: error: { ABRT }
>> Apr  2 04:14:17 envy kernel: ata2.00: configured for UDMA/133
>> Apr  2 04:14:18 envy kernel: ata2: EH complete
>> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] 1953525168 512-byte 
>> hardware sectors (1000205 MB)
>> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write Protect is off
>> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
>> Apr  2 04:14:18 envy kernel: sd 1:0:0:0: [sdb] Write cache: enabled, 
>> read cache: enabled, doesn't support DPO or FUA
> 
> The errors continue to occur at random interval, even after i stoped the 
> copy-alot-of-files-and-sync stresstest.
> 
> Any other ideas or things to try?

Looks like a broken drive to me.  Can you put it on a different controller?

-- 
tejun

Re: Need help understanding SATA error message.

[Mark Lord]

Tomas Lund wrote:
> On Fri, 28 Mar 2008, Mark Lord wrote:
> 
>> Mark Lord wrote:
>>
>> Duh..  actually, we were just discussing this very error in another 
>> thread. The drive is really telling us that it hit an unrecoverable 
>> WRITE error at sector 0a:24:f9 on the drive.  Bad sector.
..

One thing to try, to verify that my interpretation was correct,
is to try and read that exact sector.  It should fail, I think.

The hex values are in low:middle:high order,
so that translates to 0xf9240a, or decimal 16327690.

So you could try this, with the latest hdparm (from sourceforge.net):

   hdparm --read-sector 16327689
   hdparm --read-sector 16327690
   hdparm --read-sector 16327691

At least one of those ought to fail, if we've done this correctly.

Cheers

Re: Need help understanding SATA error message.

[Tomas Lund]

On Fri, 28 Mar 2008, Mark Lord wrote:

> One thing to try, to verify that my interpretation was correct, is to 
> try and read that exact sector.  It should fail, I think.
>
> The hex values are in low:middle:high order, so that translates to 
> 0xf9240a, or decimal 16327690.
>
> So you could try this, with the latest hdparm (from sourceforge.net):
>
>  hdparm --read-sector 16327689
>  hdparm --read-sector 16327690
>  hdparm --read-sector 16327691
>
> At least one of those ought to fail, if we've done this correctly.

envy:/usr/src/hdparm-8.6# for i in 16327689 16327690 16327691 ; do ./hdparm --read-sector $i /dev/sdb ; done | egrep ^reading
reading sector 16327689: succeeded
reading sector 16327690: succeeded
reading sector 16327691: succeeded

(and just to be sure, i also tried 664825 (ie: 0x0a24f9 instead), works 
fine too.)

On Fri, 28 Mar 2008, Mark Lord wrote:

>  cat /dev/zero > /dev/sdX
>  sync
>  hdparm -F /dev/sdX

kicked disk from array and running it now. didnt want to wait for results 
before i posted this because of the hdparm --read-sector results...

//tlund