Re: 2.6.16-rc6-rt3

["K.R. Foley" <kr@cybsft.com>]

Ingo Molnar wrote:
> i have released the 2.6.16-rc6-rt3 tree, which can be downloaded from 
> the usual place:
> 

This one doesn't want to boot on the old SMP box. Log and config attached.

-- 
   kr

Linux version 2.6.16-rc6-rt3 (kr@porky.cybersoft.int) (gcc version 3.4.4 20050721 (Red Hat 3.4.4-2)) #19 SMP PREEMPT Tue Mar 14 07:12:19 CST 2006
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 00000000000a0000 (usable)
 BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000001ff9e000 (usable)
 BIOS-e820: 000000001ff9e000 - 0000000020000000 (reserved)
 BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
 BIOS-e820: 00000000fee00000 - 00000000fee10000 (reserved)
 BIOS-e820: 00000000ffb00000 - 0000000100000000 (reserved)
511MB LOWMEM available.
found SMP MP-table at 000fe710
DMI 2.3 present.
ACPI: PM-Timer IO Port: 0x808
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Processor #0 6:8 APIC version 17
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
Processor #1 6:8 APIC version 17
ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
ACPI: LAPIC_NMI (acpi_id[0x02] high edge lint[0x1])
ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 2, version 32, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Enabling APIC mode:  Flat.  Using 1 I/O APICs
Using ACPI (MADT) for SMP configuration information
Allocating PCI resources starting at 30000000 (gap: 20000000:dec00000)
Detected 931.007 MHz processor.
Real-Time Preemption Support (C) 2004-2006 Ingo Molnar
Built 1 zonelists
Kernel command line: ro root=LABEL=/ console=ttyS0,38400 console=tty0 nmi_watchdog=1 
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
WARNING: experimental RCU implementation.
PID hash table entries: 2048 (order: 11, 32768 bytes)
requested: 50000000  calculated 49992350 ns 50 cyc error: 7650
Event source pit installed with caps set: 01
Console: colour VGA+ 80x25
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 506304k/523896k available (1785k kernel code, 17208k reserved, 921k data, 280k init, 0k highmem)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 1862.56 BogoMIPS (lpj=931284)
Security Framework v1.0.0 initialized
Capability LSM initialized
Mount-cache hash table entries: 512
CPU: L1 I cache: 16K, L1 D cache: 16K
CPU: L2 cache: 256K
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
Checking 'hlt' instruction... OK.
CPU0: Intel Pentium III (Coppermine) stepping 06
Booting processor 1/1 eip 2000
Initializing CPU#1
Calibrating delay using timer specific routine.. 1861.67 BogoMIPS (lpj=930838)
CPU: L1 I cache: 16K, L1 D cache: 16K
CPU: L2 cache: 256K
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#1.
CPU1: Intel Pentium III (Coppermine) stepping 06
Total of 2 processors activated (3724.24 BogoMIPS).
ENABLING IO-APIC IRQs
..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
Event source lapic installed with caps set: 04
checking TSC synchronization across 2 CPUs: passed.
Event source lapic installed with caps set: 04
Brought up 2 CPUs
checking if image is initramfs... it is
Freeing initrd memory: 433k freed
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xfc03e, last bus=4
PCI: Using configuration type 1
ACPI: Subsystem revision 20060127
ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
ACPI: Assume root bridge [\_SB_.PCI0] bus is 0
PCI quirk: region 0800-087f claimed by ICH4 ACPI/GPIO/TCO
PCI quirk: region 0880-08bf claimed by ICH4 GPIO
PCI: Transparent bridge - 0000:00:1e.0
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 *9 10 11 12 15)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 *10 11 12 15)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 *5 6 7 9 10 11 12 15)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11 12 15)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
pnp: PnP ACPI: found 14 devices
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq".  If it helps, post a report
pnp: 00:0d: ioport range 0x800-0x85f could not be reserved
pnp: 00:0d: ioport range 0xc00-0xc7f has been reserved
pnp: 00:0d: ioport range 0x860-0x8ff could not be reserved
PCI: Bridge: 0000:00:01.0
  IO window: disabled.
  MEM window: fc000000-fdffffff
  PREFETCH window: f4000000-f5ffffff
