ZFS CAM Status issues

D

diddie17-1

Hi, over the last couple of days my FreeBSD 10.1 box is starting to give some interesting errors.

A sample of these are -

Code: 
Jul 9 13:38:39 HAYLESNAS kernel: (aprobe2:ahcich4:0:0:0): CAM status: Command timeout
Jul 9 13:39:09 HAYLESNAS kernel: (aprobe0:ahcich3:0:0:0): CAM status: Command timeout
Jul 9 13:39:09 HAYLESNAS kernel: ahcich4: (aprobe1:ahcich2:0:0:0): CAM status: Command timeout
Jul 9 13:39:09 HAYLESNAS kernel: (aprobe2:ahcich4:0:0:0): CAM status: Command timeout
Jul 9 13:39:40 HAYLESNAS kernel: ahcich2: (aprobe0:ahcich3:0:0:0): CAM status: Command timeout
Jul 9 13:39:40 HAYLESNAS kernel: ahcich4: (aprobe1:ahcich2:0:0:0): CAM status: Command timeout
Jul 9 13:39:40 HAYLESNAS kernel: (aprobe2:ahcich4:0:0:0): CAM status: Command timeout
Jul 9 13:40:10 HAYLESNAS kernel: ahcich3: (aprobe1:ahcich2:0:0:0): CAM status: Command timeout
Jul 9 13:40:10 HAYLESNAS kernel: ahcich4: (aprobe0:ahcich3:0:0:0): CAM status: Command timeout
Jul 9 13:40:10 HAYLESNAS kernel: (aprobe2:ahcich4:0:0:0): CAM status: Command timeout
Jul 9 13:54:55 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 13:54:55 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:09:04 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:09:04 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:14:56 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:14:56 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:23:27 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 14:23:27 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 15:48:22 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 15:48:22 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Jul 9 16:41:19 HAYLESNAS kernel: (ada0:ahcich0:0:0:0): CAM status: Uncorrectable parity/CRC error
Originally I suspected a disk going down, as the parity errors are all on ada0, but unless I'm misunderstanding the output, the command timeout errors are more widespread.

I ran a scrub which found and corrected lots of errors on ada0, which again points to the disk, but I when I look at smartctl(8) for /dev/ada0 I can't really see any issues.

HAYLESNAS# smartctl -a /dev/ada0
Code: 
smartctl 6.2 2013-07-26 r3841 [FreeBSD 10.1-RELEASE-p10 amd64] (local build)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Seagate Barracuda Green (AF)
Device Model:     ST2000DL003-9VT166
Serial Number:    5YD14P19
LU WWN Device Id: 5 000c50 02f1bfc53
Firmware Version: CC32
User Capacity:    2,000,398,934,016 bytes [2.00 TB]
Sector Size:      512 bytes logical/physical
Rotation Rate:    5900 rpm
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ATA8-ACS T13/1699-D revision 4
SATA Version is:  SATA 3.0, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Thu Jul  9 22:41:50 2015 NZST
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
See vendor-specific Attribute list for marginal Attributes.

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:      ( 249) Self-test routine in progress...
                                        90% of test remaining.
Total time to complete Offline
data collection:                (  623) 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:        ( 341) minutes.
Conveyance self-test routine
recommended polling time:        (   2) minutes.
SCT capabilities:              (0x30b7) SCT Status 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   115   099   006    Pre-fail  Always       -       89899776
  3 Spin_Up_Time            0x0003   094   092   000    Pre-fail  Always       -       0
  4 Start_Stop_Count        0x0032   100   100   020    Old_age   Always       -       53
  5 Reallocated_Sector_Ct   0x0033   100   100   036    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x000f   077   060   030    Pre-fail  Always       -       52029794
  9 Power_On_Hours          0x0032   063   063   000    Old_age   Always       -       32844
