On Thu, Feb 16, 2012 at 10:48:00PM -0000, Steven Hartland
wrote:> We've got a machine here with a suspected failed disk but
> the ahci driver seems to be hiding the details of any failure
> and only displaying "Synchronize cache failed" to the console.
>
> Switching to IDE mode in the bios and using the old adX devices
> show info such as:-
>
> ad6: 953869MB <Seagate ST91000640NS SN01> at ata3-master UDMA100 SATA
3Gb/s
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525165
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525151
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525167
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525164
> ad6: FAILURE - READ_DMA status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=128
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525167
> ad6: FAILURE - READ_DMA status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=16
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525167
> ad6: FAILURE - READ_DMA status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=0
> ad6: FAILURE - READ_DMA48 status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=1953525105
> ad6: FAILURE - READ_DMA status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=0
> ad6: FAILURE - READ_DMA status=51<READY,DSC,ERROR>
error=4<ABORTED> LBA=0
These types of messages can be returned by ahci.ko and related CAM bits.
They're formatted quite differently, but the same indications are given.
What you need to be aware of is that quite often the ata(4) driver would
spit out errors for things which weren't really errors. Likewise, I
remember seeing vfs_xxx_x functions often spit out errno=5 for
filesystem stuff with LBAs that were negative or totally off the scale
(e.g. exceeded the LBA range of the actual disk). Thus, I was left to
believe the ata(4) driver had some serious bugs in it.
The above logs indicate that the ATA READ requests are failing to almost
random LBAs. Note that LBA 0 is listed -- sector 0 is quite special as
I'm sure you know -- so I'm quite surprised by that one, especially if
other I/O to the disk works.
It's worth pointing out that all of the errors shown above are on READ
operations, which seems to imply sector problems, except the SMART stats
show no such issues. Keep reading.
A possibility is power-related problems, where the drive may be being
fed improper voltages (it needs 5V, 12V, and 3.3V -- yep all 3) at some
times, which can cause all sorts of craziness on a drive.
> So should we be getting more info on this from the ahci driver?
The driver is quite verbose as-is, IMHO.
> The machine is currently running a long smart test on the drive as a
> short test showed no errors.
Short tests do not do surface scans. Long tests *may* do a surface
scan, but it varies from drive to drive (I keep having to have arguments
with people off-list about this who insist long tests do surface scans
on all drives -- this is not the case).
> Any ideas if the disk is bad or possibly a controller failure?
A controller failure should appear differently. Communication failures
between the disk and controller would also not show up/manifest
themselves as what you've shown above. CRC errors between host
controller and disk controller would show up in SMART attribute 199.
> mfsbsd# smartctl -a /dev/ad6
> smartctl 5.40 2010-10-16 r3189 [FreeBSD 8.2-RELEASE amd64] (local build)
> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>
> === START OF INFORMATION SECTION ==> Device Model: ST91000640NS
> Serial Number: 9XG05QJY
> Firmware Version: SN01
> 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: ATA-8-ACS revision 4
> Local Time is: Thu Feb 16 18:08:32 2012 UTC
> SMART support is: Available - device has SMART capability.
> SMART support is: Enabled
>
> {snipping}
>
> Self-test execution status: ( 246) Self-test routine in progress...
> 60% of test remaining.
It's important to note here that your self-test run is still running.
It's very easy to miss this.
> {snipping}
> SMART Attributes Data Structure revision number: 10
> 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 082 063 044 Pre-fail Always
- 171321356
> 3 Spin_Up_Time 0x0003 094 094 000 Pre-fail Always
- 0
> 4 Start_Stop_Count 0x0032 100 100 020 Old_age Always
- 17
> 5 Reallocated_Sector_Ct 0x0033 100 100 036 Pre-fail Always
- 0
> 7 Seek_Error_Rate 0x000f 074 060 030 Pre-fail Always
- 29134930
> 9 Power_On_Hours 0x0032 093 093 000 Old_age Always
- 6659
> 10 Spin_Retry_Count 0x0013 100 100 097 Pre-fail Always
- 0
> 12 Power_Cycle_Count 0x0032 100 100 020 Old_age Always
- 17
> 184 End-to-End_Error 0x0032 100 100 099 Old_age Always
- 0
> 187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always
- 0
> 188 Command_Timeout 0x0032 100 100 000 Old_age Always
- 0
> 189 High_Fly_Writes 0x003a 100 100 000 Old_age Always
- 0
> 190 Airflow_Temperature_Cel 0x0022 078 046 045 Old_age Always
- 22 (Min/Max 21/23)
> 191 G-Sense_Error_Rate 0x0032 100 100 000 Old_age Always
- 0
> 192 Power-Off_Retract_Count 0x0032 100 100 000 Old_age Always
- 12
> 193 Load_Cycle_Count 0x0032 100 100 000 Old_age Always
- 17
> 194 Temperature_Celsius 0x0022 022 054 000 Old_age Always
- 22 (0 14 0 0)
> 195 Hardware_ECC_Recovered 0x001a 118 099 000 Old_age Always
- 171321356
> 197 Current_Pending_Sector 0x0012 100 100 000 Old_age Always
- 0
> 198 Offline_Uncorrectable 0x0010 100 100 000 Old_age Offline
- 0
> 199 UDMA_CRC_Error_Count 0x003e 200 200 000 Old_age Always
- 0
I see absolutely no anomalies here. Literally the disk looks perfectly
fine. Given my comments about voltage concerns, I would recommend you
watch attribute 12 the next time you see I/O errors. If it increments,
then your drive is losing power in the middle of I/O operations.
Other attributes such as 1, 7, and 195 are all vendor-encoded and thus
are not literal counters. This is normal for Seagate disks. All of
these will almost always have non-zero values in them, given that there
are always some degree of errors when reading from magnetic media --
this is what the ECC section per-sector is used to address.
I will also point out that this is not a problem with your drive's
on-board cache. That would show up in attribute 184.
> SMART Error Log Version: 1
> No Errors Logged
>
> SMART Self-test log structure revision number 1
> Num Test_Description Status Remaining LifeTime(hours)
LBA_of_first_error
> # 1 Extended offline Self-test routine in progress 60% 6659
-
> # 2 Short offline Completed without error 00% 6657
-
The long test is still running, as I stated above. Also, just as a data
point: folks should remember to completely ignore the "remaining"
percentage shown -- it is hardly ever accurate, especially on Western
Digital drives.
I would appreciate if you could provide actual timestamps associated
with the above I/O errors from your logs. One of the kernel logs,
probably messages (or all.log if you enable it -- I HIGHLY recomment
folks do!) -- should have actual datestamps too. I'd like to see how
often these occur, or if all at once.
Otherwise I see nothing wrong with your drive. As such, I'm inclined to
believe what you're seeing is probably a bug in the ata(4) driver.
Also, just for amusement value: so far in the past 7 days, this is the
*TENTH* disk-related issue I have had to look at from people on the
Internet (not just FreeBSD either). I don't know what's going on, but
you people are practically requiring me to make this a full-time job.
Hell, maybe I should start doing "consulting" on these type of things,
haha.
I will take this opportunity to give a shout-out to mav@ and related
folks (I think avg@ had some involvement, maybe not?) for the
AHCI-to-CAM layer bits, as well as the latest ATA-to-CAM bits too. I'm
really glad to see us moving away from ata(4). I say that as
respectfully as possible towards the original author Soren Schmidt,
whose work on ata(4) and "ATAng" over the years shouldn't be
forgotten.
--
| Jeremy Chadwick jdc at parodius.com |
| Parodius Networking http://www.parodius.com/ |
| UNIX Systems Administrator Mountain View, CA, US |
| Making life hard for others since 1977. PGP 4BD6C0CB |