Re: More ULE bugs fixed.

On Fri, 31 Oct 2003, Sam Leffler wrote:

> On Friday 31 October 2003 09:04 am, Bruce Evans wrote:
>
> > My simple make benchmark now takes infinitely longer with ULE under SMP,
> > since make -j 16 with ULE under SMP now hangs nfs after about a minute.
> > 4BSD works better.  However, some networking bugs have developed in the
> > last few days.  One of their manifestations is that SMP kernels always
> > panic in sbdrop() on shutdown.
>
> I'm looking at something similar now.  If you have a stack trace please send
> it to me (along with any other info).  You might also try booting
> debug.mpsafenet=0.

Turning off mpsafenet fixed all these problems.

These console messages are with it not turned off.  fxp is the only
physical network device.

%%%
WARNING: loader(8) metadata is missing!
[ preserving 869208 bytes of kernel symbol table ]
Copyright (c) 1992-2003 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD 5.1-CURRENT #1005: Sun Nov  2 20:38:42 EST 2003
    bde_at_besplex.bde.org:/c/sysc/i386/compile/smp
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Pentium II/Pentium II Xeon/Celeron (400.91-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x665  Stepping = 5
  Features=0x183fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
real memory  = 268435456 (256 MB)
avail memory = 255369216 (243 MB)
Programming 24 pins in IOAPIC #0
IOAPIC #0 intpin 2 -> irq 0
IOAPIC #0 intpin 17 -> irq 9
IOAPIC #0 intpin 18 -> irq 11
IOAPIC #0 intpin 19 -> irq 5
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 cpu0 (BSP): apic id:  0, version: 0x00040011, at 0xfee00000
 cpu1 (AP):  apic id:  1, version: 0x00040011, at 0xfee00000
 io0 (APIC): apic id:  2, version: 0x00170011, at 0xfec00000
Pentium Pro MTRR support enabled
npx0: <math processor> on motherboard
npx0: flags 0x80 npx0: INT 16 interface
pcibios: BIOS version 2.10
Using $PIR table, 8 entries at 0xc00fdef0
pcib0: <Intel 82443BX (440 BX) host to PCI bridge> at pcibus 0 on motherboard
pci0: <PCI bus> on pcib0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel PIIX4 UDMA33 controller> port 0xf000-0xf00f at device 7.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata0: [MPSAFE]
ata1: at 0x170 irq 15 on atapci0
ata1: [MPSAFE]
pci0: <serial bus, USB> at device 7.2 (no driver attached)
piix0: <PIIX Timecounter> port 0x5000-0x500f at device 7.3 on pci0
Timecounter "PIIX" frequency 3579545 Hz quality 0
pci0: <multimedia, video> at device 11.0 (no driver attached)
pci0: <multimedia> at device 11.1 (no driver attached)
fxp0: <Intel 82559 Pro/100 Ethernet> port 0xa400-0xa43f mem 0xea000000-0xea0fffff,0xea104000-0xea104fff irq 9 at device 13.0 on pci0
fxp0: Ethernet address 00:90:27:99:02:99
miibus0: <MII bus> on fxp0
inphy0: <i82555 10/100 media interface> on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: [MPSAFE]
puc0: <Titan VScom PCI-200HV2> port 0xb000-0xb01f,0xac00-0xac07,0xa800-0xa807 mem 0xea103000-0xea103fff,0xea102000-0xea102fff irq 5 at device 17.0 on pci0
sio4: <Titan VScom PCI-200HV2> on puc0
sio4: type 16550A
sio5: <Titan VScom PCI-200HV2> on puc0
sio5: type 16550A
atapci1: <HighPoint HPT366 UDMA66 controller> port 0xbc00-0xbcff,0xb800-0xb803,0xb400-0xb407 irq 11 at device 19.0 on pci0
atapci1: [MPSAFE]
ata2: at 0xb400 on atapci1
ata2: [MPSAFE]
atapci2: <HighPoint HPT366 UDMA66 controller> port 0xc800-0xc8ff,0xc400-0xc403,0xc000-0xc007 irq 11 at device 19.1 on pci0
atapci2: [MPSAFE]
ata3: at 0xc000 on atapci2
ata3: [MPSAFE]
orm0: <Option ROMs> at iomem 0xc8000-0xcbfff,0xc0000-0xc7fff on isa0
fdc0: <Enhanced floppy controller (i82077, NE72065 or clone)> at port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on isa0
fdc0: FIFO enabled, 8 bytes threshold
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
atkbdc0: <Keyboard controller (i8042)> at port 0x64,0x60 on isa0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
kbd0 at atkbd0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model Generic PS/2 mouse, device ID 0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x100>
sio0 at port 0x3f8-0x3ff irq 4 flags 0x90 on isa0
sio0: type 16550A, console
sio1 at port 0x2f8-0x2ff irq 3 on isa0
sio1: type 16550A
cy0 at iomem 0xd4000-0xd5fff irq 10 on isa0
cy0: driver is using old-style compatibility shims
ppc0: <Parallel port> at port 0x378-0x37f irq 7 on isa0
ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode
ppc0: FIFO with 16/16/16 bytes threshold
ppbus0: <Parallel port bus> on ppc0
ppbus0: IEEE1284 device found
Probing for PnP devices on ppbus0:
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
unknown: <PNP0303> can't assign resources (port)
speaker0: <PC speaker> at port 0x61 on isa0
unknown: <PNP0a03> can't assign resources (port)
unknown: <PNP0f13> can't assign resources (irq)
unknown: <PNP0501> can't assign resources (port)
unknown: <PNP0700> can't assign resources (port)
unknown: <PNP0401> can't assign resources (port)
unknown: <PNP0501> can't assign resources (port)
APIC_IO: Testing 8254 interrupt delivery
APIC_IO: routing 8254 via IOAPIC #0 intpin 2

Timecounters tick every 10.000 msec
ipfw2 initialized, divert enabled, rule-based forwarding enabled, default to accept, logging disabled
GEOM: create disk ad0 dp=0xc2999370
ad0: 6149MB <QUANTUM FIREBALL ST6.4A> [13328/15/63] at ata0-master UDMA33
GEOM: create disk afd0 dp=0xc2978e7c
afd0: REMOVABLE <IOMEGA ZIP 100 ATAPI> at ata0-slave PIO0
acd0: CDRW <RICOH CD-RW MP7320A> at ata1-slave UDMA33
acd1: CDROM <ATAPI 44X CDROM> at ata2-slave PIO4
(probe5:ata2:0:1:0): Recovered Sense
(probe5:ata2:0:1:0): INQUIRY. CDB: 12 1 80 0 ff 0
(probe5:ata2:0:1:0): CAM Status: SCSI Status Error
(probe5:ata2:0:1:0): SCSI Status: Check Condition
(probe5:ata2:0:1:0): ILLEGAL REQUEST asc:24,0
(probe5:ata2:0:1:0): Invalid field in CDB
(probe5:ata2:0:1:0): Recovered Sense
(probe5:ata2:0:1:0): INQUIRY. CDB: 12 1 80 0 ff 0
(probe5:ata2:0:1:0): CAM Status: SCSI Status Error
(probe5:ata2:0:1:0): SCSI Status: Check Condition
(probe5:ata2:0:1:0): ILLEGAL REQUEST asc:24,0
(probe5:ata2:0:1:0): Invalid field in CDB
(probe1:ata0:0:1:0): Recovered Sense
(probe1:ata0:0:1:0): INQUIRY. CDB: 12 1 80 0 ff 0
(probe1:ata0:0:1:0): CAM Status: SCSI Status Error
(probe1:ata0:0:1:0): SCSI Status: Check Condition
(probe1:ata0:0:1:0): ILLEGAL REQUEST asc:24,0
(probe1:ata0:0:1:0): Invalid field in CDB
(probe1:ata0:0:1:0): Recovered Sense
(probe1:ata0:0:1:0): INQUIRY. CDB: 12 1 80 0 ff 0
(probe1:ata0:0:1:0): CAM Status: SCSI Status Error
(probe1:ata0:0:1:0): SCSI Status: Check Condition
(probe1:ata0:0:1:0): ILLEGAL REQUEST asc:24,0
(probe1:ata0:0:1:0): Invalid field in CDB
GEOM: create disk cd0 dp=0xc294ae00
GEOM: create disk cd1 dp=0xc294b600
GEOM: create disk da0 dp=0xc2a2b450
(cd1:ata2:0:1:0): Recovered Sense
(cd1:ata2:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd1:ata2:0:1:0): CAM Status: SCSI Status Error
(cd1:ata2:0:1:0): SCSI Status: Check Condition
(cd1:ata2:0:1:0): NOT READY asc:3a,0
(cd1:ata2:0:1:0): Medium not present
cd1 at ata2 bus 0 target 1 lun 0
cd1: <ATAPI 44X CDROM 3.40> Removable CD-ROM SCSI-0 device
cd1: 16.000MB/s transfers
cd1: Attempt to query device size failed: NOT READY, Medium not present
(cd0:ata1:0:1:0): Recovered Sense
(cd0:ata1:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd0:ata1:0:1:0): CAM Status: SCSI Status Error
(cd0:ata1:0:1:0): SCSI Status: Check Condition
(cd0:ata1:0:1:0): NOT READY asc:3a,0
(cd0:ata1:0:1:0): Medium not present
cd0 at ata1 bus 0 target 1 lun 0
cd0: <RICOH CD-RW MP7320A bp13> Removable CD-ROM SCSI-0 device
cd0: 33.000MB/s transfers
cd0: Attempt to query device size failed: NOT READY, Medium not present
da0 at ata0 bus 0 target 1 lun 0
da0: <IOMEGA ZIP 100 14.A> Removable Direct Access SCSI-0 device
da0: 3.300MB/s transfers
da0: 96MB (196608 512 byte sectors: 64H 32S/T 96C)
SMP: AP CPU #1 Launched!
(cd0:ata1:0:1:0): Recovered Sense
(cd0:ata1:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd0:ata1:0:1:0): CAM Status: SCSI Status Error
(cd0:ata1:0:1:0): SCSI Status: Check Condition
(cd0:ata1:0:1:0): NOT READY asc:3a,0
(cd0:ata1:0:1:0): Medium not present
(cd0:ata1:0:1:0): Recovered Sense
(cd0:ata1:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd0:ata1:0:1:0): CAM Status: SCSI Status Error
(cd0:ata1:0:1:0): SCSI Status: Check Condition
(cd0:ata1:0:1:0): NOT READY asc:3a,0
(cd0:ata1:0:1:0): Medium not present
(cd1:ata2:0:1:0): Recovered Sense
(cd1:ata2:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd1:ata2:0:1:0): CAM Status: SCSI Status Error
(cd1:ata2:0:1:0): SCSI Status: Check Condition
(cd1:ata2:0:1:0): NOT READY asc:3a,0
(cd1:ata2:0:1:0): Medium not present
(cd1:ata2:0:1:0): Recovered Sense
(cd1:ata2:0:1:0): READ CD RECORDED CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
(cd1:ata2:0:1:0): CAM Status: SCSI Status Error
(cd1:ata2:0:1:0): SCSI Status: Check Condition
(cd1:ata2:0:1:0): NOT READY asc:3a,0
(cd1:ata2:0:1:0): Medium not present
Mounting root from ufs:/dev/ad0s2a
Loading configuration files.
Entropy harvesting: interrupts ethernet point_to_point.
swapon: adding /dev/ad0s4 as swap device
Starting file system checks:
/dev/ad0s2a: clean, 19780 free (964 frags, 2352 blocks, 1.5% fragmentation)
/dev/ad0s2f: clean, 486141 free (3029 frags, 60389 blocks, 0.3% fragmentation)
/dev/ad0s2g: clean, 949804 free (84 frags, 118715 blocks, 0.0% fragmentation)
/dev/ad0s2h: clean, 364942 free (23062 frags, 42735 blocks, 2.1% fragmentation)
Setting hostname: gamplex.bde.org.
fxp0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 1500
	inet 192.168.2.3 netmask 0xffffff00 broadcast 192.168.2.255
	ether 00:90:27:99:02:99
	media: Ethernet autoselect (100baseTX <full-duplex>)
	status: active
lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> mtu 16384
	inet 127.0.0.1 netmask 0xff000000
Additional routing options: IP gateway=YES.
hw.bus.devctl_disable: 0 -> 1
Mounting NFS file systems:.
Starting syslogd.
Nov  2 22:36:59 gamplex syslogd: kernel boot file is /kernel
Starting ntpdate.
Starting rpcbind.
Nov  2 22:37:00 gamplex rpcbind: cannot create socket for udp6
Nov  2 22:37:00 gamplex rpcbind: cannot create socket for tcp6
NFS access cache time=2
ELF ldconfig path: /lib /usr/lib /usr/lib/compat /usr/X11R6/lib /usr/local/lib
a.out ldconfig path: /usr/lib/aout /usr/lib/compat/aout /usr/X11R6/lib/aout
Starting local daemons:machdep.i8254_freq: 1193182 -> 1193211
machdep.tsc_freq: 400909276 -> 400918854
net.inet.icmp.icmplim: 200 -> 0
net.isr.enable: 0 -> 1
sysctl: unknown oid 'machdep.rtcpps'
.
Updating motd.
Starting ntpd.
Configuring syscons: keyrate keybell font8x16 blanktime.
Starting sendmail.
Initial i386 initialization:.
Additional ABI support:.
Starting cron.
Local package initialization: healthd.
Additional TCP options:.
Starting inetd.

Sun Nov  2 22:37:02 EST 2003
Nov  2 22:37:50 gamplex ntpd[477]: kernel time discipline status change 20c1
Stopping inetd.
Shutting down daemon processes: healthd.
Stopping cron.
Shutting down local daemons:.
.
Nov  2 22:39:31 gamplex syslogd: exiting on signal 15
boot() called on cpu#0
Waiting (max 60 seconds) for system process `vnlru' to stop...stopped
Waiting (max 60 seconds) for system process `bufdaemon' to stop...stopped
Waiting (max 60 seconds) for system process `syncer' to stop...stopped

syncing disks, buffers remaining...
done
panic: sbdrop
cpuid = 0; lapic.id = 00000000
Stack backtrace:
backtrace(100,c12ae720,6c4,cdb1cbd8,0) at backtrace+0x12
panic(c0643965,cdb1cbd8,c2ae97fc,cdb1cc18,cdb1cbb4) at panic+0x124
sbdrop(cdb1cbd8,6c4) at sbdrop+0x36
sbflush(cdb1cbd8,c2ae97bc,cdb1cc24,c0509280,cdb1cbd8) at sbflush+0x3e
sbrelease(cdb1cbd8,c2ae9770,c0673ab4,0,0) at sbrelease+0xd
sorflush(c2ae9770) at sorflush+0xac
soshutdown(c2ae9770,2,2,cdb1cc68,c056c28f) at soshutdown+0x24
nfs_disconnect(c2af3ee0,0,80000,c12ae720,cdb1cc90) at nfs_disconnect+0x1f
nfs_unmount(c2af2600,80000,c12ae720,0,c2af0124) at nfs_unmount+0x4b
dounmount(c2af2600,80000,c12ae720,c7b2ffe8,0) at dounmount+0x1d4
vfs_unmountall(0,0,0,cdb1ccd0,0) at vfs_unmountall+0x4a
boot(0,cdb1cd40,c0604a6f,c12ae720,cdb1cd14) at boot+0x4ec
reboot(c12ae720,cdb1cd14,1,6,282) at reboot+0x4d
syscall(2f,2f,2f,bfbffdf8,bfbffdf8) at syscall+0x27f
Xint0x80_syscall() at Xint0x80_syscall+0x1d
--- syscall (55), eip = 0x804f7eb, esp = 0xbfbffc4c, ebp = 0xbfbffd18 ---
Debugger("panic")
Stopped at      Debugger+0x46:  xchgl   %ebx,in_Debugger.2
db> c
boot() called on cpu#0
Uptime: 2m56s
pfs_vncache_unload(): 1 entries remaining
Automatic reboot in 15 seconds - press a key on the console to abort
Rebooting...
cpu_reset called on cpu#0
cpu_reset: Stopping other CPUs
%%%

Bruce