Fresh Build - Slot Timeouts and Smart Errors?

[Motorhead]

Hey everyone, just finished up building out a box in the last few weeks ago. Long story short, I wanted to set up a sacalable personal NAS. It will host Plex, and all personal data. Plus, I enjoy expanding my IT skills outside of work.

Setup:
9.3-RELEASE-p28 amd64

Case: Fractal Design Node 304
Power Supply: SeaSonic SS-460FL2 460W Active PFC F3 80 PLUS Platinum Fanless ATX12V/EPS12V
Board: Asrockrack Motherboard, Mini ITX DDR3 1066 LGA 1150 E3C224D2I
CPU: Intel(R) Pentium(R) CPU G3220 @ 3.00GHz (2993.38-MHz K8-class CPU)
Memory: Crucial 16GB Kit (8GBx2) DDR3/DDR3L-1600MT/s (PC3-12800) DR x8 ECC UDIMM
OS Location: SanDisk Cruzer Fit CZ33 16GB USB 2.0 Low-Profile Flash Drive- SDCZ33-016G-B35
Drives: Seagate SEST4000VN00 4TB NAS Internal HDD
NOTE: Only one drive for now. I want continue familiarizing myself with the system before setting up Z2.

I'm still learning the output of smart tests and kernel messages as there are some concerns with the installed drive. After setting up the volume and dataset , I started encountering Kernel timeout errors after startup. Reading through one of the threads (Building, Burn-In, and Testing your FreeNAS system), I began running manual smart tests.

Anytime I run a captive test (IE: smartctl -t short -C /dev/ada0), that same timeout is thrown, interrupting the test:

Code:

Jan 22 08:36:42 FreeNAS ahcich0: Timeout on slot 8 port 0
Jan 22 08:36:42 FreeNAS ahcich0: is 00000000 cs 00000100 ss 00000000 rs 00000100 tfd d0 serr 00000000 cmd 0004c817
Jan 22 08:36:42 FreeNAS ahcich0: Timeout on slot 8 port 0
Jan 22 08:36:42 FreeNAS ahcich0: is 00000000 cs 00000300 ss 00000000 rs 00000300 tfd d0 serr 00000000 cmd 0004c817
Jan 22 08:36:42 FreeNAS ahcich0: Timeout on slot 9 port 0
Jan 22 08:36:42 FreeNAS ahcich0: is 00000000 cs 00000600 ss 00000000 rs 00000600 tfd d0 serr 00000000 cmd 0004c917

However offline tests seem to be successful (according to smart):

Code:

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)      70%      6240         -
# 2  Selective offline   Completed without error       00%      6240         -
# 3  Extended offline    Completed without error       00%      6238         -
# 4  Short offline       Completed without error       00%      6229         -
# 5  Extended captive    Interrupted (host reset)      90%      6229         -

Reading through the entire smart output, it looks like there are other errors to be concerned about, but Im not sure what to make of them yet. They may be related to the timeouts, or are a separate issue:

Code:

smartctl 6.3 2014-07-26 r3976 [FreeBSD 9.3-RELEASE-p28 amd64] (local build)
Copyright (C) 2002-14, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Seagate NAS HDD
Device Model:     ST4000VN000-1H4168
Serial Number:    S300XHMM
LU WWN Device Id: 5 000c50 07560c512
Firmware Version: SC44
User Capacity:    4,000,787,030,016 bytes [4.00 TB]
Sector Sizes:     512 bytes logical, 4096 bytes physical
Rotation Rate:    5900 rpm
Form Factor:      3.5 inches
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ACS-2, ACS-3 T13/2161-D revision 3b
SATA Version is:  SATA 3.1, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Fri Jan 22 09:18:00 2016 PST
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:      (  39)    The self-test routine was interrupted
                    by the host with a hard or soft reset.
Total time to complete Offline
data collection:         (  117) 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:      (   1) minutes.
Extended self-test routine
recommended polling time:      ( 516) minutes.
Conveyance self-test routine
recommended polling time:      (   2) minutes.
SCT capabilities:            (0x10bd)    SCT Status supported.
                    SCT Error Recovery Control supported.
                    SCT Feature Control supported.
                    SCT Data Table supported.

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   111   099   006    Pre-fail  Always       -       39306576
  3 Spin_Up_Time            0x0003   093   093   000    Pre-fail  Always       -       0
  4 Start_Stop_Count        0x0032   100   100   020    Old_age   Always       -       486
  5 Reallocated_Sector_Ct   0x0033   100   100   010    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x000f   100   253   030    Pre-fail  Always       -       232351
  9 Power_On_Hours          0x0032   093   093   000    Old_age   Always       -       6241
