Strange SMART behavior

[Nindustries]

Hi guys.
I've got something happening on my server and it's driving me crazy.
I got short self-tests set up daily, long self-tests every two weeks. And it all started 2 weeks ago..

So it started when I received emails about failed to read SMART data.
First ada1, then ada2.

Device: /dev/ada1, failed to read SMART Attribute Data
Device info:
WDC WD30EZRX-00D8PB0, S/N:WD-WCC4N0707666, WWN:5-0014ee-2b473dc47, FW:80.00A80, 3.00 TB

Device: /dev/ada2, Read SMART Self-Test Log Failed
Device info:
WDC WD30EZRX-00D8PB0, S/N:WD-WCC4N0707189, WWN:5-0014ee-2b473a179, FW:80.00A80, 3.00 TB

OK, so the SMART test failed. What could have caused this? better check the SMART eh!
/dev/ada2/

Show : /dev/ada2 SMART results

smartctl 6.2 2013-07-26 r3841 [FreeBSD 9.2-RELEASE-p12 amd64] (local build)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family: Western Digital Caviar Green (AF, SATA 6Gb/s)
Device Model: WDC WD30EZRX-00D8PB0
Serial Number: WD-WCC4N0707189
LU WWN Device Id: 5 0014ee 2b473a179
Firmware Version: 80.00A80
User Capacity: 3,000,592,982,016 bytes [3.00 TB]
Sector Sizes: 512 bytes logical, 4096 bytes physical
Rotation Rate: 5400 rpm
Device is: In smartctl database [for details use: -P show]
ATA Version is: ACS-2 (minor revision not indicated)
SATA Version is: SATA 3.0, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is: Thu Oct 9 17:25:32 2014 CEST
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: (0x82) Offline data collection activity
was completed without error.
Auto Offline Data Collection: Enabled.
Self-test execution status: ( 41) The self-test routine was interrupted
by the host with a hard or soft reset.
Total time to complete Offline
data collection: (41760) 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: ( 418) minutes.
Conveyance self-test routine
recommended polling time: ( 5) minutes.
SCT capabilities: (0x7035) SCT Status supported.
SCT Feature Control supported.
SCT Data Table supported.

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 200 051 Pre-fail Always - 0
3 Spin_Up_Time 0x0027 187 180 021 Pre-fail Always - 5650
4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 22
5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
7 Seek_Error_Rate 0x002e 100 253 000 Old_age Always - 0
9 Power_On_Hours 0x0032 097 097 000 Old_age Always - 2633
10 Spin_Retry_Count 0x0032 100 253 000 Old_age Always - 0
11 Calibration_Retry_Count 0x0032 100 253 000 Old_age Always - 0
12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 22
192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 17
193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 614
194 Temperature_Celsius 0x0022 121 110 000 Old_age Always - 29
196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0
198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 0
199 UDMA_CRC_Error_Count 0x0032 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
No Errors Logged

SMART Self-test log structure revision number 1
Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
# 1 Short captive Interrupted (host reset) 90% 2633 -
# 2 Short offline Completed without error 00% 2633 -
# 3 Short offline Completed without error 00% 2615 -
# 4 Short offline Completed without error 00% 2591 -
# 5 Short offline Completed without error 00% 2567 -
# 6 Short offline Completed without error 00% 2543 -
# 7 Short offline Completed without error 00% 2519 -
# 8 Short offline Completed without error 00% 2495 -
# 9 Short offline Completed without error 00% 2471 -
#10 Short offline Completed without error 00% 2448 -
#11 Extended offline Completed without error 00% 2432 -
#12 Short offline Completed without error 00% 2424 -
#13 Short offline Completed without error 00% 2400 -
#14 Extended offline Completed without error 00% 2384 -
#15 Short offline Completed without error 00% 2376 -
#16 Short offline Completed without error 00% 2352 -
#17 Short offline Completed without error 00% 2328 -
#18 Short offline Completed without error 00% 2304 -
#19 Short offline Completed without error 00% 2280 -
#20 Short offline Completed without error 00% 2256 -
#21 Short offline Completed without error 00% 2232 -

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.

So the self-test is interrupted. What do I think of this? Always when manually doing SMART tests the first or second test is interrupted by host. No active file transfers.
Spin-up time is normal, as I waited a bit (i know) before wdidling them.


Second problem; I checked my emails yesterday and SHAPOW: disk /dev/ada6/ offline. volume degraded. Lolwut?

Show : Drive log

