problem with aac0 on FreeBSD 5.4 Stable#5

Tue Sep 27 14:51:00 PDT 2005

>Synopsis:      aac driver hangs under load
>Description:

I am having the same/very similiar problem as described in
http://lists.freebsd.org/pipermail/freebsd-current/2004-December/044613.html.

I have 2  identical boxes "dell poweredge 1750", with Atapdec raid
controller <Adaptec SCSI RAID 2200S> and external powervault 220s.

Everything is fine on FreeBSD 5.3 Stable #7 (the box has been 6 month
under load)

On FreeBSD 5.4 Stable #5 the aac0 hangs once a fortnight, alway during
large file copy operations (Mysql database running optimize on all
tables,one after another), several Gigabyte of data)

(The box also has a amr controlled raid (as boot partition and /var
/usr). I had one occasion, where the disks on the amr became
inaccessable, since this are the boot and logging disks, there is no
data about that)

Not exactly sure, what else to attach, thankfull for any advice.

Here are the relevant parts from the message log
1) Errors
2) Boot msgs

Sep 26 04:07:17 db02 kernel: aac0: COMMAND 0xc4f816d8 TIMEOUT AFTER 47
SECONDS
Sep 26 04:07:17 db02 kernel: aac0: COMMAND 0xc4f7fa40 TIMEOUT AFTER 47
SECONDS
Sep 26 04:07:17 db02 kernel: aac0: COMMAND 0xc4f7ece4 TIMEOUT AFTER 47
SECONDS
Sep 26 04:07:17 db02 kernel: aac0: WARNING! Controller is no longer
running! code= 0x100
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f816d8 TIMEOUT AFTER 67
SECONDS
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f7fa40 TIMEOUT AFTER 67
SECONDS
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f7ece4 TIMEOUT AFTER 67
SECONDS
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f7f068 TIMEOUT AFTER 46
SECONDS
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f7e384 TIMEOUT AFTER 46
SECONDS
Sep 26 04:07:37 db02 kernel: aac0: COMMAND 0xc4f815ac TIMEOUT AFTER 46
SECONDS

continued as above, until reboot

Sep 26 12:35:49 db02 kernel: Copyright (c) 1992-2005 The FreeBSD Project.
Sep 26 12:35:49 db02 kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988,
1989, 1991, 1992, 1993, 1994
Sep 26 12:35:49 db02 kernel: The Regents of the University of
California. All rights reserved.
Sep 26 12:35:49 db02 kernel: FreeBSD 5.4-STABLE #5: Fri May 27 11:56:29
UTC 2005
Sep 26 12:35:49 db02 kernel:
root at db2.hybyte.net:/usr/obj/usr/src/sys/DB02
Sep 26 12:35:49 db02 kernel: Timecounter "i8254" frequency 1193182 Hz
quality 0
Sep 26 12:35:49 db02 kernel: CPU: Intel(R) Xeon(TM) CPU 3.20GHz
(3185.12-MHz 686-class CPU)
Sep 26 12:35:49 db02 kernel: Origin = "GenuineIntel"  Id = 0xf25
Stepping = 5
Sep 26 12:35:49 db02 kernel:
Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE> 

