Register for the iXsystems Community to get an ad-free experience and exclusive discounts in our eBay Store.

CAM status: ATA Status Error

Western Digital Drives - The Preferred Drives of FreeNAS and TrueNAS CORE
Status
Not open for further replies.

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
Hi,
I have Recently RMA a WD30EFRX drive because it was noisy (sound to be unbalanced). I have replace the failed disc with the recertified replacement drive provided, using the web GUI (offline and replace buttons).
The status of the pool was healthy after the resilvering (and is already healthy).
Few time later some kernel messages have appeared:
Code:
Dec 11 08:05:18 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 d8 a7 eb 40 32 00 00 00 00 00
Dec 11 08:05:18 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 11 08:05:18 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 11 08:05:18 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 d8 a7 eb 40 32 00 00 00 00
Dec 11 08:05:18 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command

There is less than 16GB on the pool, and nothing important.
I have proceed a scrub and nothing to notice:
Code:
[root@freenas] ~# zpool status
  pool: Volume1
 state: ONLINE
  scan: scrub repaired 0 in 0h6m with 0 errors on Thu Dec 12 07:16:28 2013
config:

        NAME                                            STATE     READ WRITE CKSUM
        Volume1                                         ONLINE       0     0     0
          raidz1-0                                      ONLINE       0     0     0
            gptid/a734066f-61ba-11e3-a751-ac220b7596c7  ONLINE       0     0     0
            gptid/4254e25c-4670-11e3-9600-ac220b7596c7  ONLINE       0     0     0
            gptid/42be8a92-4670-11e3-9600-ac220b7596c7  ONLINE       0     0     0

errors: No known data errors


Then I have proceed to a short follwing by a long SMART test and all seems to be fine:
Code:
[root@freenas] ~# smartctl -a -q noserial /dev/ada0
smartctl 6.1 2013-03-16 r3800 [FreeBSD 9.1-STABLE amd64] (local build)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Western Digital Red (AF)
Device Model:     WDC WD30EFRX-68EUZN0
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 Dec 12 18:44:37 2013 CET
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:                (38880) 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:        ( 390) 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   100   253   021    Pre-fail  Always       -       0
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       3
  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   100   100   000    Old_age   Always       -       48
 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       -       3
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       0
193 Load_Cycle_Count        0x0032   200   200   000    Old_age   Always       -       609
194 Temperature_Celsius     0x0022   122   118   000    Old_age   Always       -       28
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  Extended offline    Completed without error       00%        44         -
# 2  Short offline       Completed without error       00%        37         -
# 3  Extended offline    Completed without error       00%        11         -
# 4  Conveyance offline  Completed without error       00%         1         -
# 5  Short offline       Completed without error       00%         1         -

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.