PCI: Bridge: 0000:02:1f.0
  IO window: disabled.
  MEM window: fb000000-fb0fffff
  PREFETCH window: disabled.
PCI: Bridge: 0000:00:02.0
  IO window: disabled.
  MEM window: fb000000-fbffffff
  PREFETCH window: disabled.
PCI: Bridge: 0000:00:1e.0
  IO window: e000-efff
  MEM window: f9000000-faffffff
  PREFETCH window: 30000000-300fffff
No per-cpu room for modules.
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Initializing Cryptographic API
io scheduler noop registered
io scheduler anticipatory registered (default)
io scheduler deadline registered
io scheduler cfq registered
ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
nvidiafb: PCI id - 10de002d
nvidiafb: Actual id - 10de002d
nvidiafb: nVidia device/chipset 10DE002D
nvidiafb: HW is currently programmed for CRT
nvidiafb: Using CRT on CRTC 0
nvidiafb: MTRR set to ON
nvidiafb: PCI nVidia NV2 framebuffer (32MB @ 0xF4000000)
ACPI: Power Button (FF) [PWRF]
ibm_acpi: ec object not found
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found
Real Time Clock Driver v1.12ac
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:0b: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
RAMDISK driver initialized: 16 RAM disks of 8192K size 1024 blocksize
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
ICH: IDE controller at PCI slot 0000:00:1f.1
ICH: chipset revision 2
ICH: not 100% native mode: will probe irqs later
    ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:pio
    ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio
hda: SAMSUNG CD-R/RW SW-248F, ATAPI CD/DVD-ROM drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
hdc: Lite-On LTN483S 48x Max, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
mice: PS/2 mouse device common for all mice
md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: bitmap version 4.39
NET: Registered protocol family 2
input: AT Translated Set 2 keyboard as /class/input/input0
IP route cache hash table entries: 8192 (order: 3, 32768 bytes)
TCP established hash table entries: 32768 (order: 9, 2490368 bytes)
TCP bind hash table entries: 32768 (order: 9, 2359296 bytes)
TCP: Hash tables configured (established 32768 bind 32768)
TCP reno registered
TCP bic registered
NET: Registered protocol family 1
NET: Registered protocol family 17
input: ImPS/2 Generic Wheel Mouse as /class/input/input1
NET: Registered protocol family 8
NET: Registered protocol family 20
Testing NMI watchdog ... OK.
Starting balanced_irq
Using IPI Shortcut mode
*****************************************************************************
*                                                                           *
requested: 50000000  calculated 50000000 ns 46550352 cyc error: 0
Time: tsc clocksource has been installed.
*  REMINDER, the following debugging options are turned on in your .config: *
*                                                                           *
*        CONFIG_DEBUG_RT_MUTEXES                                             *
*        CONFIG_DEBUG_PREEMPT                                               *
*                                                                           *
*  they may increase runtime overhead and latencies.                        *
*                                                                           *
*****************************************************************************
*****************************************************************************
*                                                                           *
*  REMINDER, the following debugging options are turned on in your .config: *
*                                                                           *
*        CONFIG_DEBUG_RT_MUTEXES                                             *
*        CONFIG_DEBUG_PREEMPT                                               *
*                                                                           *
*  they may increase runtime overhead and latencies.                        *
*                                                                           *
*****************************************************************************
Freeing unused kernel memory: 280k freed
Could not allocate 8 bytes percpu data
BUG: Unable to handle kernel paging request at virtual address f3010000
 printing eip:
c0131c79
*pde = 00000000
Oops: 0000 [#1]
PREEMPT SMP 
Modules linked in:
CPU:    0
EIP:    0060:[<c0131c79>]    Not tainted VLI
EFLAGS: 00010297   (2.6.16-rc6-rt3 #19) 
EIP is at __find_symbol+0x37/0x1da
eax: ffffffff   ebx: 000004b0   ecx: c02fe964   edx: c02fab00
esi: f3010000   edi: e08255d0   ebp: de78fe9c   esp: de78fe8c
ds: 007b   es: 007b   ss: 0068   preempt: 00000001
Process insmod (pid: 804, threadinfo=de78e000 task=de4f9840 stack_left=7768 worst_left=-1)
Stack: <0>000004b0 e082adc0 e082bc80 e08255d0 de78fec8 c0132cc6 e08255d0 de78feb4 
       de78feb8 00000001 00000000 e082adc0 e082adc0 00000370 00000032 de78fef0 
       c013321c e0824930 0000000b e08255d0 e082bc80 00000000 e0824930 e082bc8d 
Call Trace:
 [<c01038fb>] show_stack_log_lvl+0xa5/0xad (44)
 [<c0103a67>] show_registers+0x137/0x1a0 (44)
 [<c0103c3b>] die+0xf3/0x16f (56)
 [<c0111e19>] do_page_fault+0x36f/0x48a (88)
 [<c010357f>] error_code+0x4f/0x54 (76)
 [<c0132cc6>] resolve_symbol+0x22/0x5d (44)
 [<c013321c>] simplify_symbols+0x81/0xf4 (40)
 [<c0133e2d>] load_module+0x637/0x968 (168)
 [<c01341c1>] sys_init_module+0x3d/0x1d3 (28)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c02bd871>] .... _raw_spin_lock_irqsave+0x11/0x33
.....[<c0103b87>] ..   ( <= die+0x3f/0x16f)

------------------------------
| showing all locks held by: |  (insmod/804 [de4f9840, 120]):
------------------------------

#001:             [c0311f24] {module_mutex.lock}
... acquired at:               rt_down_interruptible+0x15/0x32

Code: 00 00 00 00 b8 80 85 2f c0 3d 04 cb 2f c0 c7 45 f0 00 00 00 00 73 4a 89 c2 b9 a4 d6 2f c0 8b 5d f0 8b 7d 08 8b 34 dd 84 85 2f c0 <ac> ae 75 08 84 c0 75 f8 31 c0 eb 04 19 c0 0c 01 85 c0 75 11 8b 
 BUG: nonzero lock count 1 at exit time?
          insmod:  804 [de4f9840, 120]
 [<c0103854>] show_trace+0x13/0x15 (20)
 [<c010392e>] dump_stack+0x16/0x18 (20)
 [<c013067f>] rt_mutex_debug_check_no_locks_held+0x60/0x227 (44)
 [<c011c837>] do_exit+0x3e3/0x45b (32)
 [<c0103cb7>] do_trap+0x0/0x97 (52)
 [<c0111e19>] do_page_fault+0x36f/0x48a (88)
 [<c010357f>] error_code+0x4f/0x54 (76)
 [<c0132cc6>] resolve_symbol+0x22/0x5d (44)
 [<c013321c>] simplify_symbols+0x81/0xf4 (40)
 [<c0133e2d>] load_module+0x637/0x968 (168)
 [<c01341c1>] sys_init_module+0x3d/0x1d3 (28)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

------------------------------
| showing all locks held by: |  (insmod/804 [de4f9840, 120]):
------------------------------

#001:             [c0311f24] {module_mutex.lock}
... acquired at:               rt_down_interruptible+0x15/0x32

BUG: insmod/804, lock held at task exit time!
 [c0311f24] {module_mutex.lock}
.. ->owner: de4f9840
.. held by:            insmod:  804 [de4f9840, 120]
... acquired at:               rt_down_interruptible+0x15/0x32
BUG at kernel/rtmutex.c:674!
------------[ cut here ]------------
kernel BUG at kernel/rtmutex.c:674!
invalid opcode: 0000 [#2]
PREEMPT SMP 
Modules linked in:
CPU:    0
EIP:    0060:[<c02bd019>]    Not tainted VLI
EFLAGS: 00010202   (2.6.16-rc6-rt3 #19) 
EIP is at rt_mutex_slowlock+0xaf/0x262
eax: 00000020   ebx: de78e000   ecx: de4f9840   edx: 00000002
esi: 00000000   edi: c0311f24   ebp: de78ff78   esp: de78fef0
ds: 007b   es: 007b   ss: 0068   preempt: 00000002
Process insmod (pid: 805, threadinfo=de78e000 task=de4f9840 stack_left=7868 worst_left=-1)
Stack: <0>c02cc5bf c02d2c3d 000002a2 ffffffff 00000000 00000000 00000002 c02bcf49 
       c1d307c8 c1d307a0 de78ff20 c02bd5a5 de78ff2c c0130fd3 00000000 0000008c 
       de78ff30 de78ff30 de78ff38 de78ff38 00000000 0000008c de78ff48 de78ff48 
Call Trace:
 [<c01038fb>] show_stack_log_lvl+0xa5/0xad (44)
 [<c0103a67>] show_registers+0x137/0x1a0 (44)
 [<c0103c3b>] die+0xf3/0x16f (56)
 [<c0103d32>] do_trap+0x7b/0x97 (32)
 [<c0103f89>] do_invalid_op+0x90/0x97 (204)
 [<c010357f>] error_code+0x4f/0x54 (196)
 [<c02bd285>] rt_mutex_lock_interruptible+0x2f/0x39 (28)
 [<c0131142>] rt_down_interruptible+0x15/0x32 (16)
 [<c01341a6>] sys_init_module+0x22/0x1d3 (16)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000002 ]
| 2-level deep critical section nesting:
----------------------------------------
.. [<c02bd8a1>] .... _raw_spin_lock_irq+0xe/0x22
.....[<c02bcfa0>] ..   ( <= rt_mutex_slowlock+0x36/0x262)
.. [<c02bd871>] .... _raw_spin_lock_irqsave+0x11/0x33
.....[<c0103b87>] ..   ( <= die+0x3f/0x16f)

------------------------------
| showing all locks held by: |  (insmod/805 [de4f9840, 119]):
------------------------------

Code: c0 e9 d0 01 00 00 8b 47 1c bb 00 e0 ff ff 21 e3 83 e0 fc 3b 03 75 1f 68 a2 02 00 00 68 3d 2c 2d c0 68 bf c5 2c c0 e8 87 d3 e5 ff <0f> 0b a2 02 3d 2c 2d c0 83 c4 0c 8b 03 8b 58 14 85 db 78 2e c7 
 <3>BUG: sleeping function called from invalid context insmod(805) at kernel/rtmutex.c:831
in_atomic():1 [00000001], irqs_disabled():0
 [<c0103854>] show_trace+0x13/0x15 (20)
 [<c010392e>] dump_stack+0x16/0x18 (20)
 [<c0117077>] __might_sleep+0xce/0xd8 (36)
 [<c02bd23a>] rt_mutex_lock+0x15/0x31 (20)
 [<c01310ed>] rt_down_read+0x3c/0x3f (12)
 [<c011abb1>] profile_task_exit+0xd/0x2b (8)
 [<c011c46e>] do_exit+0x1a/0x45b (32)
 [<c0103cb7>] do_trap+0x0/0x97 (52)
 [<c0103d32>] do_trap+0x7b/0x97 (32)
 [<c0103f89>] do_invalid_op+0x90/0x97 (204)
 [<c010357f>] error_code+0x4f/0x54 (196)
 [<c02bd285>] rt_mutex_lock_interruptible+0x2f/0x39 (28)
 [<c0131142>] rt_down_interruptible+0x15/0x32 (16)
 [<c01341a6>] sys_init_module+0x22/0x1d3 (16)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c02bd8a1>] .... _raw_spin_lock_irq+0xe/0x22
.....[<c02bcfa0>] ..   ( <= rt_mutex_slowlock+0x36/0x262)

------------------------------
| showing all locks held by: |  (insmod/805 [de4f9840, 119]):
------------------------------

note: insmod[805] exited with preempt_count 1
BUG: scheduling while atomic: insmod/0x00000001/805
caller is do_exit+0x41a/0x45b
 [<c0103854>] show_trace+0x13/0x15 (20)
 [<c010392e>] dump_stack+0x16/0x18 (20)
 [<c02bbab6>] __schedule+0x6c/0x6e0 (76)
 [<c011c86e>] do_exit+0x41a/0x45b (28)
 [<c0103cb7>] do_trap+0x0/0x97 (52)
 [<c0103d32>] do_trap+0x7b/0x97 (32)
 [<c0103f89>] do_invalid_op+0x90/0x97 (204)
 [<c010357f>] error_code+0x4f/0x54 (196)
 [<c02bd285>] rt_mutex_lock_interruptible+0x2f/0x39 (28)
 [<c0131142>] rt_down_interruptible+0x15/0x32 (16)
 [<c01341a6>] sys_init_module+0x22/0x1d3 (16)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c02bd8a1>] .... _raw_spin_lock_irq+0xe/0x22
