CAM status: SCSI Status Error & Subsystem is busy

shawly

Dabbler
Joined
Apr 2, 2014
Messages
45
I recently migrated my host which was running ESXi with FreeNAS as guest (SAS controller passed through) to a native FreeNAS 11.2-U3 install.
I've been running it as a virtual machine for almost 4 years now without ANY issues what so ever, but since migrating to native hardware the whole system got really unstable.
It's running since 2 weeks now on real hardware and I already had 2 unscheduled reboots in the middle of the night, according to the email notifications I received, but it never sent any failure logs so I don't know what caused these reboots.

The only thing different from my virtualized setup is, that I'm now running a Plex and a Syncthing jail, back when I virtualized FreeNAS I didn't have any jails and virtualized both applications within Docker containers in another guest.

Hardware Specs:
CPU: Intel Xeon E3-1220v3
MB: Supermicro X10SL7-F
RAM: 2x8GB Crucial CT102472BD160B DDR3 ECC memory
HDD: 5x 3TB WD Red connected to the LSI 2308 SAS controller which has been flashed to IT mode, all the disks are connected to a Silverstone backplane so I can hotswap.

A few days ago I setup the Syncthing plugin, but because one of the folders I added to Syncthing had the webdav user as owner, Syncthing threw a lot of error messages about permissions and it started to consume all the memory which resulted in the swap partition being filled until it was full and the system froze completely.
I had to force restart the system a couple of times until I was quick enough to disable the Syncthing Jails start on boot.

After I fixed the permission issue and Syncthing seemingly ran properly, I get these error messages at irregular times of the day, sometimes they don't appear for a day at all.
Code:
...
Apr 23 10:42:42 store (da3:mps0:0:3:0): WRITE(16). CDB: 8a 00 00 00 00 01 5d 50 9e a0 00 00 00 e0 00 00
Apr 23 10:42:42 store (da3:mps0:0:3:0): CAM status: CCB request completed with an error
Apr 23 10:42:42 store (da3:mps0:0:3:0): Retrying command
Apr 23 10:42:42 store (da3:mps0:0:3:0): WRITE(16). CDB: 8a 00 00 00 00 01 5d 50 9e a0 00 00 00 e0 00 00
Apr 23 10:42:42 store (da3:mps0:0:3:0): CAM status: SCSI Status Error
Apr 23 10:42:42 store (da3:mps0:0:3:0): SCSI status: Check Condition
Apr 23 10:42:42 store (da3:mps0:0:3:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred)
Apr 23 10:42:42 store (da3:mps0:0:3:0): Retrying command (per sense data)
Apr 23 10:42:47 store (da3:mps0:0:3:0): WRITE(10). CDB: 2a 00 99 dd 67 70 00 00 08 00
Apr 23 10:42:47 store (da3:mps0:0:3:0): CAM status: SCSI Status Error
Apr 23 10:42:47 store (da3:mps0:0:3:0): SCSI status: Check Condition
Apr 23 10:42:47 store (da3:mps0:0:3:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred)
Apr 23 10:42:47 store (da3:mps0:0:3:0): Retrying command (per sense data)
...


Strange thing is, after the KP half an hour ago, these errors are now reported from da2, before the KP it was da3 which was causing these errors..
And now I got another KP after I started a scrub on my pool.

1556008432726.png


After the restart it shows the SCSI Status errors for da3 again.

smartctl -a /dev/da3
Code:
smartctl 6.6 2017-11-05 r4594 [FreeBSD 11.2-STABLE amd64] (local build)
Copyright (C) 2002-17, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Western Digital Red
Device Model:     WDC WD30EFRX-68N32N0
Serial Number:    WD-WCC7K7VPAC02
LU WWN Device Id: 5 0014ee 20f865825
Firmware Version: 82.00A82
User Capacity:    3,000,592,982,016 bytes [3.00 TB]
Sector Sizes:     512 bytes logical, 4096 bytes physical
Rotation Rate:    5400 rpm
Form Factor:      3.5 inches
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ACS-3 T13/2161-D revision 5
SATA Version is:  SATA 3.1, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Tue Apr 23 10:46:37 2019 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:  (0x00) Offline data collection activity
                                        was never started.
                                        Auto Offline Data Collection: Disabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever
                                        been run.
