9.1-stable: ATI IXP600 AHCI: CAM timeout

Wed May 29 08:10:18 UTC 2013

Hi,

Yesterday I have downloaded the latest 9.1 snapshot (May 15th)
from ftp.freebsd.org and installed it on a machine that was
previously running Linux.  It works fine, except that I get
many the following when there is heavy disk I/O, e.g. when
building world or ports:

ahcich0: Timeout on slot 23 port 0
ahcich0: is 00000000 cs f07fffff ss ffffffff rs ffffffff tfd c0 serr 00000000 cmd 0004bc17
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 40 00 c9 e0 40 04 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command

It happens for *both* ahcich0/ada0 and ahcich1/ada1 equally
often (it's a gmirror), sometimes even at exactly the same
time so the messages for ada0 and ada1 are interleaved in
the dmesg output.

The worst thing is that the whole system seems to freeze
completely for about 10 seconds each time it happens.
Other than that, I haven't seen any ill effects, i.e. no
processes dying and no panics (so far).  But the system is
quite unusable because of the freezes.

I'm pretty sure the hardware has no defects.  The machine
was running Linux fine until recently.

Are there any known issues with FreeBSD + ATI IXP600?

The kernel is the default GENERIC from the snapshot, the
only additional modules loaded are geom_mirror and linux.ko.
The dmesg messages related to disks are copied below, and
the full dmesg can be found here:
http://www.secnetix.de/olli/tmp/dmesg.nox.txt

Best regards
   Oliver

FreeBSD 9.1-STABLE #0: Mon May 13 05:10:23 UTC 2013
    root at snap.freebsd.org:/usr/obj/usr/src/sys/GENERIC amd64
..
ahci0: <ATI IXP600 AHCI SATA controller> port 0xb000-0xb007,0xa000-0xa003,0x9000-0x9007,0x8000-0x8003,0x7000-0x700f mem 0xfe7ff800-0xfe7ffbff irq 22 at device 18.0 on pci0
ahci0: AHCI v1.10 with 4 3Gbps ports, Port Multiplier supported
ahcich0: <AHCI channel> at channel 0 on ahci0
ahcich1: <AHCI channel> at channel 1 on ahci0
ahcich2: <AHCI channel> at channel 2 on ahci0
ahcich3: <AHCI channel> at channel 3 on ahci0
..
..
(aprobe0:ahcich0:0:15:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe0:ahcich0:0:15:0): CAM status: Command timeout
(aprobe0:ahcich0:0:15:0): Error 5, Retries exhausted
(aprobe1:ahcich1:0:15:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
(aprobe1:ahcich1:0:15:0): CAM status: Command timeout
(aprobe1:ahcich1:0:15:0): Error 5, Retries exhausted
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <SAMSUNG HD403LJ CT100-12> ATA-8 SATA 2.x device
ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada0: Command Queueing enabled
ada0: 381554MB (781422768 512 byte sectors: 16H 63S/T 16383C)
ada0: Previously was known as ad4
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <SAMSUNG HD403LJ CT100-12> ATA-8 SATA 2.x device
ada1: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada1: Command Queueing enabled
ada1: 381554MB (781422768 512 byte sectors: 16H 63S/T 16383C)
ada1: Previously was known as ad6
..
GEOM_MIRROR: Device mirror/gm0 launched (2/2).
..
Trying to mount root from ufs:/dev/mirror/gm0s1a [rw]...
..
ahcich0: Timeout on slot 23 port 0
ahcich0: is 00000000 cs f07fffff ss ffffffff rs ffffffff tfd c0 serr 00000000 cmd 0004bc17
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 40 00 c9 e0 40 04 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
ahcich1: Timeout on slot 12 port 0
ahcich1: is 00000000 cs ffff8fff ss ffffffff rs ffffffff tfd 40 serr 00000000 cmd 0004ee17
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 20 80 85 e3 40 04 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
(ada1:ahcich1:0:0:0): Retrying command
ahcich1: Timeout on slot 2 port 0
ahcich1: is 00000000 cs 00000000 ss 0000001c rs 0000001c tfd 40 serr 00000000 cmd 0004e417
ahcich0: Timeout on slot 12 port 0
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 e0 04 e3 40 04 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
ahcich0: is 00000000 cs 00000000 ss 00007000 rs 00007000 tfd 40 serr 00000000 cmd 0004ee17
(ada1:ahcich1:0:0:0): Retrying command
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 e0 04 e3 40 04 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
pid 40615 (try), uid 0: exited on signal 10 (core dumped)
ahcich1: Timeout on slot 7 port 0
ahcich1: is 00000000 cs fffff07f ss ffffffff rs ffffffff tfd c0 serr 00000000 cmd 0004ac17
ahcich0: (ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 40 00 7d 92 40 02 00 00 00 00 00
Timeout on slot 19 port 0
(ada1:ahcich1:0:0:0): CAM status: Command timeout
ahcich0: is 00000000 cs ff07ffff ss ffffffff rs ffffffff tfd c0 serr 00000000 cmd 0004b817
(ada1:ahcich1:0:0:0): Retrying command
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 40 00 7d 92 40 02 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
ahcich1: Timeout on slot 12 port 0
ahcich1: is 00000000 cs 00000000 ss 0000f000 rs 0000f000 tfd 40 serr 00000000 cmd 0004ef17
ahcich0: Timeout on slot 24 port 0
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 20 d8 78 e4 40 04 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
ahcich0: is 00000000 cs 00000000 ss 0f000000 rs 0f000000 tfd 40 serr 00000000 cmd 0004fb17
(ada1:ahcich1:0:0:0): Retrying command
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 20 d8 78 e4 40 04 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
ahcich1: Timeout on slot 1 port 0
ahcich1: is 00000000 cs 00000000 ss 0000003e rs 0000003e tfd 40 serr 00000000 cmd 0004e517
ahcich0: Timeout on slot 13 port 0
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 30 e0 e4 40 04 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: Command timeout
ahcich0: is 00000000 cs 00000000 ss 0003e000 rs 0003e000 tfd 40 serr 00000000 cmd 0004f117
(ada1:ahcich1:0:0:0): Retrying command
(ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 08 30 e0 e4 40 04 00 00 00 00 00
(ada0:ahcich0:0:0:0): CAM status: Command timeout
(ada0:ahcich0:0:0:0): Retrying command
..
..

-- 
Oliver Fromme,  secnetix GmbH & Co. KG,  Marktplatz 29, 85567 Grafing
Handelsregister:  Amtsgericht Muenchen, HRA 74606, Geschäftsfuehrung:
secnetix Verwaltungsgesellsch. mbH, Handelsreg.: Amtsgericht München,
HRB 125758, Geschäftsführer:  Maik Bachmann,  Olaf Erb,  Ralf Gebhart

FreeBSD-Dienstleistungen/-Produkte + mehr: http://www.secnetix.de/bsd

"The most important decision in [programming] language design
concerns what is to be left out."  --  Niklaus Wirth