2006-11-02 10:44:20

by Rui Nuno Capela

[permalink] [raw]
Subject: realtime-preempt patch-2.6.18-rt7 oops

Ingo et al.

For quite some time I've been running the realtime-preempt kernels with
success on all of my (home) production machines. All of them under
openSUSE 10.1 i586 (all P4), two laptops UP and one desktop SMP/HT.

While on UP kernels everything works great and without major issues to
report, problem goes here on the SMP/HT one. Simple fact: it hangs,
freezes in some non-deterministic ways. However, sometimes, it is just a
matter of a couple of dozen clicks while browsing over those
funky-ajax-enabled-web2 sites :)

I've managed to grab some of those oopses via serial console, and a sample
is shown below. I have more of those, just let me know if you want them :)

One thing to notice notice is that all .config debug switches are off --
as said before, this was production line. If I turn the .config
preempt-debug
switches on, the experience gets a lot less painful, that is, the
hard-locks just don't seem to happen (but some traces are spitted out
(on dmesg), nevertheless.

I'll beg you to have a spare look and try to hint on me whether and how I
can gather some more debug information on this issue, which has gone quite
annoying by now -- for a so-called "production machine", I mean ;)

...
Oops: 0002 [#1]
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 snd_seq_dummy edd
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event snd_seq w83627hf
hwmon_vid hwmon i2c_isa button battery ac loop dm_mod intel_rng usbhid
wacom shpchp pci_hotplug snd_ice1712 snd_ice17xx_ak4xxx snd_ak4xxx_adda
snd_cs8427 snd_i2c snd_mpu401_uart snd_cs46xx gameport snd_rawmidi ide_cd
snd_seq_device cdrom snd_intel8x0 snd_ac97_codec snd_ac97_bus snd_pcm
intel_agp snd_timer snd_page_alloc i8xx_tco snd sk98lin agpgart ehci_hcd
soundcore uhci_hcd usbcore i2c_i801 i2c_core ohci1394 ieee1394 ext3 jbd
reiserfs fan thermal processor piix ide_disk ide_core
CPU: 0
EIP: 0060:[<c011e5ab>] Not tainted VLI
EFLAGS: 00010046 (2.6.18.1-rt7.0-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f708 ebx: c188f28c ecx: 00000000 edx: dfd010d8
esi: dfd010b0 edi: c188edc0 ebp: c03e3e8c esp: c03e3e84
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process swapper (pid: 0, ti=c03e2000 task=c0358840 task.ti=c03e2000)
Stack: c188edc0 dfd010b0 c03e3e9c c011e631 00000001 dfd010b0 c03e3f00
c01209b1
00000002 1865a2d4 00000001 00000000 0000001f c03e2000 00000001
00000000
00000004 a16a98d4 10219a55 006d16d6 c03e3ef0 00000115 00000115
c03d5280
Call Trace:
[<c011e631>] __activate_task+0x21/0x40
[<c01209b1>] try_to_wake_up+0x321/0x450
[<c0144822>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b59>] wake_up_process_mutex+0x19/0x20
[<c0300531>] rt_spin_lock_slowunlock+0x41/0x70
[<c02ff34c>] __schedule+0xc0c/0xee0
[<c014091a>] hrtimer_interrupt+0x18a/0x250
[<c015848e>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e7808>] start_kernel+0x368/0x440
[<c03e7220>] unknown_bootoption+0x0/0x280
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 80 c0 35 c0 85 c0 75
4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11 89 4a
04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011e5ab>] enqueue_task+0x2b/0x90 SS:ESP 0068:c03e3e84
<0>Kernel panic - not syncing: Attempted to kill the idle task!
[<c01271e1>] panic+0x51/0x120
[<c012ae90>] do_exit+0x6e0/0xa90
[<c0106462>] show_registers+0x172/0x240
[<c012784b>] printk+0x1b/0x20
[<c0110068>] positive_have_wrcomb+0x8/0x10
[<c0106831>] die+0x301/0x310
[<c0302995>] do_page_fault+0x205/0x610
[<c0302790>] do_page_fault+0x0/0x610
[<c0105e09>] error_code+0x39/0x40
[<c011007b>] generic_validate_add_page+0xb/0x100
[<c011e5ab>] enqueue_task+0x2b/0x90
[<c011e631>] __activate_task+0x21/0x40
[<c01209b1>] try_to_wake_up+0x321/0x450
[<c0144822>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b59>] wake_up_process_mutex+0x19/0x20
[<c0300531>] rt_spin_lock_slowunlock+0x41/0x70
[<c02ff34c>] __schedule+0xc0c/0xee0
[<c014091a>] hrtimer_interrupt+0x18a/0x250
[<c015848e>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e7808>] start_kernel+0x368/0x440
[<c03e7220>] unknown_bootoption+0x0/0x280
swapper/0[CPU#0]: BUG in smp_call_function at arch/i386/kernel/smp.c:557
[<c0128436>] __WARN_ON+0x66/0x90
[<c0115220>] stop_this_cpu+0x0/0x40
[<c011501a>] smp_call_function+0xda/0xe0
[<c012784b>] printk+0x1b/0x20
[<c011503b>] smp_send_stop+0x1b/0x30
[<c01271f4>] panic+0x64/0x120
[<c012ae90>] do_exit+0x6e0/0xa90
[<c0106462>] show_registers+0x172/0x240
[<c012784b>] printk+0x1b/0x20
[<c0110068>] positive_have_wrcomb+0x8/0x10
[<c0106831>] die+0x301/0x310
[<c0302995>] do_page_fault+0x205/0x610
[<c0302790>] do_page_fault+0x0/0x610
[<c0105e09>] error_code+0x39/0x40
[<c011007b>] generic_validate_add_page+0xb/0x100
[<c011e5ab>] enqueue_task+0x2b/0x90
[<c011e631>] __activate_task+0x21/0x40
[<c01209b1>] try_to_wake_up+0x321/0x450
[<c0144822>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b59>] wake_up_process_mutex+0x19/0x20
[<c0300531>] rt_spin_lock_slowunlock+0x41/0x70
[<c02ff34c>] __schedule+0xc0c/0xee0
[<c014091a>] hrtimer_interrupt+0x18a/0x250
[<c015848e>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e7808>] start_kernel+0x368/0x440
[<c03e7220>] unknown_bootoption+0x0/0x280
...

Bye now!
--
rncbc aka Rui Nuno Capela
[email protected]


2006-11-03 11:30:20

by Karsten Wiese

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Am Donnerstag, 2. November 2006 11:43 schrieb Rui Nuno Capela:
>
> While on UP kernels everything works great and without major issues to
> report, problem goes here on the SMP/HT one. Simple fact: it hangs,
> freezes in some non-deterministic ways. However, sometimes, it is just a
> matter of a couple of dozen clicks while browsing over those
> funky-ajax-enabled-web2 sites :)
>
> ........
>
> Call Trace:
> [<c011e631>] __activate_task+0x21/0x40
> [<c01209b1>] try_to_wake_up+0x321/0x450
> [<c0144822>] wakeup_next_waiter+0xd2/0x1d0
> [<c0120b59>] wake_up_process_mutex+0x19/0x20
> [<c0300531>] rt_spin_lock_slowunlock+0x41/0x70
> [<c02ff34c>] __schedule+0xc0c/0xee0
> [<c014091a>] hrtimer_interrupt+0x18a/0x250

Does it make a difference, if you build & run with
CONFIG_HIGH_RES_TIMERS disabled?

Karsten

2006-11-03 22:51:54

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Karsten Wiese wrote:
>
> Does it make a difference, if you build & run with
> CONFIG_HIGH_RES_TIMERS disabled?
>

Now with CONFIG_HIGH_RES_TIMERS not set, it seems to live longer, but
not enough. Notice the soft lockup being detected:

...
Oops: 0002 [#1]
__schedule+0x644/0xee0
[<c011e5f1>] __activate_task+0x21/0x40
[<c011e5f1>] __activate_task+0x21/0x40
[<c01206ab>] try_to_wake_up+0x5b/0x450
[<c0143c68>] __rt_mutex_adjust_prio+0x8/0x20
[<c01444f1>] task_blocks_on_rt_mutex+0x111/0x210
[<c02feac0>] schedule+0x30/0x100
[<c02ff9cb>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
BUG: scheduling from the idle thread!
[<c02fe149>] __schedule+0x6d9/0xee0
[<c011e5f1>] __activate_task+0x21/0x40
[<c011e5f1>] __activate_task+0x21/0x40
[<c0143c68>] __rt_mutex_adjust_prio+0x8/0x20
[<c01444f1>] task_blocks_on_rt_mutex+0x111/0x210
[<c02feac0>] schedule+0x30/0x100
[<c02ff9cb>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 snd_seq_dummy edd
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event snd_seq button
battery ac w83627hf hwmon_vid hwmon i2c_isa loop dm_mod intel_rng usbhid
wacom snd_cs46xx snd_intel8x0 gameport snd_ice1712 snd_ice17xx_ak4xxx
snd_ak4xxx_adda snd_cs8427 snd_ac97_codec snd_ac97_bus i2c_i801 snd_i2c
snd_pcm i2c_core snd_mpu401_uart intel_agp snd_timer snd_rawmidi
snd_seq_device agpgart i8xx_tco snd ehci_hcd soundcore snd_page_alloc
sk98lin ide_cd cdrom shpchp ohci1394 pci_hotplug ieee1394 uhci_hcd
usbcore ext3 jbd reiserfs fan thermal processor piix ide_disk ide_core
CPU: 0
EIP: 0060:[<c011e56b>] Not tainted VLI
EFLAGS: 00010046 (2.6.18.1-rt7.1-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f708 ebx: c188f28c ecx: 00000000 edx: dfd010d8
esi: dfd010b0 edi: c188edc0 ebp: e3659d10 esp: e3659d08
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process kio_http (pid: 7114, ti=e3658000 task=f79282b0 task.ti=e3658000)
Stack: c188edc0 dfd010b0 e3659d20 c011e5f1 00000001 dfd010b0 e3659d84
c0120971
00000001 c188f740 c042b024 00000000 0000001f e3658000 00000001
00000000
00000004 00000000 00000000 00000000 00000000 00000001 00000001
c03d4280
Call Trace:
[<c011e5f1>] __activate_task+0x21/0x40
[<c0120971>] try_to_wake_up+0x321/0x450
[<c0143b62>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b19>] wake_up_process_mutex+0x19/0x20
[<c02ff861>] rt_spin_lock_slowunlock+0x41/0x70
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c01f6e54>] rb_insert_color+0x64/0xb0
[<c013f432>] enqueue_hrtimer+0x72/0x90
[<c02feac0>] schedule+0x30/0x100
[<c0143018>] do_futex+0xa08/0xee0
[<c029102d>] move_addr_to_user+0x7d/0x90
[<c013f610>] hrtimer_wakeup+0x0/0x20
[<c0120aa0>] default_wake_function+0x0/0x20
[<c0197c50>] iput+0x60/0x90
[<c014358a>] sys_futex+0x9a/0xd0
[<c01052cd>] sysenter_past_esp+0x56/0x79
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 b0 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011e56b>] enqueue_task+0x2b/0x90 SS:ESP 0068:e3659d08
<6>note: kio_http[7114] exited with preempt_count 3
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003d2>] __spin_lock_irqsave+0x22/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003d2>] __spin_lock_irqsave+0x22/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c015740f>] softlockup_tick+0xcf/0x130
[<c01323d1>] update_process_times+0x31/0x80
[<c0141021>] handle_update_profile+0x11/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c03003cf>] __spin_lock_irqsave+0x1f/0x40
[<c02ff946>] rt_spin_lock_slowlock+0x16/0x1b0
[<c0120b59>] wake_up_process+0x19/0x20
[<c0117674>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d57>] apic_timer_interrupt+0x1f/0x24
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0120b59>] wake_up_process+0x19/0x20
[<c01577ce>] redirect_hardirq+0x5e/0xa0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
...