10 Spin_Retry_Count        0x0013   100   100   097    Pre-fail  Always       -       0
12 Power_Cycle_Count       0x0032   100   100   020    Old_age   Always       -       28
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   097   000    Old_age   Always       -       21475164188
189 High_Fly_Writes         0x003a   100   100   000    Old_age   Always       -       0
190 Airflow_Temperature_Cel 0x0022   073   051   045    Old_age   Always       -       27 (Min/Max 24/31)
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       -       9
193 Load_Cycle_Count        0x0032   100   100   000    Old_age   Always       -       756
194 Temperature_Celsius     0x0022   027   049   000    Old_age   Always       -       27 (0 22 0 0 0)
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

SMART Error Log Version: 1
ATA Error Count: 5
    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 5 occurred at disk power-on lifetime: 6240 hours (260 days + 0 hours)
  When the command that caused the error occurred, the device was in an unknown state.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      12:02:35.753  NOP [Abort queued commands]
  b0 d4 00 81 4f c2 40 00      12:02:15.597  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      12:02:15.521  SMART READ DATA
  ec 00 01 00 00 00 40 00      12:02:15.514  IDENTIFY DEVICE
  ea 00 00 00 00 00 40 00      12:02:14.274  FLUSH CACHE EXT

Error 4 occurred at disk power-on lifetime: 6229 hours (259 days + 13 hours)
  When the command that caused the error occurred, the device was in an unknown state.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      00:52:05.721  NOP [Abort queued commands]
  b0 d4 00 82 4f c2 40 00      00:51:45.566  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      00:51:45.485  SMART READ DATA
  ec 00 01 00 00 00 40 00      00:51:45.476  IDENTIFY DEVICE
  ea 00 00 00 00 00 40 00      00:51:44.172  FLUSH CACHE EXT

Error 3 occurred at disk power-on lifetime: 6229 hours (259 days + 13 hours)
  When the command that caused the error occurred, the device was in an unknown state.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      00:16:58.564  NOP [Abort queued commands]
  b0 d4 00 81 4f c2 40 00      00:16:38.408  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      00:16:38.326  SMART READ DATA
  ec 00 01 00 00 00 40 00      00:16:38.318  IDENTIFY DEVICE
  60 00 20 90 8d 80 48 00      00:16:38.058  READ FPDMA QUEUED

Error 2 occurred at disk power-on lifetime: 6228 hours (259 days + 12 hours)
  When the command that caused the error occurred, the device was in an unknown state.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      03:31:19.669  NOP [Abort queued commands]
  b0 d4 00 81 4f c2 40 00      03:30:59.515  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      03:30:59.445  SMART READ DATA
  ec 00 01 00 00 00 40 00      03:30:59.437  IDENTIFY DEVICE
  ea 00 00 00 00 00 40 00      03:30:56.877  FLUSH CACHE EXT

Error 1 occurred at disk power-on lifetime: 6228 hours (259 days + 12 hours)
  When the command that caused the error occurred, the device was in an unknown state.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      03:12:36.389  NOP [Abort queued commands]
  b0 d4 00 81 4f c2 40 00      03:12:16.234  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      03:12:16.158  SMART READ DATA
  ec 00 01 00 00 00 40 00      03:12:16.150  IDENTIFY DEVICE
  ea 00 00 00 00 00 40 00      03:12:11.789  FLUSH CACHE EXT

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)      70%      6240         -
# 2  Selective offline   Completed without error       00%      6240         -
# 3  Extended offline    Completed without error       00%      6238         -
# 4  Short offline       Completed without error       00%      6229         -
# 5  Extended captive    Interrupted (host reset)      90%      6229         -
# 6  Short captive       Interrupted (host reset)      70%      6229         -
# 7  Short captive       Interrupted (host reset)      70%      6228         -
# 8  Short captive       Interrupted (host reset)      70%      6228         -
# 9  Selective offline   Completed without error       00%      6228         -
#10  Selective offline   Completed without error       00%      6228         -
#11  Selective offline   Completed without error       00%      6228         -

SMART Selective self-test log data structure revision number 1
SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1       10       20  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.