> ahcich13: Timeout on slot 3 port 0
> ahcich13: is 00000000 cs 00000008 ss 00000000 rs 00000008 tfd c0 serr 00000000 cmd 0004c317
> (ada6:ahcich13:0:0:0): FLUSHCACHE48. ACB: ea 00 00 00 00 40 00 00 00 00 00 00
> (ada6:ahcich13:0:0:0): CAM status: Command timeout
> (ada6:ahcich13:0:0:0): Retrying command
> ahcich13: Timeout on slot 3 port 0
> ahcich13: is 00000000 cs 00000018 ss 00000000 rs 00000018 tfd d0 serr 00000000 cmd 0004c317
> (ada6:ahcich13:0:0:0): FLUSHCACHE48. ACB: ea 00 00 00 00 40 00 00 00 00 00 00
> (ada6:ahcich13:0:0:0): CAM status: Command timeout
> (ada6:ahcich13:0:0:0): Retrying command
> ahcich13: AHCI reset: device not ready after 31000ms (tfd = 00000080)
> (aprobe0:ahcich13:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
> (aprobe0:ahcich13:0:0:0): CAM status: Unconditionally Re-queue Request
> (aprobe0:ahcich13:0:0:0): Error 5, Retry was blocked
> ada6 at ahcich13 bus 0 scbus13 target 0 lun 0
> ada6: <WDC WD20EFRX-68EUZN0 80.00A80> s/n WD-WMC4M3203246 detached
> GEOM_ELI: Crypto WRITE request failed (error=6). gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[WRITE(offset=17919324160, length=4096)]
> GEOM_ELI: g_eli_read_done() failed gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[READ(offset=270336, length=8192)]
> GEOM_ELI: g_eli_read_done() failed gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[READ(offset=1998250844160, length=8192)]
> GEOM_ELI: g_eli_read_done() failed gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[READ(offset=1998251106304, length=8192)]
> GEOM_ELI: Crypto WRITE request failed (error=6). gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[WRITE(offset=17919328256, length=40960)]
> GEOM_ELI: Crypto WRITE request failed (error=6). gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli[WRITE(offset=17919320064, length=4096)]
> GEOM_ELI: Device gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli destroyed.
> GEOM_ELI: Detached gptid/a52598aa-48b0-11e4-a1a9-001b785decb2.eli on last close.
> (aprobe0:ahcich13:0:0:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
> (aprobe0:ahcich13:0:0:0): CAM status: ATA Status Error
> (aprobe0:ahcich13:0:0:0): ATA status: d1 (BSY DRDY SERV ERR), error: 04 (ABRT )
> (aprobe0:ahcich13:0:0:0): RES: d1 04 ff ff ff ff ff ff ff ff ff
> (aprobe0:ahcich13:0:0:0): Error 5, Retries exhausted
> (aprobe0:ahcich13:0:0:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
> (aprobe0:ahcich13:0:0:0): CAM status: ATA Status Error
> (aprobe0:ahcich13:0:0:0): ATA status: d1 (BSY DRDY SERV ERR), error: 04 (ABRT )
> (aprobe0:ahcich13:0:0:0): RES: d1 04 ff ff ff ff ff ff ff ff ff
> (aprobe0:ahcich13:0:0:0): Error 5, Retries exhausted

So I checked the web interface and it shows the volume degraded (duh) and the drive is just sitting there:

Any suggestions? I'm at a loss what's causing this.

 

[Nindustries]

The recently dropped drive:

 

[Yatti420]

Check your sata cables... If self tests continue failing thats a bad sign.. I don't consider this behaviour weird.. What happened to me the other night I find very odd.. I have a batch of 2tb seagate desktop drives.. 2 older.. 4 newer.. with different platter configurations.. I had 1 drive report a smart read error (oldest seagate 2tb).. smart long testing failed.. 10 minutes later 2 more drives report identical errors (2 newer seagate drives).. Same amount of bad sectors (8) - apparently all around the same lba.. 3/6 was a bad sign .. I threw one of my greens in there in the meantime.. About to put my second green in leaving 1 apparently failing drive..

 

[cyberjock]

You also many have a problem where voltage at the hard drive is fluctuating enough that it's causing things like tests to be aborted.

 

[Nindustries]

You also many have a problem where voltage at the hard drive is fluctuating enough that it's causing things like tests to be aborted.

And this could be a problem of the PSU I assume? Or dirty power, but that may seem unlikely.

 

[cyberjock]

Could be the PSU, could be the cables, could be a cheap extender cable if you are using one, could even be the connector at the PSU if you are using a modular power supply. The only "good" way to rule this out quickly and easily is to start replacing stuff. I always keep a spare 1000w PSU around the house for situations like this. ;)

 

[Nindustries]

I'll swap cables&PSU tomorrow night and post back!
BTW: My PSU is a Seasonic SS-400L2U.

Edit1: Finally installed FreeNAS on a decent brand-name USB stick to exclude this as a possible cause. (unlikely I know) Freenas/the webgui works much faster now however!

Edit2: Requested an RMA for ada6
Edit2: For the moment, everthing points to the SATA cables. (host interrupted the long test) Gonna test this.

Edit: Aside from the RMA, this person encounters the same problems: https://forums.freenas.org/index.php?posts/128950