What next?
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-04 02:04:45

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

> Karsten Wiese wrote:
>> Does it make a difference, if you build & run with
>> CONFIG_HIGH_RES_TIMERS disabled?
>>
>

More food for thought; still with CONFIG_HIGH_RES_TIMERS not set:

...
Oops: 0002 [#1]
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 edd snd_seq_dummy
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event w83627hf
hwmon_vid snd_seq button hwmon i2c_isa battery ac loop dm_mod usbhid
wacom intel_rng ehci_hcd shpchp pci_hotplug snd_ice1712
snd_ice17xx_ak4xxx intel_agp snd_ak4xxx_adda snd_cs8427 snd_i2c
snd_intel8x0 i2c_i801 snd_mpu401_uart agpgart i2c_core uhci_hcd ide_cd
cdrom usbcore ohci1394 ieee1394 snd_cs46xx gameport snd_rawmidi
snd_seq_device snd_ac97_codec snd_ac97_bus snd_pcm snd_timer snd
soundcore snd_page_alloc i8xx_tco sk98lin ext3 jbd reiserfs fan thermal
processor piix ide_disk ide_core
CPU: 1
EIP: 0060:[<c011e56b>] Not tainted VLI
EFLAGS: 00210046 (2.6.18.1-rt7.1-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c180f708 ebx: c180f28c ecx: 00000000 edx: c0357868
esi: c0357840 edi: c180edc0 ebp: f7291cd0 esp: f7291cc8
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process ssh-agent (pid: 3751, ti=f7290000 task=dfcb2630 task.ti=f7290000)
Stack: c180edc0 c0357840 f7291ce0 c011e5f1 00000001 c0357840 f7291d44
c0120971
38c0f067 ff898284 c17181e0 00000000 0000001f f7290000 00000000
00000001
00000004 dfd010b0 c0357840 7e7ad015 00000009 b7ca1000 f7bc7ef0
c03d4280
Call Trace:
[<c011e5f1>] __activate_task+0x21/0x40
[<c0120971>] try_to_wake_up+0x321/0x450
[<c0143b62>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b19>] wake_up_process_mutex+0x19/0x20
[<c02ff861>] rt_spin_lock_slowunlock+0x41/0x70
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c01439cb>] _atomic_dec_and_spin_lock+0x2b/0x40
[<c01968ae>] dput+0x1e/0x140
[<c02fefc5>] preempt_schedule_irq+0x55/0x80
[<c010526c>] need_resched+0x20/0x24
[<c010a41a>] convert_fxsr_to_user+0x10a/0x1a0
[<c010a92d>] save_i387+0x12d/0x1e0
[<c0104546>] setup_sigcontext+0x106/0x190
[<c0104e49>] do_notify_resume+0x5e9/0x710
[<c02fefc5>] preempt_schedule_irq+0x55/0x80
[<c010526c>] need_resched+0x20/0x24
[<c01923dd>] sys_select+0x4d/0x1b0
[<c0104759>] restore_sigcontext+0x169/0x190
[<c01053cc>] work_notifysig+0x13/0x1b
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 b0 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011e56b>] enqueue_task+0x2b/0x90 SS:ESP 0068:f7291cc8
<6>note: ssh-agent[3751] exited with preempt_count 3

...
Oops: 0002 [#1]
__schedule+0x644/0xee0
[<c011e5f1>] __activate_task+0x21/0x40
[<c011e5f1>] __activate_task+0x21/0x40
[<c01206ab>] try_to_wake_up+0x5b/0x450
[<c01206ab>] try_to_wake_up+0x5b/0x450
[<c0143c68>] __rt_mutex_adjust_prio+0x8/0x20
[<c01444f1>] task_blocks_on_rt_mutex+0x111/0x210
[<c01f42d2>] __next_cpu+0x12/0x30
[<c02feac0>] schedule+0x30/0x100
[<c02ff9cb>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
BUG: scheduling from the idle thread!
[<c02fe149>] __schedule+0x6d9/0xee0
[<c011e5f1>] __activate_task+0x21/0x40
[<c011e5f1>] __activate_task+0x21/0x40
[<c01206ab>] try_to_wake_up+0x5b/0x450
[<c0143c68>] __rt_mutex_adjust_prio+0x8/0x20
[<c01444f1>] task_blocks_on_rt_mutex+0x111/0x210
[<c01f42d2>] __next_cpu+0x12/0x30
[<c02feac0>] schedule+0x30/0x100
[<c02ff9cb>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c0302b6e>] kprobe_flush_task+0xe/0x50
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 edd snd_seq_dummy
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event w83627hf
snd_seq hwmon_vid hwmon i2c_isa button battery ac loop dm_mod intel_rng
usbhid wacom shpchp snd_cs46xx i2c_i801 pci_hotplug gameport i2c_core
intel_agp ide_cd cdrom ehci_hcd uhci_hcd agpgart snd_ice1712
snd_ice17xx_ak4xxx snd_ak4xxx_adda ohci1394 i8xx_tco usbcore sk98lin
snd_cs8427 ieee1394 snd_i2c snd_mpu401_uart snd_rawmidi snd_seq_device
snd_intel8x0 snd_ac97_codec snd_ac97_bus snd_pcm snd_timer snd soundcore
snd_page_alloc ext3 jbd reiserfs fan thermal processor piix ide_disk
ide_core
CPU: 0
EIP: 0060:[<c011e56b>] Not tainted VLI
EFLAGS: 00010046 (2.6.18.1-rt7.1-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f28c ebx: c188ee10 ecx: 00000000 edx: dfd010d8
esi: dfd010b0 edi: c188edc0 ebp: c03e1e8c esp: c03e1e84
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process swapper (pid: 0, ti=c03e0000 task=c0357840 task.ti=c03e0000)
Stack: c188edc0 dfd010b0 c03e1e9c c011e5f1 00000001 dfd010b0 c03e1f00
c0120971
f7bc3930 c03e1eb8 00000001 00000000 0000001f c03e0000 00000001
00000000
00000004 dfd13670 c03e1f30 00000001 dfd005b0 c180edc0 dfd005b0
c03d4280
Call Trace:
[<c011e5f1>] __activate_task+0x21/0x40
[<c0120971>] try_to_wake_up+0x321/0x450
[<c0143b62>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b19>] wake_up_process_mutex+0x19/0x20
[<c02ff861>] rt_spin_lock_slowunlock+0x41/0x70
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 b0 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011e56b>] enqueue_task+0x2b/0x90 SS:ESP 0068:c03e1e84
<0>Kernel panic - not syncing: Attempted to kill the idle task!
[<c01271a1>] panic+0x51/0x120
[<c012ae50>] do_exit+0x6e0/0xa90
[<c0106462>] show_registers+0x172/0x240
[<c012780b>] printk+0x1b/0x20
[<c0110068>] positive_have_wrcomb+0x8/0x10
[<c0106831>] die+0x301/0x310
[<c0301cc5>] do_page_fault+0x205/0x610
[<c0301ac0>] do_page_fault+0x0/0x610
[<c0105e09>] error_code+0x39/0x40
[<c011007b>] generic_validate_add_page+0xb/0x100
[<c011e56b>] enqueue_task+0x2b/0x90
[<c011e5f1>] __activate_task+0x21/0x40
[<c0120971>] try_to_wake_up+0x321/0x450
[<c0143b62>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b19>] wake_up_process_mutex+0x19/0x20
[<c02ff861>] rt_spin_lock_slowunlock+0x41/0x70
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
swapper/0[CPU#0]: BUG in smp_call_function at arch/i386/kernel/smp.c:557
[<c01283f6>] __WARN_ON+0x66/0x90
[<c0115220>] stop_this_cpu+0x0/0x40
[<c011501a>] smp_call_function+0xda/0xe0
[<c012780b>] printk+0x1b/0x20
[<c011503b>] smp_send_stop+0x1b/0x30
[<c01271b4>] panic+0x64/0x120
[<c012ae50>] do_exit+0x6e0/0xa90
[<c0106462>] show_registers+0x172/0x240
[<c012780b>] printk+0x1b/0x20
[<c0110068>] positive_have_wrcomb+0x8/0x10
[<c0106831>] die+0x301/0x310
[<c0301cc5>] do_page_fault+0x205/0x610
[<c0301ac0>] do_page_fault+0x0/0x610
[<c0105e09>] error_code+0x39/0x40
[<c011007b>] generic_validate_add_page+0xb/0x100
[<c011e56b>] enqueue_task+0x2b/0x90
[<c011e5f1>] __activate_task+0x21/0x40
[<c0120971>] try_to_wake_up+0x321/0x450
[<c0143b62>] wakeup_next_waiter+0xd2/0x1d0
[<c0120b19>] wake_up_process_mutex+0x19/0x20
[<c02ff861>] rt_spin_lock_slowunlock+0x41/0x70
[<c02fe67c>] __schedule+0xc0c/0xee0
[<c0105ceb>] reschedule_interrupt+0x1f/0x24
[<c0103a70>] default_idle+0x0/0x80
[<c0103ba1>] cpu_idle+0xb1/0x120
[<c03e5808>] start_kernel+0x368/0x440
[<c03e5220>] unknown_bootoption+0x0/0x280
...


I will now try turning on some .config debug options, e.g.
CONFIG_PREEMPT, and if I can catch something I'll be back here with some
more dumps ;)

Cheers.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-04 10:50:39

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Rui Nuno Capela wrote:
>
> I will now try turning on some .config debug options, e.g.
> CONFIG_PREEMPT, and if I can catch something I'll be back here with some
> more dumps ;)
>


Turned on some kernel debug switches, notably CONFIG_DEBUG_PREEMPT,
CONFIG_DEBUG_RT_MUTEXES, CONFIG_DEBUG_SLAB
and CONFIG_LOCKDEP, and it crashed on the very first boot. These are
the traces that could be captured on serial console:

...
=========================================================
[ INFO: possible irq lock inversion dependency detected ]
---------------------------------------------------------
swapper/1 just changed the state of lock:
(rtc_lock){-...}, at: [<c0426f0b>] rtc_init+0xbb/0x1c0
but this lock was taken by another, hard-irq-safe lock in the past:
(name){+...}

and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
no locks held by swapper/1.

the first lock's dependencies:
-> (rtc_lock){-...} ops: 2 {
initial-use at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0108d93>] read_persistent_clock+0x13/0x120
[<c041c448>] timekeeping_init+0xc8/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0
hardirq-on-W at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0426f0b>] rtc_init+0xbb/0x1c0
[<c0100430>] init+0x130/0x430
[<c0103005>] kernel_thread_helper+0x5/0x10
}
... key at: [<c03ec8d0>] rtc_lock+0x50/0x80