I also received notifications of critical alerts:
Wed, Jan 20, 2016 at 7:34 PM Device: /dev/ada0, ATA error count increased from 0 to 1
Thu, Jan 21, 2016 at 9:50 PM Device: /dev/ada0, ATA error count increased from 2 to 4

I think the above alerts came during smart tests as well.

The timeouts got me thinking about swapping the SATA cable. Unless someone recommends not too, I think that will be my first troubleshooting step. Any feedback would be much appreciated. Thanks.

 

[Bidule0hm]

Yep, first thing: test the SATA cables ;)

 

[Motorhead]

Tried a few cables as well as different SATA ports with no success.

 

[Mirfster]

What happens if you use a different hard drive (with the same cable and SATA port) and try the same scenarios? May let you know if the issue is isolated to the drive or elsewhere..

Or try the same drive on a different machine. Guess you can run both scenarios at the same time if you have the equipment/parts.

 

[Motorhead]

I briefly tried another drive and did not see the same problem. However its a really old drive and was reporting some bad sectors... I just opened a warranty return on the Seagate. I unmounted it and tried running captive tests with no success. I'm also getting daily alerts on the error count increasing, which is now up to 10 (Device: /dev/ada0, ATA error count increased from 9 to 10). At this point I'm fairly confident the drive needs replacing. Bummer though, its pretty much brand new. I've heard of problems with Seagate drives, maybe this is just a anomaly. I'll update this thread when I test out the replacement. Thanks for the advice!

 

[DrKK]

I briefly tried another drive and did not see the same problem. However its a really old drive and was reporting some bad sectors... I just opened a warranty return on the Seagate. I unmounted it and tried running captive tests with no success. I'm also getting daily alerts on the error count increasing, which is now up to 10 (Device: /dev/ada0, ATA error count increased from 9 to 10). At this point I'm fairly confident the drive needs replacing. Bummer though, its pretty much brand new. I've heard of problems with Seagate drives, maybe this is just a anomaly. I'll update this thread when I test out the replacement. Thanks for the advice!

There's a reason why probably less than 5% of us run any Seagate drives in our NASses.

 

[Mirfster]

Hope it works out. I suggest HGST, but others are WD Red fans. Either one is a "win" in my book.

 

[Motorhead]

Dang, if I would have done some extra reading before going with Seagate... I've always ran Western Digital anyway. This time around the budget was tight. I thought to myself, there must not be a difference right? Oh well...

 

[DrKK]

28 months, Western Digital reds, not one single bit out of place, not one misread byte, not one missed scan, not one byte repaired by a scrub. Not one single thing wrong with any drive in the array. Not one single SMART attribute showing anything wrong.

:)

 

[Motorhead]

So it seems we passed all the judgement on Seagate for no reason? Just received a replacement drive and the same error occurred. Am I running the smart test correctly? "smartctl -t short -C /dev/ada0" , while the drive is unmounted.

Output:

Code:

SMART Error Log Version: 1
ATA Error Count: 1
        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 1 occurred at disk power-on lifetime: 0 hours (0 days + 0 hours)
  When the command that caused the error occurred, the device was in an unknown state

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 00 00 00 00 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  00 00 00 00 00 00 00 ff      00:08:32.283  NOP [Abort queued commands]
  b0 d4 00 81 4f c2 40 00      00:08:12.127  SMART EXECUTE OFF-LINE IMMEDIATE
  b0 d0 01 00 4f c2 40 00      00:08:12.051  SMART READ DATA
  ec 00 01 00 00 00 40 00      00:08:12.043  IDENTIFY DEVICE
  b0 d5 01 09 4f c2 40 00      00:07:02.014  SMART READ LOG

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)      70%         0         -

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.

Caused by:
Jan 27 18:14:57 FreeNAS ahcich0: Timeout on slot 0 port 0
Jan 27 18:14:57 FreeNAS ahcich0: is 00000000 cs 00000001 ss 00000000 rs 00000001 tfd d0 serr 00000000 cmd 0004c017


I don't know what the heck is going on here.

 

[Motorhead]

Is there a way to test install a different version of the ahci drivers? It looks like im currently running 1.30.

Jan 27 10:09:29 FreeNAS ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not supported

 

[hugovsky]

smartctl -t short -C /dev/ada0"

use the long test, not the short. Although if it can't pass the short, it will not pass the long... (I think ;))