Sep 26 12:35:49 db02 kernel: Hyperthreading: 2 logical CPUs
Sep 26 12:35:49 db02 kernel: real memory  = 3892146176 (3711 MB)
Sep 26 12:35:49 db02 kernel: avail memory = 3813191680 (3636 MB)
Sep 26 12:35:49 db02 kernel: ACPI APIC Table: <DELL   PE1750  >
Sep 26 12:35:49 db02 kernel: FreeBSD/SMP: Multiprocessor System
Detected: 4 CPUs
Sep 26 12:35:49 db02 kernel: cpu0 (BSP): APIC ID:  0
Sep 26 12:35:49 db02 kernel: cpu1 (AP): APIC ID:  1
Sep 26 12:35:49 db02 kernel: cpu2 (AP): APIC ID:  6
Sep 26 12:35:49 db02 kernel: cpu3 (AP): APIC ID:  7
Sep 26 12:35:49 db02 kernel: ioapic0: Changing APIC ID to 8
Sep 26 12:35:49 db02 kernel: ioapic1: Changing APIC ID to 9
Sep 26 12:35:50 db02 kernel: ioapic2: Changing APIC ID to 10
Sep 26 12:35:50 db02 kernel: MADT: Forcing active-low polarity and level
trigger for SCI
Sep 26 12:35:50 db02 kernel: ioapic0 <Version 1.1> irqs 0-15 on motherboard
Sep 26 12:35:50 db02 kernel: ioapic1 <Version 1.1> irqs 16-31 on
motherboard
Sep 26 12:35:50 db02 kernel: ioapic2 <Version 1.1> irqs 32-47 on
motherboard
Sep 26 12:35:50 db02 kernel: npx0: <math processor> on motherboard
Sep 26 12:35:50 db02 kernel: npx0: INT 16 interface
Sep 26 12:35:50 db02 kernel: acpi0: <DELL PE1750> on motherboard
Sep 26 12:35:50 db02 kernel: acpi0: Power Button (fixed)
Sep 26 12:35:50 db02 kernel: Timecounter "ACPI-safe" frequency 3579545
Hz quality 1000
Sep 26 12:35:50 db02 kernel: acpi_timer0: <32-bit timer at 3.579545MHz>
port 0x808-0x80b on acpi0
Sep 26 12:35:50 db02 kernel: cpu0: <ACPI CPU> on acpi0
Sep 26 12:35:50 db02 kernel: cpu1: <ACPI CPU> on acpi0
Sep 26 12:35:50 db02 kernel: cpu2: <ACPI CPU> on acpi0
Sep 26 12:35:50 db02 kernel: cpu3: <ACPI CPU> on acpi0
Sep 26 12:35:50 db02 kernel: pcib0: <ACPI Host-PCI bridge> port
0xcf8-0xcff on acpi0
Sep 26 12:35:50 db02 kernel: pci0: <ACPI PCI bus> on pcib0
Sep 26 12:35:50 db02 kernel: pci0: <display, VGA> at device 14.0 (no
driver attached)
Sep 26 12:35:50 db02 kernel: atapci0: <ServerWorks CSB5 UDMA100
controller> port 0x8b0-0x8bf,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at
device 15.1 on pci0
Sep 26 12:35:50 db02 kernel: ata0: channel #0 on atapci0
Sep 26 12:35:50 db02 kernel: ata1: channel #1 on atapci0
Sep 26 12:35:50 db02 kernel: pci0: <serial bus, USB> at device 15.2 (no
driver attached)
Sep 26 12:35:50 db02 kernel: isab0: <PCI-ISA bridge> at device 15.3 on pci0
Sep 26 12:35:50 db02 kernel: isa0: <ISA bus> on isab0
Sep 26 12:35:50 db02 kernel: pcib1: <ACPI Host-PCI bridge> on acpi0
Sep 26 12:35:50 db02 kernel: pci4: <ACPI PCI bus> on pcib1
Sep 26 12:35:50 db02 kernel: amr0: <LSILogic MegaRAID 1.51> mem
0xf7f00000-0xf7f3ffff,0xe8000000-0xefffffff irq 18 at device 3.0 on pci4
Sep 26 12:35:50 db02 kernel: amr0: <LSILogic PERC 4/Di> Firmware 412W,
BIOS H406, 128MB RAM
Sep 26 12:35:50 db02 kernel: pcib2: <ACPI Host-PCI bridge> on acpi0
Sep 26 12:35:50 db02 kernel: pci3: <ACPI PCI bus> on pcib2
Sep 26 12:35:50 db02 kernel: aac0: <Adaptec SCSI RAID 2200S> mem
0xf8000000-0xfbffffff irq 24 at device 6.0 on pci3
Sep 26 12:35:50 db02 kernel: aac0: Unknown processor 100MHz, 48MB cache
memory, optional battery present
Sep 26 12:35:50 db02 kernel: aac0: Kernel 4.1-0, Build 7244, S/N b764f4
Sep 26 12:35:50 db02 kernel: aac0: Supported
Options=11d7e<CLUSTERS,WCACHE,DATA64,HOSTTIME,RAID50,WINDOW4GB,SOFTERR,SGMAP64,ALARM,NONDASD> 