Find also the gpart list (I don't have enough knoledge to extract any information from that):
Code:
[root@freenas] ~# gpart list
Geom name: ada0
modified: false
state: OK
fwheads: 16
fwsectors: 63
last: 5860533134
first: 34
entries: 128
scheme: GPT
Providers:
1. Name: ada0p1
   Mediasize: 2147483648 (2.0G)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e1
   rawuuid: a7227556-61ba-11e3-a751-ac220b7596c7
   rawtype: 516e7cb5-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2147483648
   offset: 65536
   type: freebsd-swap
   index: 1
   end: 4194431
   start: 128
2. Name: ada0p2
   Mediasize: 2998445412352 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e2
   rawuuid: a734066f-61ba-11e3-a751-ac220b7596c7
   rawtype: 516e7cba-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2998445412352
   offset: 2147549184
   type: freebsd-zfs
   index: 2
   end: 5860533127
   start: 4194432
Consumers:
1. Name: ada0
   Mediasize: 3000592982016 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r2w2e5

Geom name: ada1
modified: false
state: OK
fwheads: 16
fwsectors: 63
last: 5860533134
first: 34
entries: 128
scheme: GPT
Providers:
1. Name: ada1p1
   Mediasize: 2147483648 (2.0G)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e1
   rawuuid: 424207af-4670-11e3-9600-ac220b7596c7
   rawtype: 516e7cb5-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2147483648
   offset: 65536
   type: freebsd-swap
   index: 1
   end: 4194431
   start: 128
2. Name: ada1p2
   Mediasize: 2998445412352 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e2
   rawuuid: 4254e25c-4670-11e3-9600-ac220b7596c7
   rawtype: 516e7cba-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2998445412352
   offset: 2147549184
   type: freebsd-zfs
   index: 2
   end: 5860533127
   start: 4194432
Consumers:
1. Name: ada1
   Mediasize: 3000592982016 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r2w2e5

Geom name: ada2
modified: false
state: OK
fwheads: 16
fwsectors: 63
last: 5860533134
first: 34
entries: 128
scheme: GPT
Providers:
1. Name: ada2p1
   Mediasize: 2147483648 (2.0G)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e1
   rawuuid: 42aaa81e-4670-11e3-9600-ac220b7596c7
   rawtype: 516e7cb5-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2147483648
   offset: 65536
   type: freebsd-swap
   index: 1
   end: 4194431
   start: 128
2. Name: ada2p2
   Mediasize: 2998445412352 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r1w1e2
   rawuuid: 42be8a92-4670-11e3-9600-ac220b7596c7
   rawtype: 516e7cba-6ecf-11d6-8ff8-00022d09712b
   label: (null)
   length: 2998445412352
   offset: 2147549184
   type: freebsd-zfs
   index: 2
   end: 5860533127
   start: 4194432
Consumers:
1. Name: ada2
   Mediasize: 3000592982016 (2.7T)
   Sectorsize: 512
   Stripesize: 4096
   Stripeoffset: 0
   Mode: r2w2e5

Geom name: da0
modified: false
state: OK
fwheads: 255
fwsectors: 63
last: 15633407
first: 63
entries: 4
scheme: MBR
Providers:
1. Name: da0s1
   Mediasize: 988291584 (942M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 32256
   Mode: r1w0e1
   attrib: active
   rawtype: 165
   length: 988291584
   offset: 32256
   type: freebsd
   index: 1
   end: 1930319
   start: 63
2. Name: da0s2
   Mediasize: 988291584 (942M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 988356096
   Mode: r0w0e0
   rawtype: 165
   length: 988291584
   offset: 988356096
   type: freebsd
   index: 2
   end: 3860639
   start: 1930383
3. Name: da0s3
   Mediasize: 1548288 (1.5M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 1976647680
   Mode: r0w0e0
   rawtype: 165
   length: 1548288
   offset: 1976647680
   type: freebsd
   index: 3
   end: 3863663
   start: 3860640
4. Name: da0s4
   Mediasize: 21159936 (20M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 1978195968
   Mode: r1w1e2
   rawtype: 165
   length: 21159936
   offset: 1978195968
   type: freebsd
   index: 4
   end: 3904991
   start: 3863664
Consumers:
1. Name: da0
   Mediasize: 8004304896 (7.5G)
   Sectorsize: 512
   Mode: r2w1e4

Geom name: da0s1
modified: false
state: OK
fwheads: 255
fwsectors: 63
last: 1930256
first: 0
entries: 8
scheme: BSD
Providers:
1. Name: da0s1a
   Mediasize: 988283392 (942M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 40448
   Mode: r1w0e1
   rawtype: 0
   length: 988283392
   offset: 8192
   type: !0
   index: 1
   end: 1930256
   start: 16
Consumers:
1. Name: da0s1
   Mediasize: 988291584 (942M)
   Sectorsize: 512
   Stripesize: 0
   Stripeoffset: 32256
   Mode: r1w0e1


I have try to change the SATA cable and I have test the RAM with Memetest and nothing to notice.
I don't understand what's happend, and what to do now.
Has somebody any idea?

Thanks.
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
I got nothing. Everything looks fine. Even the cable error values are zero per SMART. So you should start looking elsewhere. Maybe a crappy power supply or something?

You have made the choice to buy an Asus desktop motherboard, which is not exactly a choice that is even remotely recommended around here. You also didn't go with ECC RAM, not recommended around here. Granted, ECC shouldn't be making drives sound funny. But there's 2 ways to build a server. The way we recommend and any other way. The recommended way is obviously easier as you KNOW everything should work properly. As soon as you want to go any other way you accept certain risks.

Unfortunately, you are on your own at this point as none of your info gives me any impression anything is wrong. This is why I think its smarter for people just learning FreeNAS/FreeBSD to stick to recommended hardware as you are not familiar enough with the OS to go out buying random hardware. This isn't Windows. 100% of your hardware won't work in FreeBSD. Even if it works, that doesn't mean it will work properly or even work reliably.
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
I got nothing. Everything looks fine. Even the cable error values are zero per SMART. So you should start looking elsewhere. Maybe a crappy power supply or something?

You have made the choice to buy an Asus desktop motherboard, which is not exactly a choice that is even remotely recommended around here. You also didn't go with ECC RAM, not recommended around here. Granted, ECC shouldn't be making drives sound funny. But there's 2 ways to build a server. The way we recommend and any other way. The recommended way is obviously easier as you KNOW everything should work properly. As soon as you want to go any other way you accept certain risks.

Unfortunately, you are on your own at this point as none of your info gives me any impression anything is wrong. This is why I think its smarter for people just learning FreeNAS/FreeBSD to stick to recommended hardware as you are not familiar enough with the OS to go out buying random hardware. This isn't Windows. 100% of your hardware won't work in FreeBSD. Even if it works, that doesn't mean it will work properly or even work reliably.
I'm absolutly not convince that there is any correlation between my "poor hardware" and this kind of kernel error:
1)H77 chipset, which manage the SATA ports, is perfectly support by Freebsd 9.1
2)Nothing for instance indicate clearly this is an hardware issue.
3)Error appear after a disc replacement.
4)Everything works perfect, just this log error I can't explain, and can't connect to a malfunction.
I'm more convinced that's related to a partition information issue.
It's too easy to assume without any proof that's related to my hardware.
Saying that my hardware isn't 100% compatible doesn't means anything. I can say the same about all new Haswell builds, even with server class motherboard (usb3 support is the perfect example).
I continue the troubleshooting and will update the thread.
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
1. Sure, but Asus adds their own stuff to the board. Are you 100% sure that Asus own additions to the board aren't responsible? Hint: You cannot answer that with a "yes" unless you have a duplicate system with the exact same hardware and BIOS version and it doesn't do it.
2. No, but that error is usually caused by an issue like a bad hard drive. In your case it gives a generic ATA status error and no disk. This makes me thing something is up with your SATA or something is interfering with your SATA and controller causing the problem.
3. If it only appears after a disk replacement then I'd ignore it. It should not be giving that error on disk replacement if your hardware supports hotswap. Hot plugging and hot swapping will depend on if you hardware supports it and if the FreeBSD driver supports it. Hot plugging is NOT the same as hot swapping.
4. You're right. And that's why I think it might be an unspecified error with your hardware. Unfortunately, you are totally on your own since you aren't using hardware that's been used alot. If you had a board like mine and still had the error at least I(or someone on the forums) could vouch that it *should* be working properly with a given version. But we can't since you are on an island by yourself regarding the hardware. There's nobody to vouch that your exact hardware should work.
5. If you look at gpart list's output you'll see a line for each disk that says "state: OK". That means it is definitely NOT a partition problem. Of course, the error made it obvious(in my opinion) that it wasn't a partition problem, but that state: OK makes it a "for certain" condition.

And regarding Haswell, I don't recommend them yet because of those issues. Those issues are similar to yours in that the error messages are unspecified and you'd have to figure it out by process of elimination or by finding someone with the same error(remember, you can't do this because of your hardware).

Unless you can provide more specific conditions on which the error occurs you are pretty much on your own to find the cause. Sorry.
 

joeschmuck

Old Man
Moderator
Joined
May 28, 2011
Messages
9,048
This is an AHCI issue. Those error will go away if you turn off AHCI in favor of IDE but I wouldn't recommend it just yet.

I had this same problem on my test machine when I installed FreeBSD 9.2 today. I don't know the root cause either but I had to change to IDE mode to get past the issues. Did you by chance just update to FreeNAS 9.2,0?
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
1. Sure, but Asus adds their own stuff to the board. Are you 100% sure that Asus own additions to the board aren't responsible? Hint: You cannot answer that with a "yes" unless you have a duplicate system with the exact same hardware and BIOS version and it doesn't do it.
This appear on a second system with same Freenas version, same up to date BIOS version, on same hardware you can find on my signature, but equiped with a G2020 processor and a 3 WD30EFRX in RAIDZ1. The first sytem (described in my signature) works like a charme.

3. If it only appears after a disk replacement then I'd ignore it. It should not be giving that error on disk replacement if your hardware supports hotswap. Hot plugging and hot swapping will depend on if you hardware supports it and if the FreeBSD driver supports it. Hot plugging is NOT the same as hot swapping.
Not sure to have well understand what you're saying, but I have physicaly replaced the drive with the system OFF. Hotplug is disable on the BIOS.

This is an AHCI issue. Those error will go away if you turn off AHCI in favor of IDE but I wouldn't recommend it just yet.

I had this same problem on my test machine when I installed FreeBSD 9.2 today. I don't know the root cause either but I had to change to IDE mode to get past the issues. Did you by chance just update to FreeNAS 9.2,0?
Unfortunatly the system was running 9.1.1 before replacement and is still with the same version. I've just proceed to the drive replacement.

I was thinking this was related to the power management of the drive, so I've disable it and set HDD standby to "always on" . I let the smartd Check interval set to 125.
Then I have reboot the system.

Here attached the log since last reboot:
Code:
Dec 13 22:17:09 freenas newsyslog[1489]: logfile first created
Dec 13 22:17:09 freenas syslogd: kernel boot file is /boot/kernel/kernel
Dec 13 22:17:09 freenas kernel: Copyright (c) 1992-2013 The FreeBSD Project.
Dec 13 22:17:09 freenas kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Dec 13 22:17:09 freenas kernel: The Regents of the University of California. All rights reserved.
Dec 13 22:17:09 freenas kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Dec 13 22:17:09 freenas kernel: FreeBSD 9.1-STABLE #0 r+16f6355: Tue Aug 27 00:38:40 PDT 2013
Dec 13 22:17:09 freenas kernel: root@build.ixsystems.com:/tank/home/jkh/src/freenas/os-base/amd64/tank/home/jkh/src/freenas/FreeBSD/src/sys/FREENAS.amd64 amd64
Dec 13 22:17:09 freenas kernel: gcc version 4.2.1 20070831 patched [FreeBSD]
Dec 13 22:17:09 freenas kernel: CPU: Intel(R) Pentium(R) CPU G2020 @ 2.90GHz (2900.08-MHz K8-class CPU)
Dec 13 22:17:09 freenas kernel: Origin = "GenuineIntel"  Id = 0x306a9  Family = 0x6  Model = 0x3a  Stepping = 9
Dec 13 22:17:09 freenas kernel: Features=0xbfebfbff
Dec 13 22:17:09 freenas kernel: Features2=0xd9ae3bf
Dec 13 22:17:09 freenas kernel: AMD Features=0x28100800
Dec 13 22:17:09 freenas kernel: AMD Features2=0x1
Dec 13 22:17:09 freenas kernel: Standard Extended Features=0x281
Dec 13 22:17:09 freenas kernel: TSC: P-state invariant, performance statistics
Dec 13 22:17:09 freenas kernel: real memory  = 17179869184 (16384 MB)
Dec 13 22:17:09 freenas kernel: avail memory = 16204607488 (15453 MB)
Dec 13 22:17:09 freenas kernel: Event timer "LAPIC" quality 600
Dec 13 22:17:09 freenas kernel: ACPI APIC Table:
Dec 13 22:17:09 freenas kernel: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
Dec 13 22:17:09 freenas kernel: FreeBSD/SMP: 1 package(s) x 2 core(s)
Dec 13 22:17:09 freenas kernel: cpu0 (BSP): APIC ID:  0
Dec 13 22:17:09 freenas kernel: cpu1 (AP): APIC ID:  2
Dec 13 22:17:09 freenas kernel: WARNING: VIMAGE (virtualized network stack) is a highly experimental feature.
Dec 13 22:17:09 freenas kernel: ACPI Warning: FADT (revision 5) is longer than ACPI 2.0 version, truncating length 268 to 244 (20110527/tbfadt-320)
Dec 13 22:17:09 freenas kernel: ioapic0  irqs 0-23 on motherboard
Dec 13 22:17:09 freenas kernel: kbd1 at kbdmux0
Dec 13 22:17:09 freenas kernel: aesni0: No AESNI support.
Dec 13 22:17:09 freenas kernel: cryptosoft0:  on motherboard
Dec 13 22:17:09 freenas kernel: acpi0:  on motherboard
Dec 13 22:17:09 freenas kernel: ACPI Error: [RAMB] Namespace lookup failure, AE_NOT_FOUND (20110527/psargs-392)
Dec 13 22:17:09 freenas kernel: ACPI Exception: AE_NOT_FOUND, Could not execute arguments for [RAMW] (Region) (20110527/nsinit-380)
Dec 13 22:17:09 freenas kernel: acpi0: Power Button (fixed)
Dec 13 22:17:09 freenas kernel: acpi0: reservation of 67, 1 (4) failed
Dec 13 22:17:09 freenas kernel: cpu0:  on acpi0
Dec 13 22:17:09 freenas kernel: cpu1:  on acpi0
Dec 13 22:17:09 freenas kernel: hpet0:  iomem 0xfed00000-0xfed003ff on acpi0
Dec 13 22:17:09 freenas kernel: Timecounter "HPET" frequency 14318180 Hz quality 950
Dec 13 22:17:09 freenas kernel: Event timer "HPET" frequency 14318180 Hz quality 550
Dec 13 22:17:09 freenas kernel: Event timer "HPET1" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: Event timer "HPET2" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: Event timer "HPET3" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: Event timer "HPET4" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: Event timer "HPET5" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: Event timer "HPET6" frequency 14318180 Hz quality 440
Dec 13 22:17:09 freenas kernel: atrtc0:  port 0x70-0x77 irq 8 on acpi0
Dec 13 22:17:09 freenas kernel: atrtc0: Warning: Couldn't map I/O.
Dec 13 22:17:09 freenas kernel: Event timer "RTC" frequency 32768 Hz quality 0
Dec 13 22:17:09 freenas kernel: attimer0:  port 0x40-0x43,0x50-0x53 irq 0 on acpi0
Dec 13 22:17:09 freenas kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Dec 13 22:17:09 freenas kernel: Event timer "i8254" frequency 1193182 Hz quality 100
Dec 13 22:17:09 freenas kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
Dec 13 22:17:09 freenas kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
Dec 13 22:17:09 freenas kernel: pcib0:  port 0xcf8-0xcff on acpi0
Dec 13 22:17:09 freenas kernel: pci0:  on pcib0
Dec 13 22:17:09 freenas kernel: pcib1:  irq 16 at device 1.0 on pci0
Dec 13 22:17:09 freenas kernel: pci1:  on pcib1
Dec 13 22:17:09 freenas kernel: vgapci0:  port 0xf000-0xf03f mem 0xf7800000-0xf7bfffff,0xe0000000-0xefffffff irq 16 at device 2.0 on pci0
Dec 13 22:17:09 freenas kernel: agp0:  on vgapci0
Dec 13 22:17:09 freenas kernel: agp0: aperture size is 256M, detected 262140k stolen memory
Dec 13 22:17:09 freenas kernel: xhci0:  mem 0xf7c00000-0xf7c0ffff irq 16 at device 20.0 on pci0
Dec 13 22:17:09 freenas kernel: xhci0: 32 byte context size.
Dec 13 22:17:09 freenas kernel: usbus0 on xhci0
Dec 13 22:17:09 freenas kernel: pci0:  at device 22.0 (no driver attached)
Dec 13 22:17:09 freenas kernel: ehci0:  mem 0xf7c14000-0xf7c143ff irq 23 at device 26.0 on pci0
Dec 13 22:17:09 freenas kernel: usbus1: EHCI version 1.0
Dec 13 22:17:09 freenas kernel: usbus1 on ehci0
Dec 13 22:17:09 freenas kernel: pcib2:  irq 16 at device 28.0 on pci0
Dec 13 22:17:09 freenas kernel: pci2:  on pcib2
Dec 13 22:17:09 freenas kernel: pcib3:  irq 16 at device 28.4 on pci0
Dec 13 22:17:09 freenas kernel: pci3:  on pcib3
Dec 13 22:17:09 freenas kernel: re0:  port 0xe000-0xe0ff mem 0xf0004000-0xf0004fff,0xf0000000-0xf0003fff irq 16 at device 0.0 on pci3
Dec 13 22:17:09 freenas kernel: re0: Using 1 MSI-X message
Dec 13 22:17:09 freenas kernel: re0: Chip rev. 0x48000000
Dec 13 22:17:09 freenas kernel: re0: MAC rev. 0x00000000
Dec 13 22:17:09 freenas kernel: miibus0:  on re0
Dec 13 22:17:09 freenas kernel: rgephy0:  PHY 1 on miibus0
Dec 13 22:17:09 freenas kernel: rgephy0:  none, 10baseT, 10baseT-FDX, 10baseT-FDX-flow, 100baseTX, 100baseTX-FDX, 100baseTX-FDX-flow, 1000baseT-FDX, 1000baseT-FDX-master, 1000baseT-FDX-flow, 1000baseT-FDX-flow-master, auto, auto-flow
Dec 13 22:17:09 freenas kernel: re0: Ethernet address: ac:22:0b:75:96:c7
Dec 13 22:17:09 freenas kernel: ehci1:  mem 0xf7c13000-0xf7c133ff irq 23 at device 29.0 on pci0
Dec 13 22:17:09 freenas kernel: usbus2: EHCI version 1.0
Dec 13 22:17:09 freenas kernel: usbus2 on ehci1
Dec 13 22:17:09 freenas kernel: isab0:  at device 31.0 on pci0
Dec 13 22:17:09 freenas kernel: isa0:  on isab0
Dec 13 22:17:09 freenas kernel: ahci0:  port 0xf0b0-0xf0b7,0xf0a0-0xf0a3,0xf090-0xf097,0xf080-0xf083,0xf060-0xf07f mem 0xf7c12000-0xf7c127ff irq 19 at device 31.2 on pci0
Dec 13 22:17:09 freenas kernel: ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not supported
Dec 13 22:17:09 freenas kernel: ahcich0:  at channel 0 on ahci0
Dec 13 22:17:09 freenas kernel: ahcich1:  at channel 1 on ahci0
Dec 13 22:17:09 freenas kernel: ahcich2:  at channel 2 on ahci0
Dec 13 22:17:09 freenas kernel: pci0:  at device 31.3 (no driver attached)
Dec 13 22:17:09 freenas kernel: acpi_button0:  on acpi0
Dec 13 22:17:09 freenas kernel: acpi_tz0:  on acpi0
Dec 13 22:17:09 freenas kernel: acpi_tz1:  on acpi0
Dec 13 22:17:09 freenas kernel: orm0:  at iomem 0xc0000-0xce7ff,0xce800-0xcf7ff on isa0
Dec 13 22:17:09 freenas kernel: sc0:  at flags 0x100 on isa0
Dec 13 22:17:09 freenas kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Dec 13 22:17:09 freenas kernel: vga0:  at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Dec 13 22:17:09 freenas kernel: atkbdc0:  at port 0x60,0x64 on isa0
Dec 13 22:17:09 freenas kernel: atkbd0:  irq 1 on atkbdc0
Dec 13 22:17:09 freenas kernel: kbd0 at atkbd0
Dec 13 22:17:09 freenas kernel: atkbd0: [GIANT-LOCKED]
Dec 13 22:17:09 freenas kernel: ppc0: cannot reserve I/O port range
Dec 13 22:17:09 freenas kernel: coretemp0:  on cpu0
Dec 13 22:17:09 freenas kernel: est0:  on cpu0
Dec 13 22:17:09 freenas kernel: p4tcc0:  on cpu0
Dec 13 22:17:09 freenas kernel: coretemp1:  on cpu1
Dec 13 22:17:09 freenas kernel: est1:  on cpu1
Dec 13 22:17:09 freenas kernel: p4tcc1:  on cpu1
Dec 13 22:17:09 freenas kernel: Timecounters tick every 1.000 msec
Dec 13 22:17:09 freenas kernel: ipfw2 (+ipv6) initialized, divert enabled, nat enabled, default to accept, logging disabled
Dec 13 22:17:09 freenas kernel: DUMMYNET 0xfffffe0003e8c440 with IPv6 initialized (100409)
Dec 13 22:17:09 freenas kernel: load_dn_sched dn_sched WF2Q+ loaded
Dec 13 22:17:09 freenas kernel: load_dn_sched dn_sched FIFO loaded
Dec 13 22:17:09 freenas kernel: load_dn_sched dn_sched PRIO loaded
Dec 13 22:17:09 freenas kernel: load_dn_sched dn_sched QFQ loaded
Dec 13 22:17:09 freenas kernel: load_dn_sched dn_sched RR loaded
Dec 13 22:17:09 freenas kernel: usbus0: 5.0Gbps Super Speed USB v3.0
Dec 13 22:17:09 freenas kernel: usbus1: 480Mbps High Speed USB v2.0
Dec 13 22:17:09 freenas kernel: usbus2: 480Mbps High Speed USB v2.0
Dec 13 22:17:09 freenas kernel: ugen0.1: <0x8086> at usbus0
Dec 13 22:17:09 freenas kernel: uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
Dec 13 22:17:09 freenas kernel: ugen1.1:  at usbus1
Dec 13 22:17:09 freenas kernel: uhub1:  on usbus1
Dec 13 22:17:09 freenas kernel: ugen2.1:  at usbus2
Dec 13 22:17:09 freenas kernel: uhub2:  on usbus2
Dec 13 22:17:09 freenas kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
Dec 13 22:17:09 freenas kernel: ada0:  ATA-9 SATA 3.x device
Dec 13 22:17:09 freenas kernel: ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
Dec 13 22:17:09 freenas kernel: ada0: Command Queueing enabled
Dec 13 22:17:09 freenas kernel: ada0: 2861588MB (5860533168 512 byte sectors: 16H 63S/T 16383C)
Dec 13 22:17:09 freenas kernel: ada0: quirks=0x1<4K>
Dec 13 22:17:09 freenas kernel: ada0: Previously was known as ad4
Dec 13 22:17:09 freenas kernel: ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
Dec 13 22:17:09 freenas kernel: ada1:  ATA-9 SATA 3.x device
Dec 13 22:17:09 freenas kernel: ada1: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
Dec 13 22:17:09 freenas kernel: ada1: Command Queueing enabled
Dec 13 22:17:09 freenas kernel: ada1: 2861588MB (5860533168 512 byte sectors: 16H 63S/T 16383C)
Dec 13 22:17:09 freenas kernel: ada1: quirks=0x1<4K>
Dec 13 22:17:09 freenas kernel: ada1: Previously was known as ad6
Dec 13 22:17:09 freenas kernel: ada2 at ahcich2 bus 0 scbus2 target 0 lun 0
Dec 13 22:17:09 freenas kernel: ada2:  ATA-9 SATA 3.x device
Dec 13 22:17:09 freenas kernel: ada2: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
Dec 13 22:17:09 freenas kernel: ada2: Command Queueing enabled
Dec 13 22:17:09 freenas kernel: ada2: 2861588MB (5860533168 512 byte sectors: 16H 63S/T 16383C)
Dec 13 22:17:09 freenas kernel: ada2: quirks=0x1<4K>
Dec 13 22:17:09 freenas kernel: ada2: Previously was known as ad8
Dec 13 22:17:09 freenas kernel: SMP: AP CPU #1 Launched!
Dec 13 22:17:09 freenas kernel: Timecounter "TSC-low" frequency 1450042036 Hz quality 1000
Dec 13 22:17:09 freenas kernel: uhub0: 8 ports with 8 removable, self powered
Dec 13 22:17:09 freenas kernel: uhub1: 2 ports with 2 removable, self powered
Dec 13 22:17:09 freenas kernel: uhub2: 2 ports with 2 removable, self powered
Dec 13 22:17:09 freenas kernel: Root mount waiting for: usbus2 usbus1
Dec 13 22:17:09 freenas kernel: ugen1.2:  at usbus1
Dec 13 22:17:09 freenas kernel: uhub3:  on usbus1
Dec 13 22:17:09 freenas kernel: ugen2.2:  at usbus2
Dec 13 22:17:09 freenas kernel: uhub4:  on usbus2
Dec 13 22:17:09 freenas kernel: Root mount waiting for: usbus2 usbus1
Dec 13 22:17:09 freenas kernel: uhub3: 6 ports with 6 removable, self powered
Dec 13 22:17:09 freenas kernel: uhub4: 8 ports with 8 removable, self powered
Dec 13 22:17:09 freenas kernel: Root mount waiting for: usbus2
Dec 13 22:17:09 freenas kernel: ugen2.3:  at usbus2
Dec 13 22:17:09 freenas kernel: umass0:  on usbus2
Dec 13 22:17:09 freenas kernel: Trying to mount root from ufs:/dev/ufs/FreeNASs1a [ro]...
Dec 13 22:17:09 freenas kernel: mountroot: waiting for device /dev/ufs/FreeNASs1a ...
Dec 13 22:17:09 freenas kernel: da0 at umass-sim0 bus 0 scbus3 target 0 lun 0
Dec 13 22:17:09 freenas kernel: da0:  Fixed Direct Access SCSI-6 device
Dec 13 22:17:09 freenas kernel: da0: 40.000MB/s transfers
Dec 13 22:17:09 freenas kernel: da0: 7633MB (15633408 512 byte sectors: 255H 63S/T 973C)
Dec 13 22:17:09 freenas kernel: da0: quirks=0x2
Dec 13 22:17:09 freenas kernel: ZFS filesystem version: 5
Dec 13 22:17:09 freenas kernel: ZFS storage pool version: features support (5000)
Dec 13 22:17:09 freenas kernel: GEOM_RAID5: Module loaded, version 1.1.20110927.40 (rev 00ce00e5abb4)
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Device ada1p1.eli created.
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Encryption: AES-XTS 256
Dec 13 22:17:09 freenas kernel: GEOM_ELI:    Crypto: software
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Device ada2p1.eli created.
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Encryption: AES-XTS 256
Dec 13 22:17:09 freenas kernel: GEOM_ELI:    Crypto: software
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Device ada0p1.eli created.
Dec 13 22:17:09 freenas kernel: GEOM_ELI: Encryption: AES-XTS 256
Dec 13 22:17:09 freenas kernel: GEOM_ELI:    Crypto: software
Dec 13 22:17:09 freenas root: /etc/rc: WARNING: failed precmd routine for vmware_guestd
Dec 13 22:17:09 freenas ntpd[1793]: ntpd 4.2.4p5-a (1)
Dec 13 22:17:09 freenas kernel: re0: link state changed to UP
Dec 13 22:17:10 freenas proftpd[2062]: 127.0.0.1 - ProFTPD 1.3.4c (maint) (built Tue Aug 27 2013 07:56:15 UTC) standalone mode STARTUP
Dec 13 22:17:15 freenas avahi-daemon[2799]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
Dec 13 22:17:15 freenas INADYN[2819]: Fri Dec 13 22:17:15 2013: W:INADYN: IP address for alias 'xxxxxxxxxxx.no-ip.biz:auto' needs update to 'xx.xx.xx.xx'...
Dec 13 22:17:16 freenas INADYN[2819]: Fri Dec 13 22:17:16 2013: W:INADYN: Alias 'xx.xx.xx.xx.no-ip.biz' to IP 'xx.xx.xx.xx' updated successfully.
Dec 13 22:17:16 freenas INADYN[2819]: Fri Dec 13 22:17:16 2013: W:INADYN: DYNDNS Server response: HTTP/1.1 200 OK^M Date: Fri, 13 Dec 2013 21:17:16 GMT^M Server: Apache/2^M Content-Location: update.php^M Vary: negotiate^M TCN: choice^M Content-Length: 19^M Connection: close^M Content-Type: text/plain; charset=UTF-8^M ^M nochg 81.249.42.154
Dec 13 22:17:16 freenas kernel: bridge0: Ethernet address: 02:57:8c:50:a0:00
Dec 13 22:17:16 freenas kernel: bridge0: link state changed to UP
Dec 13 22:17:16 freenas kernel: re0: promiscuous mode enabled
Dec 13 22:17:16 freenas kernel: epair0a: Ethernet address: 02:90:6b:00:08:0a
Dec 13 22:17:16 freenas kernel: epair0b: Ethernet address: 02:90:6b:00:09:0b
Dec 13 22:17:16 freenas kernel: epair0a: link state changed to UP
Dec 13 22:17:16 freenas kernel: epair0b: link state changed to UP
Dec 13 22:17:16 freenas kernel: re0: link state changed to DOWN
Dec 13 22:17:16 freenas kernel: epair0a: promiscuous mode enabled
Dec 13 22:17:17 freenas ntpd[1794]: sendto(xx.xx.xx.xx) (fd=22): No route to host
Dec 13 22:17:17 freenas ntpd[1794]: bind() fd 28, family AF_INET6, port 123, scope 8, addr fe80::90:6bff:fe00:80a, mcast=0 flags=0x11 fails: Can't assign requested address
Dec 13 22:17:17 freenas ntpd[1794]: unable to create socket on epair0a (7) for fe80::90:6bff:fe00:80a#123
Dec 13 22:17:20 freenas kernel: re0: link state changed to UP
Dec 13 22:17:42 freenas manage.py: [common.pipesubr:57] Popen()ing: /usr/local/bin/warden list  -v
Dec 13 22:17:42 freenas last message repeated 2 times
Dec 13 22:17:44 freenas manage.py: [py.warnings:193] /usr/local/lib/python2.7/site-packages/django/http/request.py:193: DeprecationWarning: HttpRequest.raw_post_data has been deprecated. Use HttpRequest.body instead.  warnings.warn('HttpRequest.raw_post_data has been deprecated. Use HttpRequest.body instead.', DeprecationWarning)
Dec 13 22:17:44 freenas manage.py: [common.pipesubr:57] Popen()ing: /usr/local/bin/warden list  -v
Dec 13 22:17:44 freenas manage.py: [common.pipesubr:57] Popen()ing: /usr/local/bin/warden list  -v
Dec 13 22:41:32 freenas manage.py: [common.pipesubr:57] Popen()ing: /usr/local/bin/warden list  -v
Dec 13 22:47:38 freenas last message repeated 9 times
Dec 14 00:20:16 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 e8 fa ea 40 0a 00 00 00 00 00
Dec 14 00:20:16 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 00:20:16 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 00:20:16 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 e8 fa ea 40 0a 00 00 00 00
Dec 14 00:20:16 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 01:25:13 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 98 a0 eb 40 0a 00 00 00 00 00
Dec 14 01:25:13 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 01:25:13 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 01:25:13 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 98 a0 eb 40 0a 00 00 00 00
Dec 14 01:25:13 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 02:00:13 freenas kernel: (ada0:ahcich0:0:0:0): READ_FPDMA_QUEUED. ACB: 60 08 20 25 40 40 b8 00 00 00 00 00
Dec 14 02:00:13 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 02:00:13 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 40 (UNC )
Dec 14 02:00:13 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 40 20 25 40 40 b8 00 00 00 00
Dec 14 02:00:13 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 02:00:14 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs snapshot -r Volume1/toto@auto-20131214.0200-1m
Dec 14 02:00:14 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131113.0200-1m
Dec 14 02:00:14 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131113.0200-1m
Dec 14 02:00:14 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131112.0400-1m
Dec 14 02:00:14 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131112.0400-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131112.0500-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131112.0500-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131113.0600-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131113.0600-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131113.0400-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131113.0400-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131112.0600-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131112.0600-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131113.0500-1m
Dec 14 02:00:15 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131113.0500-1m
Dec 14 02:00:16 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs get -H freenas:state Volume1/toto@auto-20131113.0300-1m
Dec 14 02:00:16 freenas autosnap.py: [tools.autosnap:57] Popen()ing: /sbin/zfs destroy -r Volume1/toto@auto-20131113.0300-1m
Dec 14 02:40:13 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 08 6b 40 40 38 00 00 00 00 00
Dec 14 02:40:13 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 02:40:13 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 02:40:13 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 08 6b 40 40 38 00 00 00 00
Dec 14 02:40:13 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 03:50:15 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 f0 40 ee 40 0a 00 00 00 00 00
Dec 14 03:50:15 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 03:50:15 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 03:50:15 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 f0 40 ee 40 0a 00 00 00 00
Dec 14 03:50:15 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 04:30:17 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 60 4d ee 40 0a 00 00 00 00 00
Dec 14 04:30:17 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 04:30:17 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 04:30:17 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 60 4d ee 40 0a 00 00 00 00
Dec 14 04:30:17 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 04:50:15 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 00 94 40 40 38 00 00 00 00 00
Dec 14 04:50:15 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 04:50:15 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 04:50:15 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 00 94 40 40 38 00 00 00 00
Dec 14 04:50:15 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command
Dec 14 06:55:33 freenas manage.py: [common.pipesubr:57] Popen()ing: /usr/local/bin/warden list  -v
Dec 14 06:55:34 freenas last message repeated 4 times
Dec 14 07:11:13 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 38 79 ee 40 0a 00 00 00 00 00
Dec 14 07:11:13 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 07:11:13 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 07:11:13 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 38 79 ee 40 0a 00 00 00 00
Dec 14 07:11:13 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command


As you can see the error continue to occure "randomly", every several hour, which made the troubleshooting boring.

I will try to connect the drive on another SATA port.
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
I have swap SATA port 1 and 2, which are both 6Gbps ports. just swap HDD on the mobo side, so each SATA cable stay with the associated drive.
before swap:
ada0 was disc1 (the "defective" one)
ada1 was disc2 (no trouble with that one)
After swap:
ada0 is disc2 (no trouble with that one)
ada1 is disc1 (the "defective" one)
The result:
Code:
Dec 14 10:45:15 freenas kernel: (ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 98 b5 95 40 05 00 00 00 00 00
Dec 14 10:45:15 freenas kernel: (ada1:ahcich1:0:0:0): CAM status: ATA Status Error
Dec 14 10:45:15 freenas kernel: (ada1:ahcich1:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 10:45:15 freenas kernel: (ada1:ahcich1:0:0:0): RES: 41 10 98 b5 95 40 05 00 00 00 00
Dec 14 10:45:15 freenas kernel: (ada1:ahcich1:0:0:0): Retrying command

So the trouble follow the Drive and the associated SATA cable.
I will now swap only SATA cable...
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
And the result:
Code:
Dec 14 11:40:14 freenas kernel: (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 00 a5 95 40 05 00 00 00 00 00
Dec 14 11:40:14 freenas kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
Dec 14 11:40:14 freenas kernel: (ada0:ahcich0:0:0:0): ATA status: 41 (DRDY ERR), error: 10 (IDNF )
Dec 14 11:40:14 freenas kernel: (ada0:ahcich0:0:0:0): RES: 41 10 00 a5 95 40 05 00 00 00 00
Dec 14 11:40:14 freenas kernel: (ada0:ahcich0:0:0:0): Retrying command

So the trouble follow the SATA cable.
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
So weird that you'd get cable errors but no UDMA errors from SMART. Never seen anything like that. At least the problem is solved. :)
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
So weird that you'd get cable errors but no UDMA errors from SMART. Never seen anything like that. At least the problem is solved. :)
I've have cross my eyes :confused: , because I swap 2 times the cable: on mobo side and on drive side!
pretty sure this the drive. Confirm it in few minutes (if the trouble reappear quickly).
I'm so excited to find the trouble and to share my bad experience that I've post too fast without double check of what I've done...
Sorry about that.:oops:
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
I have replaced the SATA cable with a brand new one, and the trouble continu to follow the drive, so it confirm the trouble is related to the drive.

So I have to RMA this drive again. As there isn't any SMART error it will be difficult to demonstrate to Werstern Digital that their Recertified Drive is in failure.
As the drive just arrive from WD as tested, I doubt they can reproduce and find the failure, so the warranty not apply and that they charge it.
This the third Red drive I receive which is DOA (for a need of 9 healthy drives). The NAS appliance and extended warranty arguments for the RED series were good for me, but my little experience with this serie let me think that this isn't a good choice. I was convinced it is due to the poor packaging of the Web distributors, but even from WD you can receive a defective parts. I'm a little bit disappointed.

I think you can mark this thread as Solved.
Thanks to Cyberjock and joeschmuck for their support.
 

joeschmuck

Old Man
Moderator
Joined
May 28, 2011
Messages
9,048
Wow, the drive was the cause, odd as Cyberjock said since you had no other indications. The firmware for your drive matches my drives so it's not a firmware issue. I noticed the 193 Load_Cycle_Count is 609 which is very high for a drive with very few hours on it. My value for the Load_Cycle_count is 248 and I have over 10,000 hours on the drive. This makes me wonder about your setup for the drives. These drives are designed to run 24/7, so spin down. Here is a screen capture of my setup, does yours look similar?
Capture.JPG


Lastly I noticed all the values reported with smartctl were as if the drive were new. Did you say this was a refurbished drive or just a replacement drive? Normally a refurbished drive will say so on the new label.
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
Here my setup on my oldest system (april 2013)
Code:
ada5	WD-WCC3007xxxxx	Disc6	Auto	120	1	Disabled	true	-a
ada4	WD-WMC4M10xxxxx	Disc5	Auto	120	1	Disabled	true	-a
ada3	WD-WCC3007xxxxx	Disc4	Auto	120	1	Disabled	true	-a
ada2	WD-WMC3013xxxxx	Disc3	Auto	120	1	Disabled	true	-a
ada1	WD-WMC3012xxxxx	Disc2	Auto	120	1	Disabled	true	-a
ada0	WD-WMC3012xxxxx	Disc1	Auto	120	1	Disabled	true	-a


I've have check the load cycle count on ada0 which is one of the oldest drive I own, and the value is 42 for 5651 power on hours.
As I have a jail, I think the drives never spin-down. Perhaps It is better to disable the power management. I have read some thread about that, but it isn't perfectly clear in my head.

Concerning the load cycle value of the defective drive, thanks for your discernment, cause I don't have seen this important detail (and evil is on detail). And I'm agree with you, this value is very strange (I have receive it this week). This is another good argument to require a warranty replacement without charge.
And I confirm this is a refurbished drive. WD call it and label it as "recertified", without joke...
 

joeschmuck

Old Man
Moderator
Joined
May 28, 2011
Messages
9,048
I would change the sleep value to Always On for FreeNAS 9.1 and above. With 8.x you could reliably sleep your drives if you knew what your system was doing but in 9.1 and greater, the plugins are in my opinion causing significant disk access so your drives either sleep for a short period of time or they don't sleep at all. I would recommend you look at your other drives to see what the Start_Stop_Count value is with respect to the Power_On_Hours value. From what I've read, frequent spinning up of your drive lead to an early failure of the drive. Also if your drives all sleep at the same time and then all wake up at the same time (not staggered spinups) then that is more stress on the power supply as well.

This is just food for thought, nothing more.

I'm just a bit surprised I guess that the refurbished drive was completely reset to zero. I've never checked that data on a refurbished drive myself but I will on my next one.

Good luck and I hope WD replaces that drive without issue.
 

Starpulkka

Member
Joined
Apr 9, 2013
Messages
179
(I have my own data that tells me that refurbished drives dont last long as a new drives. Got 3 refurbished died 2 months after warranty and other 3 still keeps spinning.)
But to the point i was in hdd repair course and wd drives had to have somekind of hiccups on power spikes or power related broblems. So if next drive keeps troubling id be lookin for powersupply or sata port fault.
 

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560

SmallGuy

Neophyte Sage
Joined
Jun 7, 2013
Messages
560
I have replace the defective drive by a new one yesterday, and so far so good.:)
 

wizpig64

Neophyte
Joined
Aug 3, 2011
Messages
11
Sorry for the bump, but I just wanted to add this for other googlers like me who had these messages. I have a drive that was removed from its pool because of write errors (a WD Green WD20EARX soon to be replaced with a Red). Rebooting the system with the drive still plugged in caused the "CAM status: ATA Status Error" kernel errors while booting. I was going to go unplug the drive to get it to boot properly, but after not getting around to that for 10 minutes the machine gave up on the drive and continued the normal boot process to let me into the webgui.

So if you're getting "CAM status: ATA Status Error" on boot, give it 10 minutes or so and it should continue, but it probably means you have a bad drive.
 

norbee007

Newbie
Joined
Sep 4, 2016
Messages
1
Hello guys, I have the same problem as in OP. I have 2X WD RED 2 TB and I created one big partition of them in Freenas 9.3 (STABLE-201512121950) (I don't remember the correct term, sorry, I built it a long time ago), the HDDs are around 2-3 years old. I tried to change the cables, but nothing happened.
My main problem is that Freenas isn't booting up, and I can't write any commands in grub, because te Ata Stasus Error repeats itself endlessly (sorry, I'm a noob). I already acknowledged the fact that I am going to have major data loss, and have to replace one of the drives. However, please help me in backing up the healthy device. Linux Mint (in live mode) have been able to see them seperately in Gparted, but it can't mount them. I tried FreeBSD and a few variants in live mode, but I couldn't get them to boot.
My config:
ASUS J1900-C



Any ideas is going to be appriciated! Thanks in advance!
 

SweetAndLow

Sweet'NASty
Joined
Nov 6, 2013
Messages
6,352
Looks like your boot device has failed. Replace it and upload configuration file to get back up and running.

Sent from my Nexus 5X using Tapatalk
 
Status
Not open for further replies.
Top