.....[<c02bcfa0>] ..   ( <= rt_mutex_slowlock+0x36/0x262)

------------------------------
| showing all locks held by: |  (insmod/805 [de4f9840, 119]):
------------------------------

NMI watchdog detected lockup on CPU#0 (5000/5000)

Pid: 806, comm:               insmod
EIP: 0060:[<c02bd8ac>] CPU: 0
EIP is at _raw_spin_lock_irq+0x19/0x22
 EFLAGS: 00000086    Not tainted  (2.6.16-rc6-rt3 #19)
EAX: 00000001 EBX: c0311f24 ECX: c02bcfa0 EDX: 00000001
ESI: 00000000 EDI: c0311f24 EBP: de78fef0 DS: 007b ES: 007b
CR0: 8005003b CR2: b7f7b007 CR3: 1fb9b000 CR4: 000006d0
 [<c0103854>] show_trace+0x13/0x15 (20)
 [<c01010c5>] show_regs+0x111/0x118 (44)
 [<c010e415>] nmi_watchdog_tick+0x12c/0x23e (44)
 [<c01045b9>] default_do_nmi+0x6f/0x13d (88)
 [<c01046bc>] do_nmi+0x2e/0x34 (16)
 [<c0103626>] nmi_stack_correct+0x1d/0x22 (64)
 [<c02bcfa0>] rt_mutex_slowlock+0x36/0x262 (136)
 [<c02bd285>] rt_mutex_lock_interruptible+0x2f/0x39 (28)
 [<c0131142>] rt_down_interruptible+0x15/0x32 (16)
 [<c01341a6>] sys_init_module+0x22/0x1d3 (16)
 [<c0102a1b>] sysenter_past_esp+0x54/0x75 (-8116)
---------------------------
| preempt count: 00000002 ]
| 2-level deep critical section nesting:
----------------------------------------
.. [<c02bd8a1>] .... _raw_spin_lock_irq+0xe/0x22
.....[<c02bcfa0>] ..   ( <= rt_mutex_slowlock+0x36/0x262)
.. [<c02bd9be>] .... _raw_spin_lock+0xd/0x21
.....[<c010e3f1>] ..   ( <= nmi_watchdog_tick+0x108/0x23e)

------------------------------
| showing all locks held by: |  (insmod/806 [de4f9840, 119]):
------------------------------

NMI show regs on CPU#1:

Attachment: config.porky.2.6.16-rc6-rt3.gz
Description: GNU Zip compressed data