the second lock's dependencies:
-> (name){+...} ops: 6297 {
initial-use at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030dd95>] __spin_lock+0x35/0x50
[<c041c39d>] timekeeping_init+0x1d/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0
in-hardirq-W at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030dd95>] __spin_lock+0x35/0x50
[<c01430f0>] handle_tick_update_profile+0x10/0x50
[<c01089cb>] timer_interrupt+0x1b/0x60
[<c015ec3f>] handle_IRQ_event+0x5f/0xf0
[<c01608ac>] handle_level_irq+0xac/0x140
[<c0107d1c>] do_IRQ+0x4c/0xc0
[<c0105e89>] common_interrupt+0x25/0x2c
[<c026da4f>] serial8250_console_putchar+0x1f/0x90
[<c0268094>] uart_console_write+0x24/0x60
[<c026b43a>] serial8250_console_write+0x8a/0x150
[<c01288e4>] __call_console_drivers+0x64/0x80
[<c0128942>] _call_console_drivers+0x42/0x80
[<c01290dd>] release_console_sem+0xed/0x270
[<c01293bb>] register_console+0xcb/0x200
[<c0427592>] serial8250_console_init+0x12/0x20
[<c04262d5>] console_init+0x25/0x40
[<c040970a>] start_kernel+0x1da/0x450
[<00000000>] 0x0
}
... key at: [<c03efb98>] xtime_lock+0x18/0x80
-> (clocksource_lock){....} ops: 1962 {
initial-use at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030e0e2>] __spin_lock_irqsave+0x42/0x60
[<c01428cd>] clocksource_get_next+0xd/0x50
[<c041c3b0>] timekeeping_init+0x30/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0
}
... key at: [<c03efe14>] clocksource_lock+0x14/0x80
... acquired at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030e0e2>] __spin_lock_irqsave+0x42/0x60
[<c01428cd>] clocksource_get_next+0xd/0x50
[<c041c3b0>] timekeeping_init+0x30/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0

-> (rtc_lock){....} ops: 3 {
initial-use at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030e0e2>] __spin_lock_irqsave+0x42/0x60
[<c030ce31>] rt_spin_lock_slowlock+0x21/0x1d0
[<c030d761>] rt_spin_lock+0x11/0x40
[<c0108d93>] read_persistent_clock+0x13/0x120
[<c041c448>] timekeeping_init+0xc8/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0
}
... key at: [<c03ec894>] rtc_lock+0x14/0x80
... acquired at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030e0e2>] __spin_lock_irqsave+0x42/0x60
[<c030ce31>] rt_spin_lock_slowlock+0x21/0x1d0
[<c030d761>] rt_spin_lock+0x11/0x40
[<c0108d93>] read_persistent_clock+0x13/0x120
[<c041c448>] timekeeping_init+0xc8/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0

-> (rtc_lock){-...} ops: 2 {
initial-use at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0108d93>] read_persistent_clock+0x13/0x120
[<c041c448>] timekeeping_init+0xc8/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0
hardirq-on-W at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0426f0b>] rtc_init+0xbb/0x1c0
[<c0100430>] init+0x130/0x430
[<c0103005>] kernel_thread_helper+0x5/0x10
}
... key at: [<c03ec8d0>] rtc_lock+0x50/0x80
... acquired at:
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0108d93>] read_persistent_clock+0x13/0x120
[<c041c448>] timekeeping_init+0xc8/0x140
[<c04096e5>] start_kernel+0x1b5/0x450
[<00000000>] 0x0


stack backtrace:
[<c0106bb2>] show_trace+0x12/0x20
[<c0106ca9>] dump_stack+0x19/0x20
[<c01446e7>] print_irq_inversion_bug+0x107/0x130
[<c0144842>] check_usage_backwards+0x42/0x50
[<c0144c85>] mark_lock+0x335/0x5f0
[<c01458c4>] __lock_acquire+0x124/0xe60
[<c0146965>] lock_acquire+0x75/0xa0
[<c030d782>] rt_spin_lock+0x32/0x40
[<c0426f0b>] rtc_init+0xbb/0x1c0
[<c0100430>] init+0x130/0x430
[<c0103005>] kernel_thread_helper+0x5/0x10
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

...
BUG: scheduling while atomic: swapper/0x00000001/0, CPU#0
BUG: unable to handle kernel NULL pointer dereference at virtual address
00000000
printing eip:
c011f7ab
*pde = 00000000
Oops: 0002 [#1]
PREEMPT SMP
Modules linked in: loop dm_mod intel_rng usbhid wacom shpchp pci_hotplug
snd_intel8x0 snd_cs46xx gameport snd_ice1712 snd_ice17xx_ak4xxx
snd_ak4xxx_adda snd_cs8427 snd_ac97_codec snd_pcm snd_timer i2c_i801
ohci1394 ieee1394 i8xx_tco sk98lin snd_ac97_bus snd_i2c snd_mpu401_uart
intel_agp agpgart snd_rawmidi snd_seq_device i2c_core snd snd_page_alloc
soundcore ehci_hcd uhci_hcd usbcore ide_cd cdrom ext3 jbd reiserfs fan
thermal processor piix ide_disk ide_core
CPU: 1
EIP: 0060:[<c011f7ab>] Not tainted VLI
EFLAGS: 00010046 (2.6.18.1-rt7.2-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c18204e4 ebx: c1820068 ecx: 00000000 edx: c036a988
esi: c036a960 edi: c1820000 ebp: f74b9d6c esp: f74b9d64
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process boot.cleanup (pid: 2269, ti=f74b8000 task=f7a820b0 task.ti=f74b8000)
Stack: c1820000 c036a960 f74b9d7c c011f831 00000001 c036a960 f74b9ddc
c0121d2a
f7a820b0 00000046 c030ce52 00000000 0000001f 00000000 00000001
00000004
00000000 f74b9dd0 00000046 00000000 00000002 00000001 00000000
f74b9ddc
Call Trace:
[<c01065c1>] show_stack_log_lvl+0xb1/0xe0
[<c01067cc>] show_registers+0x1dc/0x270
[<c0106993>] die+0x133/0x300
[<c030fee1>] do_page_fault+0x1f1/0x5e0
[<c0106021>] error_code+0x39/0x40
[<c011f831>] __activate_task+0x21/0x40
[<c0121d2a>] try_to_wake_up+0x31a/0x440
[<c0121ec9>] wake_up_process_mutex+0x19/0x20
[<c014a02f>] wakeup_next_waiter+0xef/0x1e0
[<c030cd2c>] rt_spin_lock_slowunlock+0x5c/0x80
[<c030d7ad>] rt_spin_unlock+0x1d/0x20
[<c0310d3a>] kprobe_flush_task+0x3a/0x50
[<c030bab5>] __schedule+0xbc5/0xf90
[<c030bff0>] schedule+0x30/0x100
[<c012b82c>] do_wait+0x73c/0xc00
[<c012bd22>] sys_wait4+0x32/0x40
[<c012bd57>] sys_waitpid+0x27/0x30
[<c0105419>] sysenter_past_esp+0x56/0x8d
---------------------------
| preempt count: 00000004 ]
| 4-level deep critical section nesting:
----------------------------------------
.. [<c030af41>] .... __schedule+0x51/0xf90
.....[<c030bff0>] .. ( <= schedule+0x30/0x100)
.. [<c030e0c0>] .... __spin_lock_irqsave+0x20/0x60
.....[<c030cce4>] .. ( <= rt_spin_lock_slowunlock+0x14/0x80)
.. [<c030dd73>] .... __spin_lock+0x13/0x50
.....[<c012090c>] .. ( <= task_rq_lock+0x3c/0x70)
.. [<c030e0c0>] .... __spin_lock_irqsave+0x20/0x60
.....[<c01068af>] .. ( <= die+0x4f/0x300)

Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 24 ec 36 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011f7ab>] enqueue_task+0x2b/0x90 SS:ESP 0068:f74b9d64
<3>BUG: sleeping function called from invalid context
boot.cleanup(2269) at kernel/rtmutex.c:1155
in_atomic():1 [00000003], irqs_disabled():1
[<c0106bb2>] show_trace+0x12/0x20
[<c0106ca9>] dump_stack+0x19/0x20
[<c011f460>] __might_sleep+0xe0/0x110
[<c030cde8>] rt_mutex_lock+0x18/0x40
[<c014b885>] rt_down_read+0x55/0x80
[<c0137c7c>] blocking_notifier_call_chain+0x1c/0x50
[<c012a1f1>] profile_task_exit+0x11/0x20
[<c012bdec>] do_exit+0x1c/0xab0
[<c0106b58>] die+0x2f8/0x300
[<c030fee1>] do_page_fault+0x1f1/0x5e0
[<c0106021>] error_code+0x39/0x40
[<c011f831>] __activate_task+0x21/0x40
[<c0121d2a>] try_to_wake_up+0x31a/0x440
[<c0121ec9>] wake_up_process_mutex+0x19/0x20
[<c014a02f>] wakeup_next_waiter+0xef/0x1e0
[<c030cd2c>] rt_spin_lock_slowunlock+0x5c/0x80
[<c030d7ad>] rt_spin_unlock+0x1d/0x20
[<c0310d3a>] kprobe_flush_task+0x3a/0x50
[<c030bab5>] __schedule+0xbc5/0xf90
[<c030bff0>] schedule+0x30/0x100
[<c012b82c>] do_wait+0x73c/0xc00
[<c012bd22>] sys_wait4+0x32/0x40
[<c012bd57>] sys_waitpid+0x27/0x30
[<c0105419>] sysenter_past_esp+0x56/0x8d
---------------------------
| preempt count: 00000003 ]
| 3-level deep critical section nesting:
----------------------------------------
.. [<c030af41>] .... __schedule+0x51/0xf90
.....[<c030bff0>] .. ( <= schedule+0x30/0x100)
.. [<c030e0c0>] .... __spin_lock_irqsave+0x20/0x60
.....[<c030cce4>] .. ( <= rt_spin_lock_slowunlock+0x14/0x80)
.. [<c030dd73>] .... __spin_lock+0x13/0x50
.....[<c012090c>] .. ( <= task_rq_lock+0x3c/0x70)

note: boot.cleanup[2269] exited with preempt_count 3


Bye now.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-04 15:08:44