Total time to complete Offline
data collection:                (32160) 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:        ( 342) minutes.
Conveyance self-test routine
recommended polling time:        (   5) minutes.
SCT capabilities:              (0x303d) SCT Status supported.
                                        SCT Error Recovery Control 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   177   162   021    Pre-fail  Always       -       6108
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       20
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x002e   200   200   000    Old_age   Always       -       0
  9 Power_On_Hours          0x0032   094   094   000    Old_age   Always       -       4863
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       -       20
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       18
193 Load_Cycle_Count        0x0032   197   197   000    Old_age   Always       -       11595
194 Temperature_Celsius     0x0022   117   110   000    Old_age   Always       -       33
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   100   253   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 offline       Completed without error       00%      4863         -
# 2  Short offline       Completed without error       00%      4862         -
# 3  Short offline       Completed without error       00%      4861         -
# 4  Short offline       Completed without error       00%      4860         -
# 5  Short offline       Completed without error       00%      4859         -
# 6  Short offline       Completed without error       00%      4858         -
# 7  Short offline       Completed without error       00%      4857         -
# 8  Short offline       Completed without error       00%      4856         -
# 9  Short offline       Completed without error       00%      4855         -
#10  Short offline       Completed without error       00%      4854         -
#11  Short offline       Completed without error       00%      4853         -
#12  Short offline       Completed without error       00%      4852         -
#13  Short offline       Completed without error       00%      4851         -
#14  Short offline       Completed without error       00%      4850         -
#15  Short offline       Completed without error       00%      4849         -
#16  Short offline       Completed without error       00%      4848         -
#17  Short offline       Completed without error       00%      4847         -
#18  Short offline       Completed without error       00%      4846         -
#19  Short offline       Completed without error       00%      4845         -
#20  Short offline       Completed without error       00%      4844         -
#21  Short offline       Completed without error       00%      4843         -

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.


smartctl -a /dev/da2
Code:

smartctl 6.6 2017-11-05 r4594 [FreeBSD 11.2-STABLE amd64] (local build)
Copyright (C) 2002-17, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Western Digital Red
Device Model:     WDC WD30EFRX-68EUZN0
Serial Number:    WD-WMC4N2341795
LU WWN Device Id: 5 0014ee 003c79948
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:    Tue Apr 23 10:55:01 2019 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:  (0x84) Offline data collection activity
                                        was suspended by an interrupting command from host.
                                        Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever
                                        been run.
Total time to complete Offline
data collection:                (39720) 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:        ( 399) minutes.
Conveyance self-test routine
recommended polling time:        (   5) minutes.
SCT capabilities:              (0x703d) SCT Status supported.
                                        SCT Error Recovery Control 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   176   172   021    Pre-fail  Always       -       6166
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       425
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x002e   200   200   000    Old_age   Always       -       0
  9 Power_On_Hours          0x0032   050   050   000    Old_age   Always       -       36505