while the drive is unmounted.

no need.

 

[hugovsky]

Asrockrack Motherboard, Mini ITX DDR3 1066 LGA 1150 E3C224D2I

Have you tryed intel sata ports? or at least, diferent ports.

Have you tried to test the drive on another MB?

 

[Motorhead]

use the long test, not the short. Although if it can't pass the short, it will not pass the long... (I think ;))

With the previous drive, anytime I ran a long or short test in captive mode, it was interrupted at 70% with the ACHI timeout. When I ran the tests in the background, they were successful (both long and short). I suspect the replacement drive will have the same results.

Code:

# 2  Selective offline   Completed without error       00%      6240         -
# 3  Extended offline    Completed without error       00%      6238         -
# 4  Short offline       Completed without error       00%      6229         -

However, I've only tried the short captive test. It failed on every attempt.

Have you tryed intel sata ports? or at least, diferent ports.

Yes, I've tried different ports and cable as stated above; but not with the replacement drive.
The E3C224D2I board uses an Intel C224 SATA controller.

Have you tried to test the drive on another MB?

Nope, I don't have another board to try with FreeNAS. I do have a VM loaded with FreeNAS on my desktop. Maybe I could try that, but I don't feel that would provide anything substantial, even if it works.


I'm really curious as to whether there is a bug in the AHCI driver. Then again, maybe I'm looking in the wrong direction.

 

[tres_kun]

My only encounter with this error
Timeout on slot 0 port 0
I had my System Dataset on the Boot drive
Mirror 16Gb samsung flash drives
Install freenas on a hard drive and see if that gets the error away
For me hard drive diagnostic is easy on Windows in freenas i just read the numbers

 

[hugovsky]

Nope, I don't have another board to try with FreeNAS. I do have a VM loaded with FreeNAS on my desktop. Maybe I could try that, but I don't feel that would provide anything substantial, even if it works.

Connect the drive to that desktop pc, disconnect all others, use a linux live cd and do the tests the same way: smartctl -t long /dev/???

 

[Motorhead]

My only encounter with this error
Timeout on slot 0 port 0
I had my System Dataset on the Boot drive
Mirror 16Gb samsung flash drives
Install freenas on a hard drive and see if that gets the error away
For me hard drive diagnostic is easy on Windows in freenas i just read the numbers

In your case, aside from the rule of thumb that an OS should be isolated on it's own drive; I don't think the System Dataset is supposed to be stored on a flash drive. Apparently it reduces the life of flash drives significantly, due to the amount of writes.

I could try installing FreeNAS on a hard drive. Not sure yet though, I don't see how a AHCI timeout on the same slot as the 4tb is related to the boot drive being flash.

One thing I did find though! It looks like its possible to modify the ahci timeout in the loader.conf:

Code:

 hint.ahci.X.ccc
     controls Command Completion Coalescing (CCC) usage    by the specified con-
     troller.  Non-zero    value enables CCC and defines maximum time (in ms),
     request can wait for interrupt, if    there are some more requests present
     on    controller queue.  CCC reduces number of context switches on systems
     with many parallel    requests, but it can decrease disk performance on some
     workloads due to additional command latency.

Maybe the captive mode tests are simply timing out due to a parameter, rather than a hardware problem? It seems like these timeouts happen right around 20secs. And since the captive test takes a few minutes, it times out?

I will try setting that parameter tonight and see what happens.

Connect the drive to that desktop pc, disconnect all others, use a linux live cd and do the tests the same way: smartctl -t long /dev/???

Thanks for the recommendations, I will try that as well. However I want to reiterate that this is a brand new replacement drive, replicating the exact same problem as the other drive, which was new'ish as well. I'm skeptical there is something wrong with the drive unless it's a compatibility issue.

 

[tres_kun]

I just gave you my circumstances of recieving that speciffic error
And probably a problem with the motherboard
As it was suffering of data loss and corruption
Moving the system dataset on the flash drive is my own experiment
No reason to point out flash drive endurance on such a workload
Its life expectancy will be verry short indeed

 

[jgreco]

There's a reason why probably less than 5% of us run any Seagate drives in our NASses.

Geez. That's not true and I'm pretty sure you know it. Western Digital has made lots of crap in the past too.

 

[hugovsky]

However I want to reiterate that this is a brand new replacement drive, replicating the exact same problem as the other drive, which was new'ish as well.

well... not impossible also