10 Spin_Retry_Count        0x0013   100   100   097    Pre-fail  Always       -       0
12 Power_Cycle_Count       0x0032   100   100   020    Old_age   Always       -       52
183 Runtime_Bad_Block       0x0032   100   100   000    Old_age   Always       -       0
184 End-to-End_Error        0x0032   100   100   099    Old_age   Always       -       0
187 Reported_Uncorrect      0x0032   099   099   000    Old_age   Always       -       1
188 Command_Timeout         0x0032   100   001   000    Old_age   Always       -       1043
189 High_Fly_Writes         0x003a   099   099   000    Old_age   Always       -       1
190 Airflow_Temperature_Cel 0x0022   049   045   045    Old_age   Always   In_the_past 51 (Min/Max 49/53)
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       -       47
193 Load_Cycle_Count        0x0032   100   100   000    Old_age   Always       -       53
194 Temperature_Celsius     0x0022   051   055   000    Old_age   Always       -       51 (0 17 0 0 0)
195 Hardware_ECC_Recovered  0x001a   028   003   000    Old_age   Always       -       89899776
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   139   000    Old_age   Always       -       2116
240 Head_Flying_Hours       0x0000   100   253   000    Old_age   Offline      -       125937031086155
241 Total_LBAs_Written      0x0000   100   253   000    Old_age   Offline      -       1665586290
242 Total_LBAs_Read         0x0000   100   253   000    Old_age   Offline      -       4252201402

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 90%     32844         -
# 2  Short offline       Completed without error       00%     32843         -
# 3  Short offline       Completed without error       00%     32821         -

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.
I've got another long test running now, but I would appreciate any ideas as to whether it's the disk at issue, or the controller, or whether I should be looking at things like cabling (although the case hasn't been opened in a couple of years)

Thanks in advance
 
Hi,

I've got the same problem, even during bootime. I'm very concerned, because it freezes the server. Apparently both 1TB drives from my zmirror boot volume are failing.

I believe the probability of a cabling problem is quite dim (1U server in datacenter for few years now)... Any idea of diagnostic I could perform remotely?

I'm pretty sure ahcich5 is the rescue SSD I've put into the chassis, it should not be dying, but it's consumer grade. It's no big deal, unless it's responsible for other ahcich errors.

Code: 
ahcich5: Timeout on slot 0 port 0
ahcich5: is 00000000 cs 00000000 ss 00000000 rs 00000001 tfd 150 serr 00000000 cmd 0004c017
(aprobe5:ahcich5:0:0:0): SETFEATURES SET TRANSFER MODE. ACB: ef 03 00 00 00 40 00 00 00 00 46 00
(aprobe5:ahcich5:0:0:0): CAM status: Command timeout
(aprobe5:ahcich5:0:0:0): Retrying command
run_interrupt_driven_hooks: still waiting after 60 seconds for xpt_config
ahcich5: Timeout on slot 0 port 0
ahcich5: is 00000000 cs 00000000 ss 00000000 rs 00000001 tfd 150 serr 00000000 cmd 0004c017
(aprobe5:ahcich5:0:0:0): SETFEATURES SET TRANSFER MODE. ACB: ef 03 00 00 00 40 00 00 00 00 46 00
(aprobe5:ahcich5:0:0:0): CAM status: Command timeout
(aprobe5:ahcich5:0:0:0): Error 5, Retries exhausted
ahcich5: Timeout on slot 0 port 0
ahcich5: is 00000000 cs 00000000 ss 00000000 rs 00000001 tfd 150 serr 00000000 cmd 0004c017
(aprobe5:ahcich5:0:0:0): SETFEATURES SET TRANSFER MODE. ACB: ef 03 00 00 00 40 00 00 00 00 46 00
(aprobe5:ahcich5:0:0:0): CAM status: Command timeout
(aprobe5:ahcich5:0:0:0): Retrying command
run_interrupt_driven_hooks: still waiting after 120 seconds for xpt_config
ahcich5: Timeout on slot 0 port 0
ahcich5: is 00000000 cs 00000000 ss 00000000 rs 00000001 tfd 150 serr 00000000 cmd 0004c017
(aprobe5:ahcich5:0:0:0): SETFEATURES SET TRANSFER MODE. ACB: ef 03 00 00 00 40 00 00 00 00 46 00
(aprobe5:ahcich5:0:0:0): CAM status: Command timeout
(aprobe5:ahcich5:0:0:0): Error 5, Retries exhausted
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <WDC WD1002FBYS-02A6B0 03.00C06> ATA-8 SATA 2.x device
ada0: Serial Number WD-WMATV8577497
ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada0: Command Queueing enabled
ada0: 953869MB (1953525168 512 byte sectors: 16H 63S/T 16383C)
ada0: Previously was known as ad4
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <WDC WD1002FBYS-02A6B0 03.00C06> ATA-8 SATA 2.x device
ada1: Serial Number WD-WMATV8542448
ada1: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada1: Command Queueing enabled
ada1: 953869MB (1953525168 512 byte sectors: 16H 63S/T 16383C)
ada1: Previously was known as ad6
ada2 at ahcich2 bus 0 scbus2 target 0 lun 0
ada2: <WDC WD2003FYYS-02W0B0 01.01D01> ATA-8 SATA 2.x device
ada2: Serial Number WD-WMAY00234459
ada2: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada2: Command Queueing enabled
ada2: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
ada2: Previously was known as ad8
ada3 at ahcich3 bus 0 scbus3 target 0 lun 0
ada3: <WDC WD2003FYYS-02W0B0 01.01D01> ATA-8 SATA 2.x device
ada3: Serial Number WD-WMAY00232182
ada3: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada3: Command Queueing enabled
ada3: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
ada3: Previously was known as ad10
ses0 at ahciem0 bus 0 scbus6 target 0 lun 0
ses0: <AHCI SGPIO Enclosure 1.00 0001> SEMB S-E-S 2.00 device
ses0: SEMB SES Device
SMP: AP CPU #1 Launched!
SMP: AP CPU #4 Launched!
SMP: AP CPU #3 Launched!
SMP: AP CPU #7 Launched!
SMP: AP CPU #5 Launched!
SMP: AP CPU #6 Launched!
SMP: AP CPU #2 Launched!
Timecounter "TSC-low" frequency 1650046094 Hz quality 1000
Trying to mount root from zfs:zmirror []...
ums0: <Winbond Electronics Corp Hermon USB hidmouse Device, class 0/0, rev 1.10/0.01, addr 3> on usbus0
ums0: 3 buttons and [Z] coordinates ID=0
Limiting icmp unreach response from 298 to 200 packets/sec
Accounting enabled
Limiting icmp unreach response from 252 to 200 packets/sec
ahcich1: Timeout on slot 25 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 06000000 tfd 40 serr 00000000 cmd 0004d917
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 28 ee 3c 40 2e 00 00 01 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Retrying command
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 23 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01800000 tfd 40 serr 00000000 cmd 0004d717
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 28 ee 3c 40 2e 00 00 01 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich1: Timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Retrying command
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Retrying command
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich1: Timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Error 5, Retries exhausted
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Error 5, Retries exhausted
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich1: Timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Error 5, Retry was blocked
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <WDC WD1002FBYS-02A6B0 03.00C06> s/n WD-WMATV8542448 detached
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Error 5, Retry was blocked
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <WDC WD1002FBYS-02A6B0 03.00C06> s/n WD-WMATV8577497 detached
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich1: Poll timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Error 5, Retries exhausted
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich0: Poll timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Error 5, Retries exhausted
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich1: Timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(ada1:ahcich1:0:0:0): SETFEATURES ENABLE RCACHE. ACB: ef aa 00 00 00 40 00 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Error 5, Periph was invalidated
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(ada0:ahcich0:0:0:0): SETFEATURES ENABLE RCACHE. ACB: ef aa 00 00 00 40 00 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Unconditionally Re-queue Request
(ada0:ahcich0:0:0:0): Error 5, Periph was invalidated
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich1: Poll timeout on slot 26 port 0
ahcich1: is 00000000 cs 04000000 ss 06000000 rs 04000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Error 5, Retries exhausted
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich0: Poll timeout on slot 24 port 0
ahcich0: is 00000000 cs 01000000 ss 01800000 rs 01000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Error 5, Retries exhausted
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich1: Timeout on slot 26 port 0
ahcich1: is 00000000 cs 0c000000 ss 0e000000 rs 0c000000 tfd 80 serr 00000000 cmd 0004d91f
(ada1:ahcich1:0:0:0): WRITE_DMA48. ACB: 35 00 b0 df 1b 40 2e 00 00 00 08 00
(ada1:ahcich1:0:0:0): CAM status: Unconditionally Re-queue Request
(ada1:ahcich1:0:0:0): Error 5, Periph was invalidated
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 28 ee 3c 40 2e 00 00 01 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Error 5, Periph was invalidated
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 90 98 ca 3c 40 2e 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Unconditionally Re-queue Request
(ada1:ahcich1:0:0:0): Error 5, Periph was invalidated
ahcich1: stopping AHCI engine failed
ahcich0: Timeout on slot 24 port 0
ahcich0: is 00000000 cs 03000000 ss 03800000 rs 03000000 tfd 80 serr 00000000 cmd 0004d71f
(ada0:ahcich0:0:0:0): WRITE_DMA48. ACB: 35 00 b0 df 1b 40 2e 00 00 00 08 00
(ada0:ahcich0:0:0:0): CAM status: Unconditionally Re-queue Request
(ada0:ahcich0:0:0:0): Error 5, Periph was invalidated
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 28 ee 3c 40 2e 00 00 01 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Error 5, Periph was invalidated
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 90 98 ca 3c 40 2e 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Unconditionally Re-queue Request
(ada0:ahcich0:0:0:0): Error 5, Periph was invalidated
ahcich0: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich1: Poll timeout on slot 27 port 0
ahcich1: is 00000000 cs 0c000000 ss 0e000000 rs 08000000 tfd 80 serr 00000000 cmd 0004d91f
(aprobe0:ahcich1:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe0:ahcich1:0:0:0): CAM status: Command timeout
(aprobe0:ahcich1:0:0:0): Error 5, Retries exhausted
ahcich1: stopping AHCI engine failed
ahcich1: executing CLO failed
ahcich0: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich0: executing CLO failed
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich0: Poll timeout on slot 25 port 0
ahcich0: is 00000000 cs 03000000 ss 03800000 rs 02000000 tfd 80 serr 00000000 cmd 0004d71f
(aprobe1:ahcich0:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe1:ahcich0:0:0:0): CAM status: Command timeout
(aprobe1:ahcich0:0:0:0): Error 5, Retries exhausted
ahcich0: stopping AHCI engine failed
ahcich0: executing CLO failed
ahcich1: Timeout on slot 27 port 0
ahcich1: is 00000000 cs 0c000000 ss 0e000000 rs 08000000 tfd 80 serr 00000000 cmd 0004d91f
(ada1:ahcich1:0:0:0): READ_FPDMA_QUEUED. ACB: 60 10 50 39 fe 40 2d 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Error 5, Periph was invalidated
(ada1:ahcich1:0:0:0): Periph destroyed
(ada0:ahcich0:0:0:0): Periph destroyed
ahcich1: stopping AHCI engine failed
ahcich1: AHCI reset: device not ready after 31000ms (tfd = 00000080)
ahcich1: executing CLO failed
 
I've been having CAM issues for a few months but on a SSD and started my own thread here about it. I read that it could be an issue with VirtualBox if you have that in your /etc/rc.conf to start up on boot. Do you guys do that?

Removing it seemed to fix it but I put it back in and I can't recall whether I confirmed it really did go away permanently.
 
No virtualbox on my side.
My drives' warranty goes until the 20th of October, so I still have 90 days to decide to RMA or not. I've asked my hosting provider for a check of SATA cables, before going through the hassle of remote drive replacement... (both in the same 2-way zmirror)
 
diddie17-1 said:
Code: 
190 Airflow_Temperature_Cel 0x0022   049   045   045    Old_age   Always   In_the_past 51 (Min/Max 49/53)
Click to expand...

Also notice that the disk is quite hot and already touched the critical limit, at least one time (hence the "failed" message here). Reduce the temperature below 40°C. This is also the usual limit when running servers.
 
Brian Watson said:
I just had a very similar situation and mine turned out to be a bad, or at least badly seated, SATA cable
Click to expand...

I just solved a similar problem here today. All of a sudden I started seeing messages like:

Code: 
kernel: (ada4:ahcich4:0:0:0): READ_FPDMA_QUEUED. ACB: 60 08 30 85 12 40 38 01 00 00 00 00
kernel: (ada4:ahcich4:0:0:0): CAM status: Uncorrectable parity/CRC error
kernel: (ada4:ahcich4:0:0:0): Retrying command

kernel: (ada4:ahcich4:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 98 a8 23 40 6b 00 00 01 00 00
kernel: (ada4:ahcich4:0:0:0): CAM status: Uncorrectable parity/CRC error
kernel: (ada4:ahcich4:0:0:0): Retrying command

in the log.

The disk is in ZFS, and is mounted in a CRU Dataport 10 removable tray. My first suspicion was that the disk is going bad. When I opened up the box as a quick first check (reseat the SATA cable and power connector), I noticed that the SATA cable for the disk was a different color than the other SATA cables in the box.

Even after I reseated both ends of the cable, I was still seeing the errors. So I figured, so long as I was in the box, I'd replace the cable (if for no other reason than the colors would match :) )

Well, to my surprise, that fixed the errors. A zpool scrub just finished without any issues.

Here was a cable that had been working fine for the year since I built the box, and then all by itself decided to introduce infrequent errors into the signal it was carrying.

Who would have thunk a cable would actually "go bad" like that.
 
Just a note, I had similar errors like these:
Code: 
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 28 ee 3c 40 2e 00 00 01 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Retrying command

But in my case it was a Promise SATA-300 controller that decided it had done enough over the years and was close to dying. The controller chip on the card was extremely hot to the touch.
 
On my server it's been a while since the last occurrence of this problem. Changed nothing on the hardware side, just followed the branch 10.1-RELEASE with freebsd-upgrade.
I've still an issue with the unused rescue SSD in the box, at boot time:
Code: 
ahcich5: Timeout on slot 0 port 0
ahcich5: is 00000000 cs 00000000 ss 00000000 rs 00000001 tfd 150 serr 00000000 cmd 0004c017
(aprobe5:ahcich5:0:0:0): SETFEATURES SET TRANSFER MODE. ACB: ef 03 00 00 00 40 00 00 00 00 46 00
(aprobe5:ahcich5:0:0:0): CAM status: Command timeout
(aprobe5:ahcich5:0:0:0): Error 5, Retries exhausted

but the server will no longer crash or display error about the other disks.
 
rotor said:
Who would have thunk a cable would actually "go bad" like that.
Click to expand...

Many materials go brittle over time and can develop cracks if bent and eventually break completely. Operating under constant heat contributes to the weakening of the materials.
 
kpa said:
Many materials go brittle over time and can develop cracks if bent and eventually break completely. Operating under constant heat contributes to the weakening of the materials.
Click to expand...

Quite true.

What I suspect may have happened in my case was that the crimp of the wire to the cable's connector may not have been "solid". Some oxidation occurred, resulting in a less than optimum connection.
 
Everything is working correctly. How to just disable this messages??
Code: 
(ada0:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 40 40 17 01 40 00 00 00 00 00 00
(ada0:ahcich1:0:0:0): CAM status: Uncorrectable parity/CRC error
(ada0:ahcich1:0:0:0): Retrying command
(ada0:ahcich1:0:0:0): READ_FPDMA_QUEUED. ACB: 60 40 80 17 01 40 00 00 00 00 00 00
(ada0:ahcich1:0:0:0): CAM status: Uncorrectable parity/CRC error
(ada0:ahcich1:0:0:0): Retrying command
 
No, things are not working correctly. The host (the computer with SATA port) is trying to communicate with the disk, and it is occasionally not working. Fortunately, it retries the communication. One of these days all the retries will get the communication problem (that's just a question of statistics), and you will get an IO error, which will probably lead to an application crashing, but it could also lead to data loss, data corruption, or system crash.

You should figure out what causes the problem and fix it. Usually, the first step with CRC errors on SATA is cables: are they plugged in correctly? Try replacing the cables.
 
I have PCI-E -> SATA adater, and chipset is very hot. This is a SMART https://www.diffchecker.com/gABo08uK and descryption: https://lime-technology.com/wiki/Understanding_SMART_Reports#1_Raw_Read_Error_Rate

Problem is here: Raw_Read_Error_Rate and here: Seek_Error_Rate

I tried relace SATA cable, no diffrence.
And Speed Test. SAMBA file serwer. Bez tytułu.png
 
You must log in or register to reply here.
Back
Top