wierd debug messages on startup and during port installation

[John Scroggins]

I have a test system running 7.0 with all the latest sources. When the
laptop is booted up and started I get some output from the kernel
debugger. Since I am not familiar with troubleshooting kernel level
components, I am forwarding this for review by the devs... As a note ..
it does not hinder the system in any way, it continues to boot and
function without additional problems, except occasionally when I call
portupgrade to update my sources.. 

I have attached my current dmesg log with the debug output for boot
up .. seems to be related to acpi drivers -- but again I'm not sure..

I have also included the portion of the debug output which occurs when
portupgrade -a is called ... 

if there is any other information that would be helpful in chasing this
problem down .. please let me know how I can help ...

_ John Scroggins 

dataefx at charter.net

btw: as another note .. the battery monitoring function in the Gnome
interface is sketchy to say the least .. but this is on the application
level so I do know what relevance this has to the previously stated
problem ... if any ;)
-------------- next part --------------
dataefx at depthcharge$ dmesg |less

Copyright (c) 1992-2005 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 7.0-CURRENT #0: Sat Jul 30 00:30:10 PDT 2005
    root at depthcharge:/usr/obj/usr/src/sys/GENERIC
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) III Mobile CPU      1000MHz (730.90-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x6b1  Stepping = 1
  Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
real memory  = 536215552 (511 MB)
avail memory = 515190784 (491 MB)
ath_hal: 0.9.14.9 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413)
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <PTLTD    RSDT> on motherboard
acpi0: Power Button (fixed)
unknown: memory range not supported
acpi0: <PTLTD    RSDT> on motherboard
acpi0: Power Button (fixed)
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
unknown: memory range not supported
pci_link0: <ACPI PCI Link LNKA> irq 9 on acpi0
pci_link1: <ACPI PCI Link LNKB> irq 5 on acpi0
pci_link2: <ACPI PCI Link LNKC> irq 9 on acpi0
pci_link3: <ACPI PCI Link LNKD> irq 11 on acpi0
pci_link4: <ACPI PCI Link LNKE> irq 10 on acpi0
pci_link5: <ACPI PCI Link LNKF> irq 0 on acpi0
pci_link6: <ACPI PCI Link LNKG> irq 0 on acpi0
pci_link7: <ACPI PCI Link LNKH> irq 0 on acpi0
acpi_ec0: <Embedded Controller: GPE 0x1d> port 0x62,0x66 on acpi0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
cpu0: <ACPI CPU> on acpi0
acpi_perf0: <ACPI CPU Frequency Control> on cpu0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <Intel 82830 host to AGP bridge> mem 0xe0000000-0xefffffff at device 0.0 on pci0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
uhci0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> port 0x1860-0x187f irq 9
at device 29.0 on pci0
uhci0: [GIANT-LOCKED]
usb0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> on uhci0
usb0: USB revision 1.0
uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> port 0x1880-0x189f irq 11 at device 29.1 on pci0
uhci1: [GIANT-LOCKED]
usb1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> on uhci1
usb1: USB revision 1.0
uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> port 0x1800-0x181f irq 9
at device 29.2 on pci0
uhci2: [GIANT-LOCKED]
usb2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> on uhci2
usb2: USB revision 1.0
uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
pcib2: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci2: <ACPI PCI bus> on pcib2
pci2: <simple comms> at device 4.0 (no driver attached)
fwohci0: <Texas Instruments TSB43AB22/A> mem 0xd0214000-0xd02147ff,0xd0210000-0xd0213fff irq 10 at device 5.0 on pci2
fwohci0: OHCI version 1.10 (ROM=1)
fwohci0: No. of Isochronous channels is 4.
fwohci0: EUI64 00:50:8b:70:31:ad:0d:15
fwohci0: Phy 1394a available S400, 2 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
fwe0: <Ethernet over FireWire> on firewire0
if_fwe0: Fake Ethernet address: 02:50:8b:ad:0d:15
fwe0: Ethernet address: 02:50:8b:ad:0d:15
fwe0: if_start running deferred for Giant
sbp0: <SBP-2/SCSI over FireWire> on firewire0
fwohci0: Initiate bus reset
fwohci0: node_id=0xc000ffc0, gen=1, CYCLEMASTER mode
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)
cbb0: <TI1410 PCI-CardBus Bridge> at device 6.0 on pci2
cardbus0: <CardBus bus> on cbb0
pccard0: <16-bit PCCard bus> on cbb0
fxp0: <Intel 82801CAM (ICH3) Pro/100 VE Ethernet> port 0x3040-0x307f mem 0xd0215000-0xd0215fff irq 10 at device 8.0 on pci2
miibus0: <MII bus> on fxp0
inphy0: <i82562ET 10/100 media interface> on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: Ethernet address: 00:02:a5:6c:4a:50
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel ICH3 UDMA100 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x1820-0x182f mem 0xd0000000-0xd00003ff at device 31.1 on pci0
ata0: <ATA channel 0> on atapci0
ata1: <ATA channel 1> on atapci0
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
pcm0: <Intel ICH3 (82801CA)> port 0x1c00-0x1cff,0x18c0-0x18ff irq 5 at device 31.5 on pci0
pcm0: [GIANT-LOCKED]
pcm0: <Analog Devices AD1886 AC97 Codec>
acpi_button0: <Power Button> on acpi0
acpi_button1: <Sleep Button> on acpi0
acpi_lid0: <Control Method Lid Switch> on acpi0
acpi_acad0: <AC Adapter> on acpi0
battery0: <ACPI Control Method Battery> on acpi0
battery1: <ACPI Control Method Battery> on acpi0
acpi_tz0: <Thermal Zone> on acpi0
 --------------------------------------- beginning of debug output during system startup -----------------------------------
   