10 Spin_Retry_Count        0x0032   100   100   000    Old_age   Always       -       0
11 Calibration_Retry_Count 0x0032   100   100   000    Old_age   Always       -       0
12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       418
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       288
193 Load_Cycle_Count        0x0032   191   191   000    Old_age   Always       -       27301
194 Temperature_Celsius     0x0022   118   101   000    Old_age   Always       -       32
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
ATA Error Count: 4
        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 4 occurred at disk power-on lifetime: 11889 hours (495 days + 9 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 01 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  b0 d5 01 e1 4f c2 00 00   9d+17:33:46.553  SMART READ LOG
  b0 d5 01 e1 4f c2 00 00   9d+17:33:46.553  SMART READ LOG
  b0 d6 01 e0 4f c2 00 00   9d+17:33:46.552  SMART WRITE LOG
  b0 d6 01 e0 4f c2 00 00   9d+17:33:46.551  SMART WRITE LOG
  b0 d5 01 e0 4f c2 00 00   9d+17:33:46.551  SMART READ LOG

Error 3 occurred at disk power-on lifetime: 11281 hours (470 days + 1 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 01 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  b0 d5 01 e1 4f c2 00 00      01:52:48.388  SMART READ LOG
  b0 d5 01 e1 4f c2 00 00      01:52:48.388  SMART READ LOG
  b0 d6 01 e0 4f c2 00 00      01:52:48.387  SMART WRITE LOG
  b0 d6 01 e0 4f c2 00 00      01:52:48.386  SMART WRITE LOG
  b0 d5 01 e0 4f c2 00 00      01:52:48.386  SMART READ LOG

Error 2 occurred at disk power-on lifetime: 11281 hours (470 days + 1 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 01 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  b0 d5 01 e1 4f c2 00 00      01:48:17.006  SMART READ LOG
  b0 d5 01 e1 4f c2 00 00      01:48:17.005  SMART READ LOG
  b0 d6 01 e0 4f c2 00 00      01:48:17.004  SMART WRITE LOG
  b0 d6 01 e0 4f c2 00 00      01:48:17.004  SMART WRITE LOG
  b0 d5 01 e0 4f c2 00 00      01:48:17.003  SMART READ LOG

Error 1 occurred at disk power-on lifetime: 7083 hours (295 days + 3 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  04 51 01 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
  -- -- -- -- -- -- -- --  ----------------  --------------------
  b0 d5 01 e1 4f c2 00 08   4d+13:08:16.485  SMART READ LOG
  b0 d5 01 e1 4f c2 00 08   4d+13:08:16.485  SMART READ LOG
  b0 d6 01 e0 4f c2 00 08   4d+13:08:16.484  SMART WRITE LOG
  b0 d6 01 e0 4f c2 00 08   4d+13:08:16.483  SMART WRITE LOG
  b0 d5 01 e0 4f c2 00 08   4d+13:08:16.483  SMART READ LOG

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Short offline       Completed without error       00%     36504         -
# 2  Short offline       Completed without error       00%     36503         -
# 3  Short offline       Completed without error       00%     36502         -
# 4  Short offline       Completed without error       00%     36501         -
# 5  Short offline       Completed without error       00%     36500         -
# 6  Short offline       Completed without error       00%     36499         -
# 7  Short offline       Completed without error       00%     36498         -
# 8  Short offline       Completed without error       00%     36497         -
# 9  Short offline       Completed without error       00%     36496         -
#10  Short offline       Completed without error       00%     36495         -
#11  Short offline       Completed without error       00%     36494         -
#12  Short offline       Completed without error       00%     36493         -
#13  Short offline       Completed without error       00%     36492         -
#14  Short offline       Completed without error       00%     36491         -
#15  Short offline       Completed without error       00%     36490         -
#16  Short offline       Completed without error       00%     36489         -
#17  Short offline       Completed without error       00%     36488         -
#18  Short offline       Completed without error       00%     36487         -
#19  Short offline       Completed without error       00%     36486         -
#20  Short offline       Completed without error       00%     36485         -
#21  Short offline       Completed without error       00%     36484         -

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.


zpool status -v
Code:

  pool: space
state: ONLINE
  scan: resilvered 20K in 0 days 00:00:01 with 0 errors on Tue Apr 23 10:42:48 2019
config:

        NAME                                            STATE     READ WRITE CKSUM
        space                                           ONLINE       0     0     0
          raidz1-0                                      ONLINE       0     0     0
            gptid/d31fcc6c-f956-11e7-b3ba-000c2936caf6  ONLINE       0     0     0
            gptid/d0f3e094-c59a-11e8-a6c2-000c2936ca14  ONLINE       0     0     0
            gptid/d517d14f-f956-11e7-b3ba-000c2936caf6  ONLINE       0     0     0
            gptid/d5e1d506-f956-11e7-b3ba-000c2936caf6  ONLINE       0     0     0
            gptid/d6b1761e-f956-11e7-b3ba-000c2936caf6  ONLINE       0     0     0
        cache
          gptid/36d180c2-5ef9-11e9-bc45-0cc47a6b5a86    ONLINE       0     0     0

errors: No known data errors


Since the pool and the disk seem ok, I'm starting to think the SAS controller is going to die soon.. Because FreeNAS wouldn't KP just because of a faulty disk, right? I once had a disk in my pool which had to be replaced after 3 years now and apart from the SMART errors, FreeNAS ran fine, atleast as a virtual machine.
I haven't started the Syncthing jail yet and for now the system seems to be quiet while scrubbing. But the SCSI errors still appeared after reboot, so I'm sure while Syncthing might not be the cause of the issue, it's apparent that Syncthing is causing the issue to appear more often.

Do you know of any way I can check the SAS controller for issues?
What else could be causing these problems? I'm thinking about going back to virtualization, because for me it was completely stable that way even though I know that it's not recommended.

Edit: The scrub is running since almost an hour now and the error didn't appear, as well as no kernel panics. I will move Syncthing to a Docker container on another host and see if the issue persists.
 
Last edited:

artlessknave

Wizard
Joined
Oct 29, 2016
Messages
1,506
do you have a backup.
can you bypass the backplane and/or run different cables.
do you have a power supply capable of running the disks?
can you stop your jails and see if there are any more panicks?
 

shawly

Dabbler
Joined
Apr 2, 2014
Messages
45
Since I stopped the Syncthing Jail there are no KPs anymore, the scrub ran through sucessfully. I'm currently setting up Syncthing in a Docker container on another machine to see if the reads and writes via NFS cause the same problem or if the Syncthing plugin is causing this. The Plex Jail also runs without any issues.
If the issue with Syncthing still exists when Syncthing isn't running on the host, I will look for hardware failures.

Like I already mentioned, I didn't use any plugins when FreeNAS was running as VM guest, so there is always the possibility of this issue being existent since a long time.
But since I disabled the Syncthing Jail, everything has been stable for the last 24 hours.
 

artlessknave

Wizard
Joined
Oct 29, 2016
Messages
1,506
hmm. my guess would be that syncthing is creating tons of disk access requests and for some reason that's causing problems, which it shouldnt. maybe if you run it and limit it more? I'm not familiar with it, tried it and just found it to be useless.
 

shawly

Dabbler
Joined
Apr 2, 2014
Messages
45
So I've set up a Syncthing container on my Docker machine and it's been running since 20 minutes now without causing any issues. My synced folders are shared via NFS, so the amount of disk access requests is basically the same, but it doesn't cause issues.
It's kinda strange but as long as my NAS is stable, I don't care if applications that need access to the data on the NAS actually have direct access or access via network, Plex and Syncthing run perfectly fine via NFS shares and I don't need any other plugins.

I guess I'll have to monitor the stability of my NAS over the course of the week to be sure that the issue is gone now.
 

arankaspar1

Dabbler
Joined
Apr 7, 2020
Messages
25
Did this happen again for you?
I'm on TrueNAS 12 and the VM runs fine for like a couple weeks or so then continues to log this + no more webGUI access page doesn't load.
Rebooting the VM fixes for another couple weeks.
Using an H200 in IT mode Dell R720 backplane is plugged into the PCIe card (H200). BIOS doesn't like it (cable not connected error) but it works.
The H200 has PCI pass-through setup and assigned to the VM.
Considering flashing my H310mini to IT mode (1) Flashing the H310 Mono Mini to IT mode : homelab
And yes I already have my VM config > storage controller setting set to LSI SAS Logic. (before I installd TrueNAS 12) not sure if this matters.
 
Last edited:
Top