Subject: very strange "temporary" filesytem lockups on netbsd-4 (i386)
To: NetBSD Kernel Technical Discussion List <tech-kern@NetBSD.org>
From: Greg A. Woods <woods@planix.com>
List: tech-kern
Date: 02/17/2007 22:58:32
I've been experimenting with the netbsd-4 branch on a dual-CPU Dell
PowerEdge 2650 (my new build server) with its embedded Dell PERC 3/Di
RAID controller, and an add-in HP NetRAID-4M controller for some
external disks.  Both of course are detected and managed by the aac(4)
driver.  Appended is a dmesg.  If anyone has any suggestions, patches,
etc., please let me know!

The install was done from a build of the netbsd-4 branch that I did on a
host running netbsd-3.  There are no local kernel changes other than to
the text of a few of the error messages in sys/dev/ic/pckbc.c.  The
GENERIC.MPACPI kernel is the same config, verbatim, from the official
tree.

I've been attempting to rebuild the netbsd-4 branch on the new machine.

However I've been experiencing frequent, but temporary, filesystem
lockups, typically during bursts of I/O to and from the /build
filesystem, such as when linking or installing a program.  The process
that gets stuck seems to be in the getblk state:

# ps -lww9442
 UID   PID  PPID   CPU PRI NI VSZ RSS WCHAN  STAT TTY      TIME COMMAND
1000  9942   586 49260  -5  0 312 320 getblk D    ttyp1 0:00.00 /build/woods/once/netbsd-4-i386-i386-tools/bin/nbinstall -U -M /build/woods/once/netbsd-4-i386-ppro-destdir/METALOG -D /build/woods/once/netbsd-4-i386-ppro-destdir -h sha1 -N /building/work/woods/m-NetBSD-4/etc -c -p -r -o root -g wheel -m 555 ed /build/woods/once/netbsd-4-i386-ppro-destdir/bin/ed 

Direct attempts to access the same file that seems to have become stuck
(or sometimes anything else on that same filesystem, even a df) result
in the second process blocking in the vnlock state.

This stuck state can exist for hours, but so far it hasn't hung the
whole system and it always eventually gets unstuck one way or another.