malloc(M_WAITOK) of "PROC", forcing M_NOWAIT with the following non-sleepable locks held:
exclusive sleep mutex ACPI thermal zone r = 0 (0xc0b29120) locked @ /usr/src/sys/modules/acpi/acpi/../../../dev/acpica/acpi_thermal.c:1023
KDB: stack backtrace:
kdb_backtrace(1,c1c89cd4,c1041000,0,c0c20ba0) at kdb_backtrace+0x29
witness_warn(5,0,c0872679,c0857611,c1c89cd4) at witness_warn+0x18e
uma_zalloc_arg(c1041000,0,2) at uma_zalloc_arg+0x41
fork1(c091f720,60034,0,c0c20bf4) at fork1+0x106
kthread_create(c0b14130,c1c89c00,c1c89cd4,40000,0) at kthread_create+0x3d
acpi_tz_cooling_thread_start(c1c89c00,307a74,c0b27958,c1ae9940,c1ad3980) at acpi_tz_cooling_thread_start+0x66
acpi_tz_attach(c1ad3980) at acpi_tz_attach+0x408
device_attach(c1ad3980,0,c1ad3980,c1ad3180,0) at device_attach+0x58
device_probe_and_attach(c1ad3980) at device_probe_and_attach+0xe0
bus_generic_attach(c1ad3200,3,c0c20cd8,c0b0aa6c,c1ad3200) at bus_generic_attach+0x16
acpi_probe_children(c1ad3200,5057b58,c1ad3200,c1ad3200,0) at acpi_probe_children+0x2f
acpi_attach(c1ad3200) at acpi_attach+0x514
device_attach(c1ad3200,c0b26d60,c1ad3200,c1a14080,0) at device_attach+0x58
device_probe_and_attach(c1ad3200) at device_probe_and_attach+0xe0
bus_generic_attach(c1a14080,c1a14080,c1a14080,c0c20d40,c0646e64) at bus_generic_attach+0x16
nexus_attach(c1a14080) at nexus_attach+0x13
device_attach(c1a14080,c08f7730,c1a14080,c08f7730,c28000) at device_attach+0x58
device_probe_and_attach(c1a14080) at device_probe_and_attach+0xe0
root_bus_configure(c0c20d88,c060b73e,0,c1ec00,c1e000) at root_bus_configure+0x16configure(0,c1ec00,c1e000,0,c0445685) at configure+0x9
mi_startup() at mi_startup+0x96
begin() at begin+0x2c
lock order reversal
 1st 0xc0b29120 ACPI thermal zone (ACPI thermal zone) @ /usr/src/sys/modules/acpi/acpi/../../../dev/acpica/acpi_thermal.c:1023
 2nd 0xc0921760 proctree (proctree) @ /usr/src/sys/kern/kern_fork.c:277