by Karsten Wiese

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Am Samstag, 4. November 2006 11:54 schrieb Rui Nuno Capela:
> Rui Nuno Capela wrote:
> >
> > I will now try turning on some .config debug options, e.g.
> > CONFIG_PREEMPT, and if I can catch something I'll be back here with some
> > more dumps ;)
> >
>
>
> Turned on some kernel debug switches, notably CONFIG_DEBUG_PREEMPT,
> CONFIG_DEBUG_RT_MUTEXES, CONFIG_DEBUG_SLAB
> and CONFIG_LOCKDEP, and it crashed on the very first boot. These are
> the traces that could be captured on serial console:
>
> ...
> =========================================================
> [ INFO: possible irq lock inversion dependency detected ]
> ---------------------------------------------------------
> swapper/1 just changed the state of lock:
> (rtc_lock){-...}, at: [<c0426f0b>] rtc_init+0xbb/0x1c0
> but this lock was taken by another, hard-irq-safe lock in the past:
> (name){+...}
>
> and interrupts could create inverse lock ordering between them.
>
>
> other info that might help us debug this:
> no locks held by swapper/1.
>
> the first lock's dependencies:
> -> (rtc_lock){-...} ops: 2 {
> initial-use at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0108d93>] read_persistent_clock+0x13/0x120
> [<c041c448>] timekeeping_init+0xc8/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
> hardirq-on-W at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0426f0b>] rtc_init+0xbb/0x1c0
> [<c0100430>] init+0x130/0x430
> [<c0103005>] kernel_thread_helper+0x5/0x10
> }
> ... key at: [<c03ec8d0>] rtc_lock+0x50/0x80
>
> the second lock's dependencies:
> -> (name){+...} ops: 6297 {
> initial-use at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030dd95>] __spin_lock+0x35/0x50
> [<c041c39d>] timekeeping_init+0x1d/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
> in-hardirq-W at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030dd95>] __spin_lock+0x35/0x50
> [<c01430f0>] handle_tick_update_profile+0x10/0x50
> [<c01089cb>] timer_interrupt+0x1b/0x60
> [<c015ec3f>] handle_IRQ_event+0x5f/0xf0
> [<c01608ac>] handle_level_irq+0xac/0x140
> [<c0107d1c>] do_IRQ+0x4c/0xc0
> [<c0105e89>] common_interrupt+0x25/0x2c
> [<c026da4f>] serial8250_console_putchar+0x1f/0x90
> [<c0268094>] uart_console_write+0x24/0x60
> [<c026b43a>] serial8250_console_write+0x8a/0x150
> [<c01288e4>] __call_console_drivers+0x64/0x80
> [<c0128942>] _call_console_drivers+0x42/0x80
> [<c01290dd>] release_console_sem+0xed/0x270
> [<c01293bb>] register_console+0xcb/0x200
> [<c0427592>] serial8250_console_init+0x12/0x20
> [<c04262d5>] console_init+0x25/0x40
> [<c040970a>] start_kernel+0x1da/0x450
> [<00000000>] 0x0
> }
> ... key at: [<c03efb98>] xtime_lock+0x18/0x80
> -> (clocksource_lock){....} ops: 1962 {
> initial-use at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030e0e2>] __spin_lock_irqsave+0x42/0x60
> [<c01428cd>] clocksource_get_next+0xd/0x50
> [<c041c3b0>] timekeeping_init+0x30/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
> }
> ... key at: [<c03efe14>] clocksource_lock+0x14/0x80
> ... acquired at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030e0e2>] __spin_lock_irqsave+0x42/0x60
> [<c01428cd>] clocksource_get_next+0xd/0x50
> [<c041c3b0>] timekeeping_init+0x30/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
>
> -> (rtc_lock){....} ops: 3 {
> initial-use at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030e0e2>] __spin_lock_irqsave+0x42/0x60
> [<c030ce31>] rt_spin_lock_slowlock+0x21/0x1d0
> [<c030d761>] rt_spin_lock+0x11/0x40
> [<c0108d93>] read_persistent_clock+0x13/0x120
> [<c041c448>] timekeeping_init+0xc8/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
> }
> ... key at: [<c03ec894>] rtc_lock+0x14/0x80
> ... acquired at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030e0e2>] __spin_lock_irqsave+0x42/0x60
> [<c030ce31>] rt_spin_lock_slowlock+0x21/0x1d0
> [<c030d761>] rt_spin_lock+0x11/0x40
> [<c0108d93>] read_persistent_clock+0x13/0x120
> [<c041c448>] timekeeping_init+0xc8/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
>
> -> (rtc_lock){-...} ops: 2 {
> initial-use at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0108d93>] read_persistent_clock+0x13/0x120
> [<c041c448>] timekeeping_init+0xc8/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
> hardirq-on-W at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0426f0b>] rtc_init+0xbb/0x1c0
> [<c0100430>] init+0x130/0x430
> [<c0103005>] kernel_thread_helper+0x5/0x10
> }
> ... key at: [<c03ec8d0>] rtc_lock+0x50/0x80
> ... acquired at:
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0108d93>] read_persistent_clock+0x13/0x120
> [<c041c448>] timekeeping_init+0xc8/0x140
> [<c04096e5>] start_kernel+0x1b5/0x450
> [<00000000>] 0x0
>
>
> stack backtrace:
> [<c0106bb2>] show_trace+0x12/0x20
> [<c0106ca9>] dump_stack+0x19/0x20
> [<c01446e7>] print_irq_inversion_bug+0x107/0x130
> [<c0144842>] check_usage_backwards+0x42/0x50
> [<c0144c85>] mark_lock+0x335/0x5f0
> [<c01458c4>] __lock_acquire+0x124/0xe60
> [<c0146965>] lock_acquire+0x75/0xa0
> [<c030d782>] rt_spin_lock+0x32/0x40
> [<c0426f0b>] rtc_init+0xbb/0x1c0
> [<c0100430>] init+0x130/0x430
> [<c0103005>] kernel_thread_helper+0x5/0x10
> ---------------------------
> | preempt count: 00000000 ]
> | 0-level deep critical section nesting:
> ----------------------------------------

Kernel stumbles over serial-console here ?

>
> ...
> BUG: scheduling while atomic: swapper/0x00000001/0, CPU#0
> BUG: unable to handle kernel NULL pointer dereference at virtual address
> 00000000

Is it always address 00000000 in your logs, when enqueue_task() oopsed?

> printing eip:
> c011f7ab
> *pde = 00000000
> Oops: 0002 [#1]
> PREEMPT SMP
> Modules linked in: loop dm_mod intel_rng usbhid wacom shpchp pci_hotplug
> snd_intel8x0 snd_cs46xx gameport snd_ice1712 snd_ice17xx_ak4xxx
> snd_ak4xxx_adda snd_cs8427 snd_ac97_codec snd_pcm snd_timer i2c_i801
> ohci1394 ieee1394 i8xx_tco sk98lin snd_ac97_bus snd_i2c snd_mpu401_uart
> intel_agp agpgart snd_rawmidi snd_seq_device i2c_core snd snd_page_alloc
> soundcore ehci_hcd uhci_hcd usbcore ide_cd cdrom ext3 jbd reiserfs fan
> thermal processor piix ide_disk ide_core
> CPU: 1
> EIP: 0060:[<c011f7ab>] Not tainted VLI
> EFLAGS: 00010046 (2.6.18.1-rt7.2-smp #1)
> EIP is at enqueue_task+0x2b/0x90

Please
$ gdb kernel/sched.o
(gdb) disassemble enqueue_task
and post output.
Maybe we can see there what exactly is 0 and shouldn't be.

Karsten

2006-11-05 15:52:09

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

After a suggestion from Mike Galbraith, I now turned to pure and
original 2.6.18-rt7 and configured with:

CONFIG_FRAME_POINTER=y
CONFIG_UNWIND_INFO=y
CONFIG_STACK_UNWIND=y

Nasty things still do happen, as the following capture can tell as evidence:

...
Oops: 0002 [#1]
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8d2f>] __schedule+0x63f/0xea0
[<c02f9700>] schedule+0x30/0x100
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 snd_seq_dummy
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event edd snd_seq
button battery ac w83627hf hwmon_vid hwmon i2c_isa loop dm_mod usbhid
wacom intel_rng shpchp pci_hotplug snd_ice1712 snd_ice17xx_ak4xxx
snd_ak4xxx_adda snd_cs8427 ohci1394 snd_i2c ieee1394 snd_mpu401_uart
i8xx_tco ide_cd snd_cs46xx gameport snd_rawmidi snd_seq_device
snd_intel8x0 cdrom uhci_hcd snd_ac97_codec snd_ac97_bus snd_pcm sk98lin
i2c_i801 snd_timer snd i2c_core soundcore snd_page_alloc ehci_hcd
usbcore intel_agp agpgart ext3 jbd reiserfs fan thermal processor piix
ide_disk ide_core
CPU: 0
EIP: 0060:[<c011f4cb>] Not tainted VLI
EFLAGS: 00010046 (2.6.18-rt7.0-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f708 ebx: c188f28c ecx: 00000000 edx: dfd490d8
esi: dfd490b0 edi: c188edc0 ebp: c5729d74 esp: c5729d6c
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process sh (pid: 1693, ti=c5728000 task=dfc8d4b0 task.ti=c5728000)
Stack: c188edc0 dfd490b0 c5729d84 c011f551 00000001 dfd490b0 c5729de8
c01218c1
00000000 c5729da8 c0168fd3 00000000 0000001f c5728000 00000001
00000000
00000004 c5729dcc c0120550 c180edc0 00000001 c19e8bb0 c5729dcc
c02fb4c8
Call Trace:
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c02f9700>] schedule+0x30/0x100
[<c012b04c>] do_wait+0x72c/0xbf0
[<c012b542>] sys_wait4+0x32/0x40
[<c012b577>] sys_waitpid+0x27/0x30
[<c0105309>] sysenter_past_esp+0x56/0x79
[<b7ef1410>] 0xb7ef1410
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 60 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011f4cb>] enqueue_task+0x2b/0x90 SS:ESP 0068:c5729d6c
<6>note: sh[1693] exited with preempt_count 3
...

Bye.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-05 16:44:21

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Rui Nuno Capela wrote:
> After a suggestion from Mike Galbraith, I now turned to pure and
> original 2.6.18-rt7 and configured with:
>
> CONFIG_FRAME_POINTER=y
> CONFIG_UNWIND_INFO=y
> CONFIG_STACK_UNWIND=y
>
> Nasty things still do happen, as the following capture can tell as evidence:
>

Some more evidence, just happening:

...
Oops: 0002 [#1]
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8d2f>] __schedule+0x63f/0xea0
[<c02f9700>] schedule+0x30/0x100
[<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c02fadb2>] rt_spin_lock+0x22/0x30
[<c02fd8b1>] kprobe_flush_task+0x11/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c011760f>] start_secondary+0x43f/0x500
BUG: scheduling from the idle thread!
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8dba>] __schedule+0x6ca/0xea0
[<c02f9700>] schedule+0x30/0x100
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 snd_seq_dummy
snd_pcm_oss edd snd_mixer_oss snd_seq_midi snd_seq_midi_event snd_seq
w83627hf hwmon_vid button hwmon battery i2c_isa ac loop dm_mod intel_rng
usbhid wacom shpchp snd_ice1712 snd_ice17xx_ak4xxx snd_ak4xxx_adda
snd_cs8427 pci_hotplug snd_intel8x0 snd_i2c i8xx_tco snd_cs46xx
snd_mpu401_uart gameport snd_rawmidi snd_ac97_codec snd_ac97_bus sk98lin
snd_seq_device snd_pcm snd_timer snd ehci_hcd snd_page_alloc uhci_hcd
soundcore usbcore i2c_i801 i2c_core intel_agp ide_cd agpgart cdrom
ohci1394 ieee1394 ext3 jbd reiserfs fan thermal processor piix ide_disk
ide_core
CPU: 0
EIP: 0060:[<c011f4cb>] Not tainted VLI
EFLAGS: 00010046 (2.6.18-rt7.0-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f28c ebx: c188ee10 ecx: 00000000 edx: dfd490d8
esi: dfd490b0 edi: c188edc0 ebp: c042be34 esp: c042be2c
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process swapper (pid: 0, ti=c042a000 task=c0352840 task.ti=c042a000)
Stack: c188edc0 dfd490b0 c042be44 c011f551 00000001 dfd490b0 c042bea8
c01218c1
00000401 00000100 00000000 00000000 0000001f c042a000 00000001
00000000
00000004 c180edc0 dfd485b0 c042be88 c011f551 00000001 a1fdbacf
c042bea4
Call Trace:
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 60 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011f4cb>] enqueue_task+0x2b/0x90 SS:ESP 0068:c042be2c
<0>Kernel panic - not syncing: Attempted to kill the idle task!
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c0128081>] panic+0x51/0x110
[<c012bcd6>] do_exit+0x6e6/0xaa0
[<c0106a88>] die+0x2f8/0x300
[<c02fc9a1>] do_page_fault+0x1f1/0x5e0
[<c0105e45>] error_code+0x39/0x40
[<c011f4cb>] enqueue_task+0x2b/0x90
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
swapper/0[CPU#0]: BUG in smp_call_function at arch/i386/kernel/smp.c:557
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c01292e3>] __WARN_ON+0x63/0x80
[<c0115fbc>] smp_call_function+0xbc/0xd0
[<c0115fee>] smp_send_stop+0x1e/0x30
[<c0128094>] panic+0x64/0x110
[<c012bcd6>] do_exit+0x6e6/0xaa0
[<c0106a88>] die+0x2f8/0x300
[<c02fc9a1>] do_page_fault+0x1f1/0x5e0
[<c0105e45>] error_code+0x39/0x40
[<c011f4cb>] enqueue_task+0x2b/0x90
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
...

Another one:

...
Oops: 0002 [#1]
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8d2f>] __schedule+0x63f/0xea0
[<c02f9700>] schedule+0x30/0x100
[<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c02fadb2>] rt_spin_lock+0x22/0x30
[<c02fd8b1>] kprobe_flush_task+0x11/0x50
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 edd snd_seq_dummy
snd_pcm_oss snd_mixer_oss snd_seq_midi snd_seq_midi_event snd_seq button
w83627hf hwmon_vid battery hwmon i2c_isa ac loop dm_mod intel_rng usbhid
wacom sk98lin snd_cs46xx shpchp pci_hotplug snd_ice1712
snd_ice17xx_ak4xxx snd_ak4xxx_adda snd_cs8427 snd_i2c snd_mpu401_uart
gameport intel_agp snd_rawmidi agpgart snd_intel8x0 snd_seq_device
i8xx_tco i2c_i801 snd_ac97_codec snd_ac97_bus snd_pcm snd_timer snd
soundcore ehci_hcd snd_page_alloc i2c_core uhci_hcd usbcore ohci1394
ide_cd ieee1394 cdrom ext3 jbd reiserfs fan thermal processor piix
ide_disk ide_core
CPU: 0
EIP: 0060:[<c011f4cb>] Not tainted VLI
EFLAGS: 00010046 (2.6.18-rt7.0-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f708 ebx: c188f28c ecx: 00000000 edx: dfd490d8
esi: dfd490b0 edi: c188edc0 ebp: f63d1c0c esp: f63d1c04
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process kio_http (pid: 4485, ti=f63d0000 task=f7840230 task.ti=f63d0000)
Stack: c188edc0 dfd490b0 f63d1c1c c011f551 00000001 dfd490b0 f63d1c80
c01218c1
ff405d89 ff415e8a ff415e8a 00000000 0000001f f63d0000 00000001
00000000
00000004 c0476028 c188edc0 c0465240 f63d1c60 c01f47f5 00000001
f63d1ce4
Call Trace:
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c02f9700>] schedule+0x30/0x100
[<c02fa7ad>] rt_mutex_slowlock+0xbd/0x280
[<c02fa538>] rt_mutex_lock+0x38/0x40
[<c01456fe>] rt_down_read+0x2e/0x50
[<c0142868>] futex_wake+0x28/0xe0
[<c0143828>] do_futex+0x388/0xf90
[<c01444b9>] sys_futex+0x89/0xc0
[<c0105309>] sysenter_past_esp+0x56/0x79
[<b7faf410>] 0xb7faf410
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 60 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011f4cb>] enqueue_task+0x2b/0x90 SS:ESP 0068:f63d1c04
<6>note: kio_http[4485] exited with preempt_count 3
BUG: soft lockup detected on CPU#0! [swapper:0]
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c01596fa>] softlockup_tick+0xca/0x100
[<c0131eb2>] run_local_timers+0x12/0x20
[<c01331f4>] update_process_times+0x34/0x80
[<c0141de4>] handle_update_profile+0x14/0x30
[<c0118644>] smp_apic_timer_interrupt+0x54/0x70
[<c0105d93>] apic_timer_interrupt+0x1f/0x24
[<c02faff2>] __spin_lock_irqsave+0x22/0x40
[<c02fa557>] rt_spin_lock_slowlock+0x17/0x1b0
[<c02fadb2>] rt_spin_lock+0x22/0x30
[<c02fd8b1>] kprobe_flush_task+0x11/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
...

Bye now.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-05 18:02:19

by Daniel Walker

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

On Sun, 2006-11-05 at 16:47 +0000, Rui Nuno Capela wrote:
> Rui Nuno Capela wrote:
> > After a suggestion from Mike Galbraith, I now turned to pure and
> > original 2.6.18-rt7 and configured with:
> >
> > CONFIG_FRAME_POINTER=y
> > CONFIG_UNWIND_INFO=y
> > CONFIG_STACK_UNWIND=y
> >
> > Nasty things still do happen, as the following capture can tell as evidence:
> >
>
> Some more evidence, just happening:
>
> ...
> Oops: 0002 [#1]
> [<c0106455>] show_trace_log_lvl+0x185/0x1a0
> [<c0106ae2>] show_trace+0x12/0x20
> [<c0106c49>] dump_stack+0x19/0x20
> [<c02f8d2f>] __schedule+0x63f/0xea0
> [<c02f9700>] schedule+0x30/0x100
> [<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
> [<c02fadb2>] rt_spin_lock+0x22/0x30
> [<c02fd8b1>] kprobe_flush_task+0x11/0x50
> [<c02f91fa>] __schedule+0xb0a/0xea0
> [<c0103b61>] cpu_idle+0xb1/0x120
> [<c011760f>] start_secondary+0x43f/0x500

Is there more above this log? It looks like your cutting off some stuff
above this.

Daniel

2006-11-05 18:35:34

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

Daniel Walker wrote:
> On Sun, 2006-11-05 at 16:47 +0000, Rui Nuno Capela wrote:
>> Rui Nuno Capela wrote:
>>> After a suggestion from Mike Galbraith, I now turned to pure and
>>> original 2.6.18-rt7 and configured with:
>>>
>>> CONFIG_FRAME_POINTER=y
>>> CONFIG_UNWIND_INFO=y
>>> CONFIG_STACK_UNWIND=y
>>>
>>> Nasty things still do happen, as the following capture can tell as evidence:
>>>
>> Some more evidence, just happening:
>>
>> ...
>> Oops: 0002 [#1]
>> [<c0106455>] show_trace_log_lvl+0x185/0x1a0
>> [<c0106ae2>] show_trace+0x12/0x20
>> [<c0106c49>] dump_stack+0x19/0x20
>> [<c02f8d2f>] __schedule+0x63f/0xea0
>> [<c02f9700>] schedule+0x30/0x100
>> [<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
>> [<c02fadb2>] rt_spin_lock+0x22/0x30
>> [<c02fd8b1>] kprobe_flush_task+0x11/0x50
>> [<c02f91fa>] __schedule+0xb0a/0xea0
>> [<c0103b61>] cpu_idle+0xb1/0x120
>> [<c011760f>] start_secondary+0x43f/0x500
>
> Is there more above this log? It looks like your cutting off some stuff
> above this.
>
> Daniel

Yes there is. However I didn't find it relevant. Here it goes now (full
captured serial-console log):

--
Linux version 2.6.18-rt7.0-smp (root@gamma-suse1) (gcc version 4.1.0
(SUSE Linux)) #1 SMP PREEMPT Sat Nov 4 15:20:54 WET 2006
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000003ff30000 (usable)
BIOS-e820: 000000003ff30000 - 000000003ff40000 (ACPI data)
BIOS-e820: 000000003ff40000 - 000000003fff0000 (ACPI NVS)
BIOS-e820: 000000003fff0000 - 0000000040000000 (reserved)
BIOS-e820: 00000000ffb80000 - 0000000100000000 (reserved)
127MB HIGHMEM available.
896MB LOWMEM available.
found SMP MP-table at 000ff780
DMI 2.3 present.
Using APIC driver default
ACPI: PM-Timer IO Port: 0x808
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Processor #0 15:2 APIC version 20
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
Processor #1 15:2 APIC version 20
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 50000000 (gap: 40000000:bfb80000)
Detected 3361.206 MHz processor.
Real-Time Preemption Support (C) 2004-2006 Ingo Molnar
Built 1 zonelists. Total pages: 261936
Kernel command line: root=/dev/hda1 vga=0x31a resume=/dev/hda3
splash=silent console=tty0 console=ttyS0,115200n8
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
WARNING: experimental RCU implementation.
Clock event device pit configured with caps set: 07
PID hash table entries: 4096 (order: 12, 16384 bytes)
Console: colour dummy device 80x25
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 1030912k/1047744k available (2041k kernel code, 16444k reserved,
879k data, 224k init, 130240k highmem)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 6723.96 BogoMIPS
(lpj=3361980)
Security Framework v1.0.0 initialized
Mount-cache hash table entries: 512
CPU: Trace cache: 12K uops, L1 D cache: 8K
CPU: L2 cache: 512K
CPU: Physical Processor ID: 0
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU0: Intel P4/Xeon Extended MCE MSRs (12) available
CPU0: Thermal monitoring enabled
Compat vDSO mapped to ffffe000.
Checking 'hlt' instruction... OK.
SMP alternatives: switching to UP code
ACPI: Core revision 20060707
CPU0: Intel(R) Pentium(R) 4 CPU 2.80GHz stepping 09
SMP alternatives: switching to SMP code
Booting processor 1/1 eip 3000
Initializing CPU#1
Calibrating delay using timer specific routine.. 6720.93 BogoMIPS
(lpj=3360466)
CPU: Trace cache: 12K uops, L1 D cache: 8K
CPU: L2 cache: 512K
CPU: Physical Processor ID: 0
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#1.
CPU1: Intel P4/Xeon Extended MCE MSRs (12) available
CPU1: Thermal monitoring enabled
CPU1: Intel(R) Pentium(R) 4 CPU 2.80GHz stepping 09
Total of 2 processors activated (13444.89 BogoMIPS).
ENABLING IO-APIC IRQs
..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
Clock event device pit new caps set: 01
Clock event device lapic configured with caps set: 06
checking TSC synchronization across 2 CPUs: passed.
Clock event device pit new caps set: 01
Clock event device lapic configured with caps set: 06
Brought up 2 CPUs
checking if image is initramfs... it is
Freeing initrd memory: 2512k freed
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xf0031, last bus=2
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI quirk: region 0800-087f claimed by ICH4 ACPI/GPIO/TCO
PCI quirk: region 0480-04bf claimed by ICH4 GPIO
PCI: Ignoring BAR0-3 of IDE controller 0000:00:1f.1
PCI: Transparent bridge - 0000:00:1e.0
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 *10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 *7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKD] (IRQs *3 4 5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 10 *11 12 14 15)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 *5 6 7 10 11 12 14 15)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 10 *11 12 14 15)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
pnp: PnP ACPI: found 13 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:09: ioport range 0x680-0x6ff has been reserved
pnp: 00:09: ioport range 0x290-0x297 has been reserved
PCI: Bridge: 0000:00:01.0
IO window: disabled.
MEM window: fc700000-fe7fffff
PREFETCH window: bff00000-dfefffff
PCI: Bridge: 0000:00:1e.0
IO window: d000-dfff
MEM window: fe800000-feafffff
PREFETCH window: disabled.
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
TCP established hash table entries: 65536 (order: 9, 2621440 bytes)
TCP bind hash table entries: 32768 (order: 8, 1179648 bytes)
TCP: Hash tables configured (established 65536 bind 32768)
TCP reno registered
apm: BIOS not found.
audit: initializing netlink socket (disabled)
audit(1162723638.770:1): initialized
highmem bounce pool size: 64 pages
Total HugeTLB memory allocated, 0
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
io scheduler deadline registered
io scheduler cfq registered (default)
vesafb: framebuffer at 0xc0000000, mapped to 0xf8880000, using 5120k,
total 262144k
vesafb: mode is 1280x1024x16, linelength=2560, pages=1
vesafb: protected mode interface info at c000:e780
vesafb: pmi: set display start = c00ce7b6, set palette = c00ce820
vesafb: pmi: ports = 3b4 3b5 3ba 3c0 3c1 3c4 3c5 3c6 3c7 3c8 3c9 3cc 3ce
3cf 3d0 3d1 3d2 3d3 3d4 3d5 3da
vesafb: scrolling: redraw
vesafb: Truecolor: size=0:5:6:5, shift=0:11:5:0
Console: switching to colour frame buffer device 160x64
fb0: VESA VGA frame buffer device
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found
Real Time Clock Driver v1.12ac
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:07: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Floppy drive(s): fd0 is 1.44M
FDC 0 is a post-1991 82077
RAMDISK driver initialized: 16 RAM disks of 64000K size 1024 blocksize
PNP: PS/2 Controller [PNP0303:PS2K,PNP0f03:PS2M] at 0x60,0x64 irq 1,12
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
mice: PS/2 mouse device common for all mice
input: PC Speaker as /class/input/input0
input: AT Translated Set 2 keyboard as /class/input/input1
md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: bitmap version 4.39
NET: Registered protocol family 1
Starting balanced_irq
Using IPI No-Shortcut mode
ACPI: (supports<6>Time: tsc clocksource has been installed.
S0 S1 S3 S4 S5)
Freeing unused kernel memory: 224k freed
Write protecting the kernel read-only data: 324k
Trying manual resume from /dev/hda3
Starting udevd
Creating devices
logips2pp: Detected unknown logitech mouse model 0
input: ImPS/2 Logitech Wheel Mouse as /class/input/input2
Loading ide-core
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
Loading ide-disk
Loading piix
ICH5: IDE controller at PCI slot 0000:00:1f.1
PCI: Enabling device 0000:00:1f.1 (0005 -> 0007)
ACPI: PCI Interrupt 0000:00:1f.1[A] -> GSI 18 (level, low) -> IRQ 16
ICH5: chipset revision 2
ICH5: not 100% native mode: will probe irqs later
ide0: BM-DMA at 0xfc00-0xfc07, BIOS settings: hda:DMA, hdb:DMA
ide1: BM-DMA at 0xfc08-0xfc0f, BIOS settings: hdc:DMA, hdd:pio
hda: Maxtor 6L250R0, ATA DISK drive
hdb: Maxtor 6L250R0, ATA DISK drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
hda: max request size: 512KiB
hda: 490234752 sectors (251000 MB) w/16384KiB Cache, CHS=30515/255/63,
UDMA(100)
hda: cache flushes supported
hda: hda1 hda2 hda3 hda4 < hda5 hda6 hda7 hda8 hda9 >
hdb: max request size: 512KiB
hdb: 490234752 sectors (251000 MB) w/16384KiB Cache, CHS=30515/255/63,
UDMA(100)
hdb: cache flushes supported
hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 hdb7 hdb8 hdb9 >
hdc: ASUS DRW-1608P2S, ATAPI CD/DVD-ROM drive
hdd: TOSHIBA CD/DVDW SDR5372V, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
Loading processor
Loading thermal
Loading fan
Loading reiserfs
Loading jbd
Loading ext3
Attempting manual resume
Waiting for device /dev/hda1 to appear: ok
rootfs: major=3 minor=1 devn=769
fsck 1.38 (30-Jun-2005)
[/bin/fsck.ext3 (1) -- /] fsck.ext3 -a /dev/hda1
/dev/hda1: clean, 109695/1954560 files, 948946/3907803 blocks
fsck succeeded. Mounting root device read-write.kjournald starting.
Commit interval 5 seconds
EXT3 FS on hda1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.