Sometimes additional activity, such as logging in in another window
(which doesn't access the stuck filesystem) unsticks everything and away
it all goes again just as fast and happy as if nothing had happened.

When discussing this with my colleague Andreas he suggested that perhaps
there's a missing interrupt causing the particular IO stream to get
stuck.  I don't know the path to/from the getblk state, but that seems
like a good idea for starters.

In the BIOS I did manually re-route the interrupt for the add-on NetRAID
controller so that it wouldn't be sharing the same interrupt as the
on-board controller.  The best available choice seemed to be to put it on
the same IRQ as the second ethernet.  I forget the exact details of what
I did and unfortunately the BIOS console redirection doesn't work well
enough to let me go find them at the moment.  Everything else in the
BIOS settings should be pretty standard, except for enabling the (mostly
broken) console re-direction to the first serial port.

One thing that worries me a lot is that the aac(4) driver is very
out-of-date with its original sources.  It really would be very nice to
get it updated from FreeBSD again!


Now here's a weird issue that may or may not be related.  The add-on
NetRAID-4M controller doesn't seem to work from NetBSD.  I've swapped it
with a spare and it still "fails" in exactly the same way so I'm pretty
sure it's a NetBSD problem, though I've been unable to test it from
anything else (one lame attempt to boot a FreeNAS-0.68 CD resulted in a
kernel panic before anything got anywhere, and I've yet to try a full
recent FreeBSD boot).

The NetRAID controller, from its BIOS, can create a container (in my
test case a 10-disk RAID-5 array made up of 9GB drives), recover a
failed disk, and even recover a failed container initialization.

Writes to the array work just fine.

Reads from the array always return blocks of zeros.

No errors are reported.

The only weird thing I see are occasional random disk accesses even when
the array should be quiescent.  (I don't see anything like this from the
built-in Dell 

# dd if=/dev/rld0d of=/dev/rld1d bs=2m 
^?157+0 records in
156+0 records out
327155712 bytes transferred in 9.552 secs (34249969 bytes/sec)

# dd if=/dev/rld1d bs=2m | od -c       
0000000   \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0  \0
*
^?39+0 records in
38+0 records out
79691776 bytes transferred in 3.230 secs (24672376 bytes/sec)


Note in the following the NetRAID-4M is the spare -- the first one I
was testing didn't have a low battery, and perhaps/hopefully this one
will eventually recharge itself too.  Here's the diff between the two of
them:

192,194c210,212
< aac1: StrongARM SA110 at 233MHz, 80MB mem (64MB cache), required battery present
< aac1: Kernel 2.3-1 [Build 3978], Monitor 2.3-1 [Build 3978], S/N 89F6CB
< aac1: Controller supports: 1d<SNAPSHOT,WCACHE,DATA64,HOSTTIME>
---
> aac1: StrongARM SA110 at 233MHz, 144MB mem (128MB cache), required battery present
> aac1: Kernel 2.4-1 [Build 4607], Monitor 2.4-1 [Build 4607], S/N 8A1A4F
> aac1: Controller supports: 17f<SNAPSHOT,CLUSTERS,WCACHE,DATA64,HOSTTIME,RAID50,WINDOW4GB,SOFTERR>


(BTW, it might be nice if sysinst could notice that the system would do
best with an ACPI kernel (GENERIC won't even boot on this machine) and
install that as /netbsd!)


# cat /var/run/dmesg.boot
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005, 2006
    The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 4.0_BETA2 (GENERIC.MPACPI) #0: Thu Feb 15 12:15:32 EST 2007
        woods@always:/build/woods/always/netbsd-4-i386-i386-ppro-obj/building/work/woods/m-NetBSD-4/sys/arch/i386/compile/GENERIC.MPACPI
total memory = 3839 MB
avail memory = 3762 MB
timecounter: Timecounters tick every 10.000 msec
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
BIOS32 rev. 0 found at 0xffe90
mainbus0 (root)
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel Xeon (686-class), 2385.55 MHz, id 0xf27
cpu0: features bfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR>
cpu0: features bfebfbff<PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX>
cpu0: features bfebfbff<FXSR,SSE,SSE2,SS,HTT,TM,SBF>
cpu0: features2 400<CID>
cpu0: "Intel(R) Xeon(TM) CPU 2.40GHz"
cpu0: I-cache 12K uOp cache 8-way, D-cache 8 KB 64B/line 4-way
cpu0: L2 cache 512 KB 64B/line 8-way
cpu0: ITLB 4K/4M: 64 entries
cpu0: DTLB 4K/4M: 64 entries
cpu0: enabling thermal monitor 1 ... enabled.
cpu0: calibrating local timer
cpu0: apic clock running at 99 MHz
cpu0: 16 page colors
cpu1 at mainbus0: apid 2 (application processor)
cpu1: starting
cpu1: Intel Xeon (686-class), 2385.45 MHz, id 0xf27
cpu1: features bfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR>
cpu1: features bfebfbff<PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX>
cpu1: features bfebfbff<FXSR,SSE,SSE2,SS,HTT,TM,SBF>
cpu1: features2 400<CID>
cpu1: "Intel(R) Xeon(TM) CPU 2.40GHz"
cpu1: I-cache 12K uOp cache 8-way, D-cache 8 KB 64B/line 4-way
cpu1: L2 cache 512 KB 64B/line 8-way
cpu1: ITLB 4K/4M: 64 entries
cpu1: DTLB 4K/4M: 64 entries
cpu1: using thermal monitor 1
cpu2 at mainbus0: apid 1 (application processor)
cpu2: starting
cpu2: Intel Xeon (686-class), 2385.45 MHz, id 0xf27
cpu2: features bfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR>
cpu2: features bfebfbff<PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX>
cpu2: features bfebfbff<FXSR,SSE,SSE2,SS,HTT,TM,SBF>
cpu2: features2 400<CID>
cpu2: "Intel(R) Xeon(TM) CPU 2.40GHz"
cpu2: I-cache 12K uOp cache 8-way, D-cache 8 KB 64B/line 4-way
cpu2: L2 cache 512 KB 64B/line 8-way
cpu2: ITLB 4K/4M: 64 entries
cpu2: DTLB 4K/4M: 64 entries
cpu2: using thermal monitor 1
cpu3 at mainbus0: apid 3 (application processor)
cpu3: starting
cpu3: Intel Xeon (686-class), 2385.46 MHz, id 0xf27
cpu3: features bfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR>
cpu3: features bfebfbff<PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX>
cpu3: features bfebfbff<FXSR,SSE,SSE2,SS,HTT,TM,SBF>
cpu3: features2 400<CID>
cpu3: "Intel(R) Xeon(TM) CPU 2.40GHz"
cpu3: I-cache 12K uOp cache 8-way, D-cache 8 KB 64B/line 4-way
cpu3: L2 cache 512 KB 64B/line 8-way
cpu3: ITLB 4K/4M: 64 entries
cpu3: DTLB 4K/4M: 64 entries
cpu3: using thermal monitor 1
ioapic0 at mainbus0 apid 4 (I/O APIC)
ioapic0: pa 0xfec00000, version 11, 16 pins
ioapic0: misconfigured as apic 0
ioapic0: remapped to apic 4
ioapic1 at mainbus0 apid 5 (I/O APIC)
ioapic1: pa 0xfec01000, version 11, 16 pins
ioapic1: misconfigured as apic 0
ioapic1: remapped to apic 5
ioapic2 at mainbus0 apid 6 (I/O APIC)
ioapic2: pa 0xfec02000, version 11, 16 pins
ioapic2: misconfigured as apic 0
ioapic2: remapped to apic 6
acpi0 at mainbus0: Advanced Configuration and Power Interface
acpi0: using Intel ACPI CA subsystem version 20060217
acpi0: X/RSDT: OemId <DELL  ,PE2650  ,00000001>, AslId <MSFT,0100000a>
acpi0: SCI interrupting at int 9
acpi0: fixed-feature power button present
timecounter: Timecounter "ACPI-Fast" frequency 3579545 Hz quality 1000
ACPI-Fast 32-bit timer
LUSB: ACPI: Found matching pin for 0.15.INTA at func 2: 5
ACPI Object Type 'Processor' (0x0c) at acpi0 not configured
ACPI Object Type 'Processor' (0x0c) at acpi0 not configured
ACPI Object Type 'Processor' (0x0c) at acpi0 not configured
ACPI Object Type 'Processor' (0x0c) at acpi0 not configured
PNP0A03 [PCI/PCI-X Host Bridge] at acpi0 not configured
PNP0200 [AT DMA Controller] at acpi0 not configured
npx0 at acpi0 (PNP0C04)
npx0: io 0xf0-0xff irq 13
npx0: reported by CPUID; using exception 16
PNP0000 [AT Interrupt Controller] at acpi0 not configured
pcppi1 at acpi0 (PNP0800)
pcppi1: io 0x61
pcppi1: children must have an explicit unit
midi0 at pcppi1: PC speaker (CPU-intensive output)
sysbeep0 at pcppi1
attimer1 at acpi0 (PNP0100): AT Timer
attimer1: io 0x40-0x5f irq 0
fdc0 at acpi0 (PNP0700)
fdc0: io 0x3f0-0x3f5,0x3f7 irq 6 drq 2
pckbc0 at acpi0 (PNP0303): kbd port
pckbc0: io 0x60,0x64 irq 1
pckbc1 at acpi0 (PNP0F13): aux port
pckbc1: irq 12
com0 at acpi0 (PNP0501-1)
com0: io 0x3f8-0x3ff irq 4
com0: ns16550a, working fifo
com0: console
com1 at acpi0 (PNP0501-2)
com1: io 0x2f8-0x2ff irq 3
com1: ns16550a, working fifo
PNP0B00 [AT Real-Time Clock] at acpi0 not configured
PNP0C01 [System Board] at acpi0 not configured
PNP0C01 [System Board] at acpi0 not configured
PNP0A03 [PCI/PCI-X Host Bridge] at acpi0 not configured
PNP0A03 [PCI/PCI-X Host Bridge] at acpi0 not configured
PNP0A03 [PCI/PCI-X Host Bridge] at acpi0 not configured
PNP0A03 [PCI/PCI-X Host Bridge] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
PNP0C0F [PCI interrupt link device] at acpi0 not configured
pcppi1: attached to attimer1
pckbd0 at pckbc0 (kbd slot)
pckbc0: using irq 1 for kbd slot
wskbd0 at pckbd0 mux 1
pci0 at mainbus0 bus 0: configuration mode 1
pci0: i/o space, memory space enabled, rd/line, rd/mult, wr/inv ok
pchb0 at pci0 dev 0 function 0
pchb0: ServerWorks CNB30-HE PCI bridge (rev. 0x13)
pchb1 at pci0 dev 0 function 1
pchb1: ServerWorks CNB30-HE PCI bridge (rev. 0x00)
pchb2 at pci0 dev 0 function 2
pchb2: ServerWorks product 0x0000 (rev. 0x00)
pchb2: unknown ServerWorks chip ID 0x0000; trying to attach PCI buses behind it
Dell Computer product 0x000c (undefined subclass 0x00) at pci0 dev 4 function 0 not configured
Dell Computer PERC 3/Di (undefined subclass 0x00) at pci0 dev 4 function 1 not configured
Dell Computer product 0x000d (undefined subclass 0x00) at pci0 dev 4 function 2 not configured
vga0 at pci0 dev 14 function 0: ATI Technologies Rage XL (rev. 0x27)
wsdisplay0 at vga0 kbdmux 1
wsmux1: connecting to wsdisplay0
wskbd0: connecting to wsdisplay0
pchb3 at pci0 dev 15 function 0
pchb3: ServerWorks CSB5 southbridge (rev. 0x93)
rccide0 at pci0 dev 15 function 1
rccide0: ServerWorks CSB5 IDE Controller (rev. 0x93)
rccide0: bus-master DMA support present
rccide0: primary channel configured to compatibility mode
rccide0: primary channel interrupting at ioapic0 pin 14 (irq 14)
atabus0 at rccide0 channel 0
rccide0: secondary channel wired to compatibility mode
rccide0: secondary channel interrupting at ioapic0 pin 15 (irq 15)
atabus1 at rccide0 channel 1
ohci0 at pci0 dev 15 function 2: ServerWorks OSB4/CSB5 USB Host Controller (rev. 0x05)
ohci0: interrupting at ioapic0 pin 5 (irq 5)
ohci0: OHCI version 1.0, legacy support
usb0 at ohci0: USB revision 1.0
uhub0 at usb0
uhub0: ServerWorks OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 4 ports with 4 removable, self powered
pcib0 at pci0 dev 15 function 3
pcib0: ServerWorks CSB5 ISA/LPC bridge (rev. 0x00)
pchb4 at pci0 dev 16 function 0
pchb4: ServerWorks CIOB-X2 PCI-X bridge (rev. 0x03)
pci1 at pchb4 bus 3
pci1: i/o space, memory space enabled
bge0 at pci1 dev 6 function 0: Broadcom BCM5701 Gigabit Ethernet
bge0: interrupting at ioapic1 pin 12 (irq 10)
bge0: ASIC BCM5701 B5 (0x0105), Ethernet address 00:06:5b:ed:e2:d1
brgphy0 at bge0 phy 1: BCM5701 1000BASE-T media interface, rev. 0
brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
bge1 at pci1 dev 8 function 0: Broadcom BCM5701 Gigabit Ethernet
bge1: interrupting at ioapic1 pin 13 (irq 7)
bge1: ASIC BCM5701 B5 (0x0105), Ethernet address 00:06:5b:ed:e2:d2
brgphy1 at bge1 phy 1: BCM5701 1000BASE-T media interface, rev. 0
brgphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
pchb5 at pci0 dev 16 function 2
pchb5: ServerWorks CIOB-X2 PCI-X bridge (rev. 0x03)
pci2 at pchb5 bus 4
pci2: i/o space, memory space enabled
ppb0 at pci2 dev 8 function 0: Intel product 0x0309 (rev. 0x01)
pci3 at ppb0 bus 5
pci3: i/o space, memory space enabled
Adaptec (2nd PCI Vendor ID) AIC-7899F RAID (SCSI mass storage, revision 0x01) at pci3 dev 6 function 0 not configured
Adaptec (2nd PCI Vendor ID) AIC-7899F RAID (SCSI mass storage, revision 0x01) at pci3 dev 6 function 1 not configured
aac0 at pci2 dev 8 function 1: Dell PERC 3/Di
aac0: interrupting at ioapic1 pin 14 (irq 11)
aac0: i960RX at 100MHz, 128MB mem (118MB cache), optional battery present
aac0: Kernel 2.7-1 [Build 3170], Monitor 2.7-1 [Build 3170], S/N A441D3
aac0: Controller supports: 75c<WCACHE,DATA64,HOSTTIME,WINDOW4GB,SOFTERR,NORECOND,SGMAP64>
ld0 at aac0 unit 0: RAID 5
ld0: 135 GB, 17700 cyl, 255 head, 63 sec, 512 bytes/sect x 284365824 sectors
pchb6 at pci0 dev 17 function 0
pchb6: ServerWorks CIOB-X2 PCI-X bridge (rev. 0x03)
pci4 at pchb6 bus 1
pci4: i/o space, memory space enabled
aac1 at pci4 dev 6 function 0: HP NetRAID-4M
aac1: interrupting at ioapic1 pin 0 (irq 7)
aac1: StrongARM SA110 at 233MHz, 144MB mem (128MB cache), required battery present
aac1: Kernel 2.4-1 [Build 4607], Monitor 2.4-1 [Build 4607], S/N 8A1A4F
aac1: Controller supports: 17f<SNAPSHOT,CLUSTERS,WCACHE,DATA64,HOSTTIME,RAID50,WINDOW4GB,SOFTERR>
ld1 at aac1 unit 0: RAID 5
ld1: 95450 MB, 12168 cyl, 255 head, 63 sec, 512 bytes/sect x 195482496 sectors
pchb7 at pci0 dev 17 function 2
pchb7: ServerWorks CIOB-X2 PCI-X bridge (rev. 0x03)
pci5 at pchb7 bus 2
pci5: i/o space, memory space enabled
isa0 at pcib0
isapnp0 at isa0 port 0x279: ISA Plug 'n Play device support
isapnp0: no ISA Plug 'n Play devices found
ioapic0: enabling
ioapic1: enabling
ioapic2: enabling
aac1: WARNING: adapter logged message:
aac1:     ERROR - Low Battery
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
fd0 at fdc0 drive 0: 1.44MB, 80 cyl, 2 head, 18 sec
Kernelized RAIDframe activated
atapibus0 at atabus0: 2 targets
cd0 at atapibus0 drive 0: <SAMSUNG CD-ROM SN-124, , N102> cdrom removable
cd0: 32-bit data port
cd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 2 (Ultra/33)
cd0(rccide0:0:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 2 (Ultra/33) (using DMA)
boot device: ld0
root on ld0a dumps on ld0b
root file system type: ffs
cpu2: CPU 1 running
cpu1: CPU 2 running
cpu3: CPU 3 running
wsdisplay0: screen 0 added (80x50, vt100 emulation)
wsdisplay0: screen 1 added (80x50, vt100 emulation)
wsdisplay0: screen 2 added (80x50, vt100 emulation)
wsdisplay0: screen 3 added (80x50, vt100 emulation)
wsdisplay0: screen 4 added (80x50, vt100 emulation)
wsdisplay0: screen 5 added (80x50, vt100 emulation)
wsdisplay0: screen 6 added (80x25, vt100 emulation)
wsdisplay0: screen 7 added (80x25, vt100 emulation)


$ df
Filesystem    512-blocks       Used      Avail %Cap Mounted on
/dev/ld0a        4032824    1910140    1921044  49% /
/dev/ld0e       10089944      19016    9566432   0% /var
/dev/ld0f       16130008     206268   15117240   1% /usr/pkg
/dev/ld0g      231522520   15928820  204017576   7% /build
mfs:337          2024220         12    1923000   0% /tmp
kernfs                 2          2          0 100% /kern
building:/home  66058424   41870044   20885456  66% /building/home
building:/work  56408152   34057948   19529796  63% /building/work
most:/var       24765660   14923184    8604192  63% /most/var
$ /sbin/mount
/dev/ld0a on / type ffs (local)
/dev/ld0e on /var type ffs (nosuid, nodev, local)
/dev/ld0f on /usr/pkg type ffs (nosuid, nodev, soft dependencies, local)
/dev/ld0g on /build type ffs (nosuid, nodev, soft dependencies, local)
mfs:337 on /tmp type mfs (synchronous, nosuid, nodev, local)
kernfs on /kern type kernfs (local)
building:/home on /building/home type nfs (nosuid, nodev)
building:/work on /building/work type nfs (nosuid, nodev)
most:/var on /most/var type nfs (nosuid, nodev)


BTW, envstat doesn't see any sensors even though this machine is wired
to the hilt with them and I thought I'd finally see them with netbsd-4)


-- 
						Greg A. Woods

H:+1 416 218-0098 W:+1 416 489-5852 x122 VE3TCP RoboHack <woods@robohack.ca>
Planix, Inc. <woods@planix.com>       Secrets of the Weird <woods@weird.com>