KDB: stack backtrace:
kdb_backtrace(0,ffffffff,c0931c10,c0932a98,c08be16c) at kdb_backtrace+0x29
witness_checkorder(c0921760,1,c0855597,115) at witness_checkorder+0x564
_sx_slock(c0921760,c0855597,115,c1c06bf0,c1c06aa4,0,0,0) at _sx_slock+0x50
fork1(c091f720,60034,0,c0c20bf4) at fork1+0x135
kthread_create(c0b14130,c1c89c00,c1c89cd4,40000,0) at kthread_create+0x3d
acpi_tz_cooling_thread_start(c1c89c00,307a74,c0b27958,c1ae9940,c1ad3980) at acpi_tz_cooling_thread_start+0x66
acpi_tz_attach(c1ad3980) at acpi_tz_attach+0x408
device_attach(c1ad3980,0,c1ad3980,c1ad3180,0) at device_attach+0x58
device_probe_and_attach(c1ad3980) at device_probe_and_attach+0xe0
bus_generic_attach(c1ad3200,3,c0c20cd8,c0b0aa6c,c1ad3200) at bus_generic_attach+0x16
acpi_probe_children(c1ad3200,5057b58,c1ad3200,c1ad3200,0) at acpi_probe_children+0x2f
acpi_attach(c1ad3200) at acpi_attach+0x514
device_attach(c1ad3200,c0b26d60,c1ad3200,c1a14080,0) at device_attach+0x58
device_probe_and_attach(c1ad3200) at device_probe_and_attach+0xe0
bus_generic_attach(c1a14080,c1a14080,c1a14080,c0c20d40,c0646e64) at bus_generic_attach+0x16
nexus_attach(c1a14080) at nexus_attach+0x13
device_attach(c1a14080,c08f7730,c1a14080,c08f7730,c28000) at device_attach+0x58
device_probe_and_attach(c1a14080) at device_probe_and_attach+0xe0
root_bus_configure(c0c20d88,c060b73e,0,c1ec00,c1e000) at root_bus_configure+0x16configure(0,c1ec00,c1e000,0,c0445685) at configure+0x9
mi_startup() at mi_startup+0x96
begin() at begin+0x2c
malloc(M_WAITOK) of "4096", forcing M_NOWAIT with the following non-sleepable locks held:
exclusive sleep mutex ACPI thermal zone r = 0 (0xc0b29120) locked @ /usr/src/sys/modules/acpi/acpi/../../../dev/acpica/acpi_thermal.c:1023
KDB: stack backtrace:
kdb_backtrace(1,ad0,c104ab40,8,c0c20b70) at kdb_backtrace+0x29
witness_warn(5,0,c0872679,c081a4e9,ad0) at witness_warn+0x18e
uma_zalloc_arg(c104ab40,0,102) at uma_zalloc_arg+0x41
malloc(acc,c08bcf80,102,29,c0c20bdc) at malloc+0xae
sigacts_alloc(c0c20bf4,c065420b,1,0,c0653be0) at sigacts_alloc+0x18
fork1(c091f720,60034,0,c0c20bf4) at fork1+0x48d
kthread_create(c0b14130,c1c89c00,c1c89cd4,40000,0) at kthread_create+0x3d
acpi_tz_cooling_thread_start(c1c89c00,307a74,c0b27958,c1ae9940,c1ad3980) at acpi_tz_cooling_thread_start+0x66
acpi_tz_attach(c1ad3980) at acpi_tz_attach+0x408
device_attach(c1ad3980,0,c1ad3980,c1ad3180,0) at device_attach+0x58
device_probe_and_attach(c1ad3980) at device_probe_and_attach+0xe0
bus_generic_attach(c1ad3200,3,c0c20cd8,c0b0aa6c,c1ad3200) at bus_generic_attach+0x16
acpi_probe_children(c1ad3200,5057b58,c1ad3200,c1ad3200,0) at acpi_probe_children+0x2f
acpi_attach(c1ad3200) at acpi_attach+0x514
device_attach(c1ad3200,c0b26d60,c1ad3200,c1a14080,0) at device_attach+0x58
device_probe_and_attach(c1ad3200) at device_probe_and_attach+0xe0
bus_generic_attach(c1a14080,c1a14080,c1a14080,c0c20d40,c0646e64) at bus_generic_attach+0x16
nexus_attach(c1a14080) at nexus_attach+0x13
device_attach(c1a14080,c08f7730,c1a14080,c08f7730,c28000) at device_attach+0x58
device_probe_and_attach(c1a14080) at device_probe_and_attach+0xe0
root_bus_configure(c0c20d88,c060b73e,0,c1ec00,c1e000) at root_bus_configure+0x16configure(0,c1ec00,c1e000,0,c0445685) at configure+0x9
mi_startup() at mi_startup+0x96
begin() at begin+0x2c
malloc(M_WAITOK) of "256", forcing M_NOWAIT with the following non-sleepable locks held:
exclusive sleep mutex ACPI thermal zone r = 0 (0xc0b29120) locked @ /usr/src/sys/modules/acpi/acpi/../../../dev/acpica/acpi_thermal.c:1023
KDB: stack backtrace:
kdb_backtrace(1,d0,c104a3c0,4,c0c20b38) at kdb_backtrace+0x29
witness_warn(5,0,c0872679,c085cbc4,d0) at witness_warn+0x18e
uma_zalloc_arg(c104a3c0,0,102) at uma_zalloc_arg+0x41
malloc(cc,c08b9dc0,102,c062b08c,29) at malloc+0xae
fdinit(c19dee00,c1c7aaa8,c08583b1,0,0) at fdinit+0x20
fdcopy(c19dee00,c0c20bf4,c065420b,1,c1c7a000) at fdcopy+0x20
fork1(c091f720,60034,0,c0c20bf4) at fork1+0x4c6
kthread_create(c0b14130,c1c89c00,c1c89cd4,40000,0) at kthread_create+0x3d
acpi_tz_cooling_thread_start(c1c89c00,307a74,c0b27958,c1ae9940,c1ad3980) at acpi_tz_cooling_thread_start+0x66
acpi_tz_attach(c1ad3980) at acpi_tz_attach+0x408
device_attach(c1ad3980,0,c1ad3980,c1ad3180,0) at device_attach+0x58
device_probe_and_attach(c1ad3980) at device_probe_and_attach+0xe0
bus_generic_attach(c1ad3200,3,c0c20cd8,c0b0aa6c,c1ad3200) at bus_generic_attach+0x16
acpi_probe_children(c1ad3200,5057b58,c1ad3200,c1ad3200,0) at acpi_probe_children+0x2f
acpi_attach(c1ad3200) at acpi_attach+0x514
device_attach(c1ad3200,c0b26d60,c1ad3200,c1a14080,0) at device_attach+0x58
device_probe_and_attach(c1ad3200) at device_probe_and_attach+0xe0
bus_generic_attach(c1a14080,c1a14080,c1a14080,c0c20d40,c0646e64) at bus_generic_attach+0x16
nexus_attach(c1a14080) at nexus_attach+0x13
device_attach(c1a14080,c08f7730,c1a14080,c08f7730,c28000) at device_attach+0x58
device_probe_and_attach(c1a14080) at device_probe_and_attach+0xe0
root_bus_configure(c0c20d88,c060b73e,0,c1ec00,c1e000) at root_bus_configure+0x16configure(0,c1ec00,c1e000,0,c0445685) at configure+0x9
mi_startup() at mi_startup+0x96
begin() at begin+0x2c
  ----------------------------------- end of debug output during system startup ---------------------------------------

atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model Generic PS/2 mouse, device ID 0
ppc0: <ECP parallel printer port> port 0x378-0x37f,0x778-0x77f irq 7 drq 1 on acpi0
ppc0: Generic chipset (ECP/PS2/NIBBLE) in COMPATIBLE mode
ppc0: FIFO with 16/16/8 bytes threshold
ppbus0: <Parallel port bus> on ppc0
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
fdc0: <floppy drive controller (FDE)> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fdc0: [FAST]
pmtimer0 on isa0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xcdfff,0xce000-0xcefff,0xe5000-0xe5fff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio1: configured irq 3 not in bitmap of probed irqs 0
sio1: port may not be enabled
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounter "TSC" frequency 730902978 Hz quality 800
Timecounters tick every 1.000 msec
unknown: timeout waiting for read DRQath0: <Atheros 5212> mem 0xd0220000-0xd022ffff irq 11 at device 0.0 on cardbus0
ath0: Ethernet address: 00:09:5b:xx:xx:xx
ath0: mac 5.9 phy 4.3 radio 4.6
ad0: 28667MB <SAMSUNG MP0302H UP100-11> at ata0-master UDMA100
ATA PseudoRAID loaded
Trying to mount root from ufs:/dev/ad0s1a
ath0: promiscuous mode enabled
drm0: <ATI Radeon LY RV100 Mobility M6> port 0x2000-0x20ff mem 0xd8000000-0xdfffffff,0xd0100000-0xd010ffff irq 9 at device 0.0 on pci1
info: [drm] AGP at 0xe0000000 256MB
info: [drm] Initialized radeon 1.16.0 20050311 on minor 0
ath0: link state changed to DOWN
ath0: link state changed to UP
ath0: link state changed to DOWN
ath0: link state changed to UP
ath0: link state changed to DOWN
ath0: link state changed to UP
 
          ------------------------------------- beginning of debug output during portupgrade -a   ---------------------------------