Mounting root /dev/hda1
INIT: version 2.86 booting
System Boot Control: Running /etc/init.d/boot
Mounting procfs at /procdone
Mounting sysfs at /sysdone
Mounting debugfs at /sys/kernel/debugdone
Initializing /devdone
Mounting devpts at /dev/ptsdone
Configuring serial ports...
/dev/ttyS0 at 0x03f8 (irq = 4) is a 16550A
Configured serial ports
doneshowconsole: Warning: the ioctl TIOCGDEV is not known by the kernel
done
Starting udevd ACPI: PCI Interrupt 0000:02:03.0[A] -> GSI 20 (level,
low) -> IRQ 17
ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[17]
MMIO=[feaff800-feafffff] Max Packet=[2048] IR/IT contexts=[4/8]
Linux agpgart interface v0.101 (c) Dave Jones
hdc: ATAPI 40X DVD-ROM DVD-R-RAM CD-R/RW drive, 2000kB Cache, UDMA(66)
Uniform CD-ROM driver Revision: 3.20
agpgart: Detected an Intel 865 Chipset.
hdd: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33)
agpgart: AGP aperture is 256M @ 0xe0000000
ACPI: PCI Interrupt 0000:00:1f.3[B] -> GSI 17 (level, low) -> IRQ 18
usbcore: registered new driver usbfs
usbcore: registered new driver hub
USB Universal Host Controller Interface driver v3.0
ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level, low) -> IRQ 19
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:1d.0: irq 19, io base 0x0000ef00
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 19 (level, low) -> IRQ 20
uhci_hcd 0000:00:1d.1: UHCI Host Controller
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1d.1: irq 20, io base 0x0000ef20
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
usb 1-2: new full speed USB device using uhci_hcd and address 2
ACPI: PCI Interrupt 0000:00:1d.2[C] -> GSI 18 (level, low) -> IRQ 16
uhci_hcd 0000:00:1d.2: UHCI Host Controller
uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.2: irq 16, io base 0x0000ef40
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
usb 1-2: configuration #1 chosen from 1 choice
ACPI: PCI Interrupt 0000:02:05.0[A] -> GSI 22 (level, low) -> IRQ 21
i8xx TCO timer: initialized (0x0860). heartbeat=30 sec (nowayout=0)
eth0: 3Com Gigabit LOM (3C940)
PrefPort:A RlmtMode:Check Link State
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
ACPI: PCI Interrupt 0000:02:0d.0[A] -> GSI 21 (level, low) -> IRQ 22
ALSA sound/pci/cs46xx/cs46xx_lib.c:3825: Crystal EAPD support forced on.
ACPI: PCI Interrupt 0000:00:1d.7[D] -> GSI 23 (level, low) -> IRQ 23
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 4
usb 2-1: new low speed USB device using uhci_hcd and address 2
ehci_hcd 0000:00:1d.7: debug port 1
ehci_hcd 0000:00:1d.7: irq 23, io mem 0xfebff800
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 6 ports detected
usb 1-2: USB disconnect, address 2
usb 4-2: new high speed USB device using ehci_hcd and address 2
usb 4-2: configuration #1 chosen from 1 choice
usb 2-1: new low speed USB device using uhci_hcd and address 3
usb 2-1: configuration #1 chosen from 1 choice
input: Wacom Graphire2 4x5 as /class/input/input3
usbcore: registered new driver wacom
drivers/usb/input/wacom.c: v1.45:USB Wacom Graphire and Wacom Intuos
tablet driver
gameport: CS46xx Gameport is pci0000:02:0d.0/gameport0, speed 1420kHz
ACPI: PCI Interrupt 0000:00:1f.5[B] -> GSI 17 (level, low) -> IRQ 18
usbcore: registered new driver hiddev
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.6:USB HID core driver
udevd-event[2030]: run_program: exec of program '/usr/sbin/alsactl' failed
intel8x0_measure_ac97_clock: measured 51247 usecs
intel8x0: clocking to 48000
ACPI: PCI Interrupt 0000:02:0a.0[A] -> GSI 22 (level, low) -> IRQ 21
shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
udevd-event[2117]: run_program: exec of program '/usr/sbin/alsactl' failed
Intel 82802 RNG detected
udevd-event[2144]: run_program: exec of program '/usr/sbin/alsactl' failed
done
Activating device mapper...
Loading required kernel modules
donedevice-mapper: ioctl: 4.7.0-ioctl (2006-06-24) initialised:
[email protected]
done
Starting MD Raid done
showconsole: Warning: the ioctl TIOCGDEV is not known by the kernel
Checking file systems...
fsck 1.38 (30-Jun-2005)
Checking all file systems.
[/sbin/fsck.ext3 (1) -- /usr] fsck.ext3 -a /dev/hda5
/dev/hda5: clean, 326314/3908128 files, 1705254/7813606 blocks
[/sbin/fsck.ext3 (1) -- /home] fsck.ext3 -a /dev/hda7
/dev/hda7 has been mounted 24 times without being checked, check forced.
/dev/hda7: 26544/7815168 files (3.3% non-contiguous), 3774544/15627220
blocks
donedone
Mounting local file systems...
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
debugfs on /sys/kernel/debug type debugfs (rw)
udev on /dev type tmpfs (rw)
loop: loaded (max 8 devices)
devpts on /dev/pts type devpts (rw,mode=0620,gid=5)
kjournald starting. Commit interval 5 seconds
/dev/hda5 on /usEXT3 FS on hda5, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
r type ext3 (rw,noatime,noacl)
kjournald starting. Commit interval 5 seconds
/dev/hda7 on /hoEXT3 FS on hda7, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
me type ext3 (rw,noatime,noacl)
doneSetting up the hardware clockdone
Retry device configurationdone
Setting up hostname 'gamma-suse1'done
Setting up loopback interface lo
lo IP address: 127.0.0.1/8
done
Creating /var/log/boot.msg
doneshowconsole: Warning: the ioctl TIOCGDEV is not known by the kernel
Adding 1959920k swap on /dev/hda3. Priority:-1 extents:1 across:1959920k
Adding 1959920k swap on /dev/hdb3. Priority:-2 extents:1 across:1959920k
Activating remaining swap-devices in /etc/fstab...
doneSetting current sysctl status from /etc/sysctl.conf
net.ipv4.icmp_echo_ignore_broadcasts = 1
net.ipv4.conf.all.rp_filter = 1
done
Enabling syn flood protectiondone
Disabling IP forwardingdone
done
done
System Boot Control: The system has been set up
System Boot Control: Running /etc/init.d/boot.local
net.core.netdev_max_backlog = 5
doneINIT: Entering runlevel: 5
blogd: Warning: the ioctl TIOCGDEV is not known by the kernel
Boot logging started on /dev/ttyS0(/dev/console) at Sun Nov 5 10:48:50 2006
Master Resource Control: previous runlevel: N, switching to runlevel: 5
Starting D-BUS daemondone
acpid: loading ACPI modules ( Starting resource managerdone
Initializing random number generatordone
ac Starting syslog servicesdone
IA-32 Microcode Update Driver: v1.14a <[email protected]>
microcode: CPU1 updated from revision 0x11 to 0x2e, date = 08112004
microcode: CPU0 updated from revision 0x11 to 0x2e, date = 08112004
Checking/updating CPU microcode done
ACPI: Power Button (FF) [PWRF]
ACPI: Power Button (CM) [PWRB]
w83627hf 9191-0290: Reading VID from GPIO5
Starting up sensors: done
battery button ) done
Starting acpid done
BIOS EDD facility v0.16 2004-Jun-25, 2 devices found
Starting HAL daemondone
Setting up network interfaces:
Loading keymap i386/qwerty/pt-latin1.map.gz
doneLoading compose table winkeys shiftctrl latin1.adddone
Start Unicode mode
doneLoading console font lat9w-16.psfu -m trivial G0:loadable
doneRequested buffer size 2048, fragment size 1024
ALSA pcm 'default' set buffer size 7524, period size 3760 bytes
TiMidity starting in ALSA server mode
Opening sequencer port: 128:0 128:1 128:2 128:3
lo
lo IP address: 127.0.0.1/8
done eth0 device: 3Com Corporation 3c940 10/100/1000Base-T
[Marvell] (rev 12)
eth0 configuration: eth-id-00:0c:6e:b3:48:ab
eth0 IP address: 192.168.1.5/24
doneSetting up service network . . . . . . . . . . . . . .
. .done
Starting SSH daemondone
Starting CRON daemondone
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
drivers/usb/input/wacom.c: wacom_graphire_irq - usb_submit_urb failed
with result -1
ADDRCONF(NETDEV_UP): eth0: link is not ready
IPv6 over IPv4 tunneling driver
rtirq: start [rtc] irq=8 pid=364 prio=90: OK.
rtirq: start [snd] irq=18 pid=1993 prio=80: OK.
rtirq: start [snd] irq=22 pid=1831 prio=79: OK.
rtirq: start [snd] irq=21 pid=1766 prio=78: OK.
rtirq: start [uhci_hcd] irq=16 pid=1708 prio=70: OK.
rtirq: start [uhci_hcd] irq=19 pid=1619 prio=69: OK.
rtirq: start [uhci_hcd] irq=20 pid=1655 prio=68: OK.
rtirq: start [ehci_hcd] irq=23 pid=1832 prio=70: OK.
rtirq: start [i8042] irq=1 pid=411 prio=60: OK.
rtirq: start [i8042] irq=12 pid=401 prio=59: OK.
eth0: network connection up using port A
speed: 100
autonegotiation: yes
duplex mode: full
flowctrl: symmetric
irq moderation: disabled
scatter-gather: disabled
tx-checksum: disabled
rx-checksum: disabled
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Starting service kdmdone
Starting service kdmdone
Master Resource Control: runlevel 5 has been reached
Skipped services in runlevel 5: splash
Oops: 0002 [#1]
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8d2f>] __schedule+0x63f/0xea0
[<c02f9700>] schedule+0x30/0x100
[<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
[<c02fadb2>] rt_spin_lock+0x22/0x30
[<c02fd8b1>] kprobe_flush_task+0x11/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c011760f>] start_secondary+0x43f/0x500
BUG: scheduling from the idle thread!
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c02f8dba>] __schedule+0x6ca/0xea0
[<c02f9700>] schedule+0x30/0x100
PREEMPT SMP
Modules linked in: appletalk ax25 ipx p8023 ipv6 snd_seq_dummy
snd_pcm_oss edd snd_mixer_oss snd_seq_midi snd_seq_midi_event snd_seq
w83627hf hwmon_vid button hwmon battery i2c_isa ac loop dm_mod intel_rng
usbhid wacom shpchp snd_ice1712 snd_ice17xx_ak4xxx snd_ak4xxx_adda
snd_cs8427 pci_hotplug snd_intel8x0 snd_i2c i8xx_tco snd_cs46xx
snd_mpu401_uart gameport snd_rawmidi snd_ac97_codec snd_ac97_bus sk98lin
snd_seq_device snd_pcm snd_timer snd ehci_hcd snd_page_alloc uhci_hcd
soundcore usbcore i2c_i801 i2c_core intel_agp ide_cd agpgart cdrom
ohci1394 ieee1394 ext3 jbd reiserfs fan thermal processor piix ide_disk
ide_core
CPU: 0
EIP: 0060:[<c011f4cb>] Not tainted VLI
EFLAGS: 00010046 (2.6.18-rt7.0-smp #1)
EIP is at enqueue_task+0x2b/0x90
eax: c188f28c ebx: c188ee10 ecx: 00000000 edx: dfd490d8
esi: dfd490b0 edi: c188edc0 ebp: c042be34 esp: c042be2c
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process swapper (pid: 0, ti=c042a000 task=c0352840 task.ti=c042a000)
Stack: c188edc0 dfd490b0 c042be44 c011f551 00000001 dfd490b0 c042bea8
c01218c1
00000401 00000100 00000000 00000000 0000001f c042a000 00000001
00000000
00000004 c180edc0 dfd485b0 c042be88 c011f551 00000001 a1fdbacf
c042bea4
Call Trace:
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
Code: 55 89 e5 56 89 c6 53 89 d3 f6 40 0c 08 74 09 a1 60 60 35 c0 85 c0
75 4b 8b 46 1c 8d 56 28 8d 44 c3 1c 8b 48 04 89 46 28 89 50 04 <89> 11
89 4a 04 8b 46 1c 83 43 04 01 0f ab 43 08 83 7e 1c 63 89
EIP: [<c011f4cb>] enqueue_task+0x2b/0x90 SS:ESP 0068:c042be2c
<0>Kernel panic - not syncing: Attempted to kill the idle task!
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c0128081>] panic+0x51/0x110
[<c012bcd6>] do_exit+0x6e6/0xaa0
[<c0106a88>] die+0x2f8/0x300
[<c02fc9a1>] do_page_fault+0x1f1/0x5e0
[<c0105e45>] error_code+0x39/0x40
[<c011f4cb>] enqueue_task+0x2b/0x90
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
swapper/0[CPU#0]: BUG in smp_call_function at arch/i386/kernel/smp.c:557
[<c0106455>] show_trace_log_lvl+0x185/0x1a0
[<c0106ae2>] show_trace+0x12/0x20
[<c0106c49>] dump_stack+0x19/0x20
[<c01292e3>] __WARN_ON+0x63/0x80
[<c0115fbc>] smp_call_function+0xbc/0xd0
[<c0115fee>] smp_send_stop+0x1e/0x30
[<c0128094>] panic+0x64/0x110
[<c012bcd6>] do_exit+0x6e6/0xaa0
[<c0106a88>] die+0x2f8/0x300
[<c02fc9a1>] do_page_fault+0x1f1/0x5e0
[<c0105e45>] error_code+0x39/0x40
[<c011f4cb>] enqueue_task+0x2b/0x90
[<c011f551>] __activate_task+0x21/0x40
[<c01218c1>] try_to_wake_up+0x321/0x450
[<c0121a69>] wake_up_process_mutex+0x19/0x20
[<c0144ab7>] wakeup_next_waiter+0xd7/0x1b0
[<c02fa46c>] rt_spin_lock_slowunlock+0x4c/0x70
[<c02fad88>] rt_spin_unlock+0x38/0x40
[<c02fd8da>] kprobe_flush_task+0x3a/0x50
[<c02f91fa>] __schedule+0xb0a/0xea0
[<c0103b61>] cpu_idle+0xb1/0x120
[<c01006d3>] rest_init+0x43/0x50
[<c042f890>] start_kernel+0x360/0x440
--

Cheers.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-05 20:18:48

by Daniel Walker

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops


Try turning this option in Kernel Hacking
"RT Mutex debugging, deadlock detection"

I'm assuming it's off.

On Sun, 2006-11-05 at 18:38 +0000, Rui Nuno Capela wrote:
> Daniel Walker wrote:
> > On Sun, 2006-11-05 at 16:47 +0000, Rui Nuno Capela wrote:
> >> Rui Nuno Capela wrote:
> >>> After a suggestion from Mike Galbraith, I now turned to pure and
> >>> original 2.6.18-rt7 and configured with:
> >>>
> >>> CONFIG_FRAME_POINTER=y
> >>> CONFIG_UNWIND_INFO=y
> >>> CONFIG_STACK_UNWIND=y
> >>>
> >>> Nasty things still do happen, as the following capture can tell as evidence:
> >>>
> >> Some more evidence, just happening:
> >>
> >> ...
> >> Oops: 0002 [#1]
> >> [<c0106455>] show_trace_log_lvl+0x185/0x1a0
> >> [<c0106ae2>] show_trace+0x12/0x20
> >> [<c0106c49>] dump_stack+0x19/0x20
> >> [<c02f8d2f>] __schedule+0x63f/0xea0
> >> [<c02f9700>] schedule+0x30/0x100
> >> [<c02fa5db>] rt_spin_lock_slowlock+0x9b/0x1b0
> >> [<c02fadb2>] rt_spin_lock+0x22/0x30
> >> [<c02fd8b1>] kprobe_flush_task+0x11/0x50
> >> [<c02f91fa>] __schedule+0xb0a/0xea0
> >> [<c0103b61>] cpu_idle+0xb1/0x120
> >> [<c011760f>] start_secondary+0x43f/0x500
> >
> > Is there more above this log? It looks like your cutting off some stuff
> > above this.
> >
> > Daniel
>
> Yes there is. However I didn't find it relevant. Here it goes now (full
> captured serial-console log):
>
> --

2006-11-06 07:24:50

by Mike Galbraith

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

I just reproduced it running glibc make check. I had just enabled
kprobes and recompiled with the stock SuSE-10.1 compiler while waiting
for you to send me your .config (nevermind that request) so I could try
to reproduce it here.

BUG: scheduling while atomic: swapper/0x00000001/0, CPU#0
BUG: unable to handle kernel NULL pointer dereference at virtual address 00000000
b101995a
*pde = 00000000
Oops: 0002 [#1]
Modules linked in: xt_pkttype ipt_LOG xt_limit snd_pcm_oss snd_mixer_oss eeprom snd_seq_midi snd_seq_midi_event snd_seq edd ip6t_REJECT xt_tcpudp ipt_REJECT xt_state iptable_mangle iptable_nat ip_nat iptable_filter ip6table_mangle ip_conntrack nfnetlink ip_tables ip6table_filter ip6_tables x_tables nls_iso8859_1 nls_cp437 nls_utf8 tuner saa7134 sd_mod bt878 snd_intel8x0 snd_ac97_codec snd_ac97_bus snd_pcm ir_kbd_i2c ohci1394 bttv video_buf ir_common i2c_i801 ieee1394 prism54 btcx_risc tveeprom snd_timer snd_page_alloc firmware_class snd_mpu401 snd_mpu401_uart snd_rawmidi snd_seq_device snd soundcore
CPU: 1
EIP: 0060:[<b101995a>] Not tainted VLI
EFLAGS: 00210046 (2.6.18-rt7-smp #186)
EIP is at enqueue_task+0x2e/0x83
eax: b2459208 ebx: b2458d8c ecx: 00000000 edx: b146bf68
esi: b146bf40 edi: b24588c0 ebp: b9e06d5c esp: b9e06d54
ds: 007b es: 007b ss: 0068 preempt: 00000004
Process ld-linux.so.2 (pid: 16981, ti=b9e06000 task=eec9d300 task.ti=b9e06000)
Stack: b24588c0 b146bf40 b9e06d6c b10199c8 00000001 b146bf40 b9e06dd0 b101bae4
b24d9300 b9e06dac 00000002 00000000 0000001f b9e06000 00000000 00000001
00000004 b1022cfb 00000068 00200002 b9e06de4 00000001 00000008 b9e06dc0
[<b10199c8>] __activate_task+0x19/0x2c
[<b101bae4>] try_to_wake_up+0x32a/0x447
[<b101bc6b>] wake_up_process_mutex+0x19/0x1b
[<b103cc33>] wakeup_next_waiter+0xd3/0x158
[<b13afb87>] rt_spin_lock_slowunlock+0x36/0x51
[<b13b0403>] rt_spin_unlock+0x29/0x2b
[<b13b2a72>] kprobe_flush_task+0x38/0x48
[<b13aeb0e>] __schedule+0xb77/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b13afe61>] rt_mutex_slowlock+0xbd/0x27d
[<b13afc28>] rt_mutex_lock+0x38/0x3a
[<b103d605>] rt_down_read+0x2e/0x41
[<b10235c5>] exit_mm+0x2a/0x11c
[<b1024bf4>] do_exit+0x11d/0x96e
[<b10254da>] complete_and_exit+0x0/0x16
[<b9e06000>] 0xb9e06000
DWARF2 unwinder stuck at 0xb9e06000
[<b10042b7>] show_stack_log_lvl+0xa6/0xcb
[<b1004493>] show_registers+0x1b7/0x23c
[<b100464f>] die+0x137/0x2a8
[<b13b1c4d>] do_page_fault+0x1ed/0x590
[<b1003c51>] error_code+0x39/0x40
[<b10199c8>] __activate_task+0x19/0x2c
[<b101bae4>] try_to_wake_up+0x32a/0x447
[<b101bc6b>] wake_up_process_mutex+0x19/0x1b
[<b103cc33>] wakeup_next_waiter+0xd3/0x158
[<b13afb87>] rt_spin_lock_slowunlock+0x36/0x51
[<b13b0403>] rt_spin_unlock+0x29/0x2b
[<b13b2a72>] kprobe_flush_task+0x38/0x48
[<b13aeb0e>] __schedule+0xb77/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b13afe61>] rt_mutex_slowlock+0xbd/0x27d
[<b13afc28>] rt_mutex_lock+0x38/0x3a
[<b103d605>] rt_down_read+0x2e/0x41
[<b10235c5>] exit_mm+0x2a/0x11c
[<b1024bf4>] do_exit+0x11d/0x96e
[<b10254da>] complete_and_exit+0x0/0x16
[<b100317f>] syscall_call+0x7/0xb
Code: 56 53 89 c6 89 d3 f6 40 0c 08 74 09 a1 20 f4 46 b1 85 c0 75 4b 8b 46 1c 8d 44 c3 1c 8b 48 04 8d 56 28 89 50 04 89 46 28 89 4a 04 <89> 11 8b 46 1c 0f ab 43 08 83 43 04 01 89 5e 30 8b 13 83 7e 1c
EIP: [<b101995a>] enqueue_task+0x2e/0x83 SS:ESP 0068:b9e06d54
BUG: scheduling with irqs disabled: ld-linux.so.2/0x00000003/16981
caller is do_exit+0x843/0x96e
[<b10041fb>] show_trace_log_lvl+0x179/0x18f
[<b1004803>] show_trace+0x12/0x14
[<b1004924>] dump_stack+0x19/0x1b
[<b13af03a>] schedule+0xf4/0xf9
[<b102531a>] do_exit+0x843/0x96e
[<b10047c0>] show_stack+0x0/0x31
[<b13f038f>] 0xb13f038f
DWARF2 unwinder stuck at 0xb13f038f
[<b1004803>] show_trace+0x12/0x14
[<b1004924>] dump_stack+0x19/0x1b
[<b13af03a>] schedule+0xf4/0xf9
[<b102531a>] do_exit+0x843/0x96e
[<b10047c0>] show_stack+0x0/0x31
[<b13b1c4d>] do_page_fault+0x1ed/0x590
[<b1003c51>] error_code+0x39/0x40
[<b10199c8>] __activate_task+0x19/0x2c
[<b101bae4>] try_to_wake_up+0x32a/0x447
[<b101bc6b>] wake_up_process_mutex+0x19/0x1b
[<b103cc33>] wakeup_next_waiter+0xd3/0x158
[<b13afb87>] rt_spin_lock_slowunlock+0x36/0x51
[<b13b0403>] rt_spin_unlock+0x29/0x2b
[<b13b2a72>] kprobe_flush_task+0x38/0x48
[<b13aeb0e>] __schedule+0xb77/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b13afe61>] rt_mutex_slowlock+0xbd/0x27d
[<b13afc28>] rt_mutex_lock+0x38/0x3a
[<b103d605>] rt_down_read+0x2e/0x41
[<b10235c5>] exit_mm+0x2a/0x11c
[<b1024bf4>] do_exit+0x11d/0x96e
[<b10254da>] complete_and_exit+0x0/0x16
[<b100317f>] syscall_call+0x7/0xb
BUG: scheduling while atomic: ld-linux.so.2/0x00000003/16981, CPU#1
[<b10041fb>] show_trace_log_lvl+0x179/0x18f
[<b1004803>] show_trace+0x12/0x14
[<b1004924>] dump_stack+0x19/0x1b
[<b13ae5d2>] __schedule+0x63b/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b102531a>] do_exit+0x843/0x96e
[<b10047c0>] show_stack+0x0/0x31
[<b13f038f>] 0xb13f038f
DWARF2 unwinder stuck at 0xb13f038f
[<b1004803>] show_trace+0x12/0x14
[<b1004924>] dump_stack+0x19/0x1b
[<b13ae5d2>] __schedule+0x63b/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b102531a>] do_exit+0x843/0x96e
[<b10047c0>] show_stack+0x0/0x31
[<b13b1c4d>] do_page_fault+0x1ed/0x590
[<b1003c51>] error_code+0x39/0x40
[<b10199c8>] __activate_task+0x19/0x2c
[<b101bae4>] try_to_wake_up+0x32a/0x447
[<b101bc6b>] wake_up_process_mutex+0x19/0x1b
[<b103cc33>] wakeup_next_waiter+0xd3/0x158
[<b13afb87>] rt_spin_lock_slowunlock+0x36/0x51
[<b13b0403>] rt_spin_unlock+0x29/0x2b
[<b13b2a72>] kprobe_flush_task+0x38/0x48
[<b13aeb0e>] __schedule+0xb77/0xea5
[<b13aef76>] schedule+0x30/0xf9
[<b13afe61>] rt_mutex_slowlock+0xbd/0x27d
[<b13afc28>] rt_mutex_lock+0x38/0x3a
[<b103d605>] rt_down_read+0x2e/0x41
[<b10235c5>] exit_mm+0x2a/0x11c
[<b1024bf4>] do_exit+0x11d/0x96e
[<b10254da>] complete_and_exit+0x0/0x16
[<b100317f>] syscall_call+0x7/0xb


2006-11-06 09:38:39

by Ingo Molnar

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops


* Mike Galbraith <[email protected]> wrote:

> I just reproduced it running glibc make check. I had just enabled
> kprobes and recompiled with the stock SuSE-10.1 compiler while waiting
> for you to send me your .config (nevermind that request) so I could
> try to reproduce it here.

hm, so kprobe_flush_task() is likely PREEMPT_RT-unsafe.

could you try the patch below, does it help? (a quick review seems to
suggest that all codepaths protected by kretprobe_lock are atomic)

Ingo

Index: linux/kernel/kprobes.c
===================================================================
--- linux.orig/kernel/kprobes.c
+++ linux/kernel/kprobes.c
@@ -50,7 +50,7 @@ static struct hlist_head kretprobe_inst_
static atomic_t kprobe_count;

DEFINE_MUTEX(kprobe_mutex); /* Protects kprobe_table */
-DEFINE_SPINLOCK(kretprobe_lock); /* Protects kretprobe_inst_table */
+DEFINE_RAW_SPINLOCK(kretprobe_lock); /* Protects kretprobe_inst_table */
static DEFINE_PER_CPU(struct kprobe *, kprobe_instance) = NULL;

static struct notifier_block kprobe_page_fault_nb = {

2006-11-06 10:02:40

by Mike Galbraith

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

On Mon, 2006-11-06 at 10:38 +0100, Ingo Molnar wrote:
> * Mike Galbraith <[email protected]> wrote:
>
> > I just reproduced it running glibc make check. I had just enabled
> > kprobes and recompiled with the stock SuSE-10.1 compiler while waiting
> > for you to send me your .config (nevermind that request) so I could
> > try to reproduce it here.
>
> hm, so kprobe_flush_task() is likely PREEMPT_RT-unsafe.
>
> could you try the patch below, does it help? (a quick review seems to
> suggest that all codepaths protected by kretprobe_lock are atomic)

Ah, so I did do the right thing. Besides the oops, I was getting a
pretty frequent non-deadly...

BUG: scheduling while atomic: ld-linux.so.2/0x00000001/11803, CPU#1
[<b10041fb>] show_trace_log_lvl+0x179/0x18f
[<b1004803>] show_trace+0x12/0x14
[<b1004924>] dump_stack+0x19/0x1b
[<b13aaf02>] __schedule+0x63b/0xea5
[<b13ab8a6>] schedule+0x30/0xf9
[<b13ac53a>] rt_spin_lock_slowlock+0x90/0x17a
[<b13acc67>] rt_spin_lock+0x22/0x24
[<b13af28b>] kprobe_flush_task+0x11/0x48
[<b13ab43e>] __schedule+0xb77/0xea5
[<b13ab8a6>] schedule+0x30/0xf9
[<b13ac53a>] rt_spin_lock_slowlock+0x90/0x17a
[<b13acccb>] __rt_spin_lock+0x22/0x28
[<b13acd64>] rt_write_lock+0x8/0xa
[<b1024cc5>] do_exit+0x2ae/0x96e
[<b102541a>] complete_and_exit+0x0/0x16
[<c90ad000>] 0xc90ad000

...so turned it back into a non-sleeping lock.

You forgot kprobes.h

>
> Ingo
>
> Index: linux/kernel/kprobes.c
> ===================================================================
> --- linux.orig/kernel/kprobes.c
> +++ linux/kernel/kprobes.c
> @@ -50,7 +50,7 @@ static struct hlist_head kretprobe_inst_
> static atomic_t kprobe_count;
>
> DEFINE_MUTEX(kprobe_mutex); /* Protects kprobe_table */
> -DEFINE_SPINLOCK(kretprobe_lock); /* Protects kretprobe_inst_table */
> +DEFINE_RAW_SPINLOCK(kretprobe_lock); /* Protects kretprobe_inst_table */
> static DEFINE_PER_CPU(struct kprobe *, kprobe_instance) = NULL;
>
> static struct notifier_block kprobe_page_fault_nb = {
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
>

2006-11-06 10:12:20

by Ingo Molnar

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops


* Mike Galbraith <[email protected]> wrote:

> > could you try the patch below, does it help? (a quick review seems
> > to suggest that all codepaths protected by kretprobe_lock are
> > atomic)
>
> Ah, so I did do the right thing. Besides the oops, I was getting a
> pretty frequent non-deadly...

yeah ...

> ...so turned it back into a non-sleeping lock.
>
> You forgot kprobes.h

so the patch solves this problem for you?

Ingo

2006-11-06 10:26:24

by Mike Galbraith

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops

On Mon, 2006-11-06 at 11:11 +0100, Ingo Molnar wrote:
> * Mike Galbraith <[email protected]> wrote:
>
> > > could you try the patch below, does it help? (a quick review seems
> > > to suggest that all codepaths protected by kretprobe_lock are
> > > atomic)
> >
> > Ah, so I did do the right thing. Besides the oops, I was getting a
> > pretty frequent non-deadly...
>
> yeah ...
>
> > ...so turned it back into a non-sleeping lock.
> >
> > You forgot kprobes.h
>
> so the patch solves this problem for you?

Yeah, seems to. I'll let it run make check in a loop for a while to
make sure the fatal oops stays gone too though. If you don't hear from
me, all is peachy (it will be methinks)

-Mike

2006-11-10 09:32:07

by Rui Nuno Capela

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops


On Mon, November 6, 2006 10:26, Mike Galbraith wrote:
> On Mon, 2006-11-06 at 11:11 +0100, Ingo Molnar wrote:
>
>> * Mike Galbraith <[email protected]> wrote:
>>
>>
>>>> could you try the patch below, does it help? (a quick review seems
>>>> to suggest that all codepaths protected by kretprobe_lock are
>>>> atomic)
>>>
>>> Ah, so I did do the right thing. Besides the oops, I was getting a
>>> pretty frequent non-deadly...
>>
>> yeah ...
>>
>>> ...so turned it back into a non-sleeping lock.
>>>
>>>
>>> You forgot kprobes.h
>>>
>>
>> so the patch solves this problem for you?
>
> Yeah, seems to. I'll let it run make check in a loop for a while to
> make sure the fatal oops stays gone too though. If you don't hear from
> me, all is peachy (it will be methinks)
>

So far so good for this pester ;)

Thanks.
--
rncbc aka Rui Nuno Capela
[email protected]

2006-11-10 09:33:59

by Ingo Molnar

[permalink] [raw]
Subject: Re: realtime-preempt patch-2.6.18-rt7 oops


* Rui Nuno Capela <[email protected]> wrote:

> >> so the patch solves this problem for you?
> >
> > Yeah, seems to. I'll let it run make check in a loop for a while to
> > make sure the fatal oops stays gone too though. If you don't hear
> > from me, all is peachy (it will be methinks)
>
> So far so good for this pester ;)

great - i've applied it and it should show up in the next code-drop.

Ingo