Drive Errors ahcich0: Timeout on slot 9 port 0

[Magnetz]

I have a dell T20 with 2 pools each of 2x1TB drives that I use to store my backups.

FreeNAS-11.1-U4
ST1000LM024 drives 1TB 2.5"

As I was doing a backup today the transfer hung and I realised the freenas error log said a drive was removed:

Code:

Feb 16 17:03:51 freenas ahcich0: Timeout on slot 9 port 0
Feb 16 17:03:51 freenas ahcich0: is 00000000 cs fffff1ff ss ffffffff rs ffffffff tfd c0 serr 00000000 cmd 0000cc17
Feb 16 17:03:51 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 f8 db ac 40 5f 00 00 01 00 00
Feb 16 17:03:51 freenas (ada0:ahcich0:0:0:0): CAM status: Command timeout
Feb 16 17:03:51 freenas (ada0:ahcich0:0:0:0): Retrying command
Feb 16 17:03:51 freenas ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
[...]
Feb 16 17:06:59 freenas (aprobe0:ahcich0:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
Feb 16 17:06:59 freenas (aprobe0:ahcich0:0:0:0): CAM status: Command timeout
Feb 16 17:06:59 freenas (aprobe0:ahcich0:0:0:0): Error 5, Retry was blocked
Feb 16 17:06:59 freenas ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
Feb 16 17:06:59 freenas ada0: <ST1000LM024 HN-M101MBB 2BA30004> s/n xx detached
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819701542912, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819702591488, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819703640064, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819704688640, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819705737216, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_read_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[READ(offset=153390071808, length=4096)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_read_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[READ(offset=270336, length=8192)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_read_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[READ(offset=998056665088, length=8192)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_read_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[READ(offset=998056927232, length=8192)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819707834368, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819706785792, length=1048576)]
Feb 16 17:06:59 freenas GEOM_ELI: g_eli_write_done() failed (error=6) gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli[WRITE(offset=819708882944, length=524288)]
Feb 16 17:07:32 freenas ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
[...]
Feb 16 17:10:22 freenas GEOM_MIRROR: Device swap1: provider ada0p1 disconnected.
Feb 16 17:10:22 freenas ZFS: vdev state changed, pool_guid=10361622149524537864 vdev_guid=8539431383270629302
Feb 16 17:10:22 freenas GEOM_ELI: Device gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli destroyed.
Feb 16 17:10:22 freenas GEOM_ELI: Detached gptid/76525f8c-4503-11e6-bbdf-64006a5dad3c.eli on last close.

The drive didn't show up for me to run smartctl so I rebooted and it appeared and passed a short self test. Is the drive dead/dieing?

Code:

ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x002f   100   100   051    Pre-fail  Always       -       3
  2 Throughput_Performance  0x0026   252   252   000    Old_age   Always       -       0
  3 Spin_Up_Time            0x0023   091   086   025    Pre-fail  Always       -       2943
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       328
  5 Reallocated_Sector_Ct   0x0033   252   252   010    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x002e   252   252   051    Old_age   Always       -       0
  8 Seek_Time_Performance   0x0024   252   252   015    Old_age   Offline      -       0
  9 Power_On_Hours          0x0032   100   100   000    Old_age   Always       -       442
10 Spin_Retry_Count        0x0032   252   252   051    Old_age   Always       -       0
11 Calibration_Retry_Count 0x0032   252   252   000    Old_age   Always       -       0
12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       330
191 G-Sense_Error_Rate      0x0022   252   252   000    Old_age   Always       -       0
192 Power-Off_Retract_Count 0x0022   100   100   000    Old_age   Always       -       17
194 Temperature_Celsius     0x0002   064   061   000    Old_age   Always       -       23 (Min/Max 9/39)
195 Hardware_ECC_Recovered  0x003a   100   100   000    Old_age   Always       -       0
196 Reallocated_Event_Count 0x0032   252   252   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0032   252   252   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0030   252   252   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x0036   100   100   000    Old_age   Always       -       1
200 Multi_Zone_Error_Rate   0x002a   100   100   000    Old_age   Always       -       288
223 Load_Retry_Count        0x0032   252   252   000    Old_age   Always       -       0
225 Load_Cycle_Count        0x0032   100   100   000    Old_age   Always       -       6787

Is it worth doing a long self test?
If I online the disk what happens? Will freenas treat it as a brand new drive and copy over all data or will it try to copy only missing changes from the other drive?

edit: extended offline completed OK

# 1 Extended offline Completed without error 00% 443 -

 

[Chris Moore]

FreeNAS-11.1-U4

Separately from the issue at hand, I suggest that you should update to FreeNAS-11.1-U7 as there have been several fixes between where you are and the current update. It is well worth the update and there is almost no risk involved.

The drive didn't show up for me to run smartctl so I rebooted and it appeared and passed a short self test. Is the drive dead/dieing?

I would suggest running some additional tests on the drive. It may very well be in the process of failing. Here is a guide with information on additional tests:

Hard Drive Troubleshooting Guide (All Versions of FreeNAS)
https://forums.freenas.org/index.ph...bleshooting-guide-all-versions-of-freenas.17/

If you are not already doing so, you should schedule periodic tests on your drives.

Here is a link to some scripts that may assist in monitoring the health of your system:

Github repository for FreeNAS scripts, including disk burnin
https://forums.freenas.org/index.ph...for-freenas-scripts-including-disk-burnin.28/

 

[Chris Moore]

PS.

If I online the disk what happens? Will freenas treat it as a brand new drive and copy over all data or will it try to copy only missing changes from the other drive?

ZFS should resync the mirror. As it records the time of transactions, it should only need to copy new transactions, not everything.

 

[Magnetz]

The disk passed a long smart test so I'll just bring it back in to the pool.

The disks are encrypted - if I click 'Replace', I'm assuming it's going to treat it like a blank disk and not attempt to recover it?

"WARNING: The recovery key of your volume will be invalidated "
That's referring to the recovery encryption key, correct? as written here: https://forums.freenas.org/index.ph...ng-a-failed-encrypted-disk.58278/#post-454459

 

[Magnetz]

I got it back up and running after manually attaching the drive with geli attach, online the drive then detach/import the volume.

Some links others may find useful

https://forums.freenas.org/index.ph...h-onlining-encrypted-drive.26367/#post-167145
https://forums.freenas.org/index.php?threads/offline-online-of-encrypted-disk-does-not-work.73340
http://aarononeal.info/freenas-convert-an-encrypted-disk-to-mirror/
https://forums.freenas.org/index.ph...when-replacing-a-failed-encrypted-disk.58278/