lock order reversal
 1st 0xc097d360 UMA lock (UMA lock) @ /usr/src/sys/vm/uma_core.c:1494
 2nd 0xc1060144 system map (system map) @ /usr/src/sys/vm/vm_map.c:2317
KDB: stack backtrace:
kdb_backtrace(0,ffffffff,c0932458,c0932598,c08bcd24) at kdb_backtrace+0x29
witness_checkorder(c1060144,9,c08732da,90d) at witness_checkorder+0x564
_mtx_lock_flags(c1060144,0,c08732da,90d) at _mtx_lock_flags+0x5b
_vm_map_lock(c10600c0,c08732da,90d) at _vm_map_lock+0x26
vm_map_remove(c10600c0,c36f9000,c36fa000,d5690c08,c0780475) at vm_map_remove+0x1f
kmem_free(c10600c0,c36f9000,1000,d5690c38,c077fe22) at kmem_free+0x25
page_free(c36f9000,1000,2) at page_free+0x29
zone_drain(c103fd20) at zone_drain+0x26a
zone_foreach(c077fbb8,d5690cec,c0791ca3,c1ace180,d5690c74) at zone_foreach+0x37
uma_reclaim(c1ace180,d5690c74,0,c0928a80,d5690c80) at uma_reclaim+0x12
vm_pageout_scan(0,c097d7c0,0,c08747c7,5c3) at vm_pageout_scan+0x103
vm_pageout(0,d5690d38,0,c0792a5c,0) at vm_pageout+0x2c3
fork_exit(c0792a5c,0,d5690d38) at fork_exit+0xa0
fork_trampoline() at fork_trampoline+0x8
--- trap 0x1, eip = 0, esp = 0xd5690d6c, ebp = 0 ---
 
          ------------------------------------- end of debug output during portupgrade -a    ----------------------------------------