Sep 26 12:35:50 db02 kernel: aacp0: <SCSI Passthrough Bus> on aac0
Sep 26 12:35:50 db02 kernel: aacp1: <SCSI Passthrough Bus> on aac0
Sep 26 12:35:50 db02 kernel: pcib3: <ACPI Host-PCI bridge> on acpi0
Sep 26 12:35:50 db02 kernel: pci2: <ACPI PCI bus> on pcib3
Sep 26 12:35:50 db02 kernel: bge0: <Broadcom BCM5704C Dual Gigabit
Ethernet, ASIC rev. 0x2002> mem
0xfcf20000-0xfcf2ffff,0xfcf30000-0xfcf3ffff irq 16 at device 0.0 on pci2
Sep 26 12:35:50 db02 kernel: miibus0: <MII bus> on bge0
Sep 26 12:35:50 db02 kernel: brgphy0: <BCM5704 10/100/1000baseTX PHY> on
miibus0
Sep 26 12:35:50 db02 kernel: brgphy0:  10baseT, 10baseT-FDX, 100baseTX,
100baseTX-FDX, 1000baseTX, 1000baseTX-FDX, auto
Sep 26 12:35:50 db02 kernel: bge0: Ethernet address: 00:11:43:5a:68:70
Sep 26 12:35:50 db02 kernel: bge1: <Broadcom BCM5704C Dual Gigabit
Ethernet, ASIC rev. 0x2002> mem
0xfcf00000-0xfcf0ffff,0xfcf10000-0xfcf1ffff irq 17 at device 0.1 on pci2
Sep 26 12:35:50 db02 kernel: miibus1: <MII bus> on bge1
Sep 26 12:35:50 db02 kernel: brgphy1: <BCM5704 10/100/1000baseTX PHY> on
miibus1
Sep 26 12:35:50 db02 kernel: brgphy1:  10baseT, 10baseT-FDX, 100baseTX,
100baseTX-FDX, 1000baseTX, 1000baseTX-FDX, auto
Sep 26 12:35:50 db02 kernel: bge1: Ethernet address: 00:11:43:5a:68:71
Sep 26 12:35:50 db02 kernel: pcib4: <ACPI Host-PCI bridge> on acpi0
Sep 26 12:35:50 db02 kernel: pci1: <ACPI PCI bus> on pcib4
Sep 26 12:35:50 db02 kernel: fdc0: <floppy drive controller> port
0x3f7,0x3f0-0x3f5 irq 6 drq 2 on acpi0
Sep 26 12:35:50 db02 kernel: fd0: <1440-KB 3.5" drive> on fdc0 drive 0
Sep 26 12:35:50 db02 kernel: atkbdc0: <Keyboard controller (i8042)> port
0x64,0x60 irq 1 on acpi0
Sep 26 12:35:50 db02 kernel: atkbd0: <AT Keyboard> irq 1 on atkbdc0
Sep 26 12:35:50 db02 kernel: kbd0 at atkbd0
Sep 26 12:35:50 db02 kernel: psm0: <PS/2 Mouse> irq 12 on atkbdc0
Sep 26 12:35:50 db02 kernel: psm0: model Generic PS/2 mouse, device ID 0
Sep 26 12:35:50 db02 kernel: sio0: <16550A-compatible COM port> port
0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Sep 26 12:35:50 db02 kernel: sio0: type 16550A
Sep 26 12:35:50 db02 kernel: orm0: <ISA Option ROMs> at iomem
0xec000-0xeffff,0xd0000-0xd17ff,0xc9000-0xcd7ff,0xc8000-0xc8fff,0xc0000-0xc7fff 

on isa0
Sep 26 12:35:50 db02 kernel: pmtimer0 on isa0
Sep 26 12:35:50 db02 kernel: sc0: <System console> at flags 0x100 on isa0
Sep 26 12:35:50 db02 kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Sep 26 12:35:50 db02 kernel: sio1: configured irq 3 not in bitmap of
probed irqs 0
Sep 26 12:35:50 db02 kernel: sio1: port may not be enabled
Sep 26 12:35:50 db02 kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df
iomem 0xa0000-0xbffff on isa0
Sep 26 12:35:50 db02 kernel: Timecounters tick every 10.000 msec
Sep 26 12:35:50 db02 kernel: IP Filter: v3.4.35 initialized.  Default =
pass all, Logging = enabled
Sep 26 12:35:50 db02 kernel: ipfw2 initialized, divert enabled,
rule-based forwarding enabled, default to accept, logging limited to
1024 packets/entry by default
Sep 26 12:35:50 db02 kernel: amrd0: <LSILogic MegaRAID logical drive> on
amr0
Sep 26 12:35:50 db02 kernel: amrd0: 34680MB (71024640 sectors) RAID 1
(optimal)
Sep 26 12:35:50 db02 kernel: aacd0: <RAID 5> on aac0
Sep 26 12:35:50 db02 kernel: aacd0: 419943MB (860045184 sectors)
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Vendor Specific
Command. CDB: 12 1 80 0 ff 0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): ILLEGAL REQUEST
asc:24,0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Invalid field in CDB
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Vendor Specific
Command. CDB: 12 1 80 0 ff 0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): ILLEGAL REQUEST
asc:24,0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Invalid field in CDB
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Vendor Specific
Command. CDB: 12 1 80 0 ff 0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): ILLEGAL REQUEST
asc:24,0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Invalid field in CDB
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Vendor Specific
Command. CDB: 12 1 80 0 ff 0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): ILLEGAL REQUEST
asc:24,0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Invalid field in CDB
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Vendor Specific
Command. CDB: 12 1 80 0 ff 0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): ILLEGAL REQUEST
asc:24,0
Sep 26 12:35:50 db02 kernel: (probe36:aacp0:0:6:0): Invalid field in CDB
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:1): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:2): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:3): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:4): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:5): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:6): AutoSense Failed
Sep 26 12:35:50 db02 kernel: (probe0:aacp0:0:6:7): AutoSense Failed
Sep 26 12:35:50 db02 kernel: ses0 at amr0 bus 0 target 6 lun 0
Sep 26 12:35:50 db02 kernel: ses0: <PE/PV 1x3 SCSI BP 1.1> Fixed
Processor SCSI-2 device
Sep 26 12:35:50 db02 kernel: ses0: SAF-TE Compliant Device
Sep 26 12:35:50 db02 kernel: ses1 at aacp0 bus 0 target 6 lun 0
Sep 26 12:35:50 db02 kernel: ses1: <DELL PV22XS E.17> Fixed unknown
SCSI-3 device
Sep 26 12:35:50 db02 kernel: ses1: 3.300MB/s transfers
Sep 26 12:35:50 db02 kernel: ses1: SAF-TE Compliant Device
Sep 26 12:35:50 db02 kernel: SMP: AP CPU #2 Launched!
Sep 26 12:35:50 db02 kernel: SMP: AP CPU #1 Launched!
Sep 26 12:35:50 db02 kernel: SMP: AP CPU #3 Launched!

>How-To-Repeat:

>Fix: