Re: linux-next 5/5 does not boot

From: Stephen Rothwell
Date: Tue May 06 2008 - 01:38:29 EST

cc'ing Ingo ...

On Mon, 5 May 2008 20:04:33 -0400 Daniel Hazelton <dhazelton@xxxxxxxxx> wrote:
>
> This may be related to one of the stack dumps I reported earlier as occurring
> when booting the 4/30 linux-next tree...
>
> During two attempted boots of the 5/5 tree using the same config as the 4/30
> tree the system locked solid at "testing tracer ftrace".
>
> The 4/30 tree produced the following dump (the 5/5 tree locks solid as soon as
> the test is started):
> [ 10.238230] Testing tracer ftrace: <4>------------[ cut here ]------------
> [ 10.356558] WARNING: at kernel/lockdep.c:2712 check_flags+0xfb/0x180()
> [ 10.356726] Modules linked in:
> [ 10.356915] Pid: 1, comm: swapper Not tainted 2.6.25-next-20080430 #2
> [ 10.357718]
> [ 10.357722] Call Trace:
> [ 10.357939] <IRQ> [<ffffffff8023d5f4>] warn_on_slowpath+0x64/0x90
> [ 10.358174] [<ffffffff8025f789>] ? tick_get_tick_sched+0x9/0x30
> [ 10.358337] [<ffffffff8022f048>] ? __update_rq_clock+0x68/0x140
> [ 10.358501] [<ffffffff8026173d>] ? trace_hardirqs_off+0xd/0x10
> [ 10.358665] [<ffffffff8026173d>] ? trace_hardirqs_off+0xd/0x10
> [ 10.358827] [<ffffffff802953ce>] ? function_trace_call+0x9e/0xa0
> [ 10.358992] [<ffffffff8020c4b4>] ? ftrace_call+0x5/0x2b
> [ 10.359148] [<ffffffff8023177a>] ? cpu_clock+0xda/0x190
> [ 10.359302] [<ffffffff80262d7b>] check_flags+0xfb/0x180
> [ 10.359457] [<ffffffff80265635>] lock_acquire+0x65/0xd0
> [ 10.359614] [<ffffffff80231799>] cpu_clock+0xf9/0x190
> [ 10.359769] [<ffffffff80293de9>] ftrace_now+0x9/0x10
> [ 10.359920] [<ffffffff80295194>] trace_function+0xc4/0x260
> [ 10.360079] [<ffffffff80243723>] ? _local_bh_enable+0x63/0xc0
> [ 10.360240] [<ffffffff804aeec9>] ? sub_preempt_count+0x9/0x90
> [ 10.360400] [<ffffffff80243723>] ? _local_bh_enable+0x63/0xc0
> [ 10.360561] [<ffffffff804aeec9>] ? sub_preempt_count+0x9/0x90
> [ 10.360721] [<ffffffff8029539c>] function_trace_call+0x6c/0xa0
> [ 10.360883] [<ffffffff8020c4b4>] ftrace_call+0x5/0x2b
> [ 10.361038] [<ffffffff804aeec9>] ? sub_preempt_count+0x9/0x90
> [ 10.361199] [<ffffffff80243723>] _local_bh_enable+0x63/0xc0
> [ 10.361357] [<ffffffff8024399e>] __do_softirq+0xfe/0x150
> [ 10.361514] [<ffffffff8020d93c>] call_softirq+0x1c/0x30
> [ 10.361669] [<ffffffff8020f76a>] do_softirq+0x6a/0xb0
> [ 10.361823] [<ffffffff80244155>] irq_exit+0xa5/0xb0
> [ 10.361975] [<ffffffff802204ee>] smp_apic_timer_interrupt+0x9e/0xf0
> [ 10.362143] [<ffffffff8020d3fb>] apic_timer_interrupt+0x6b/0x70
> [ 10.362301] <EOI> [<ffffffff804ab808>] ?
> _spin_unlock_irqrestore+0x68/0x80
> [ 10.362543] [<ffffffff8023540b>] ? try_to_wake_up+0xab/0x270
> [ 10.362704] [<ffffffff8020c4b4>] ? ftrace_call+0x5/0x2b
> [ 10.362860] [<ffffffff80235625>] ? wake_up_process+0x15/0x20
> [ 10.362979] [<ffffffff80255264>] ? kthread_create+0xa4/0x120
> [ 10.362979] [<ffffffff8027a390>] ? do_stop+0x0/0x190
> [ 10.362979] [<ffffffff80265a6e>] ? mark_held_locks+0x3e/0x80
> [ 10.362979] [<ffffffff80265d4d>] ? trace_hardirqs_on+0xd/0x10
> [ 10.362979] [<ffffffff80265c85>] ? trace_hardirqs_on_caller+0xf5/0x1b0
> [ 10.362979] [<ffffffff80263f2b>] ? lockdep_init_map+0x4b/0x140
> [ 10.362979] [<ffffffff8037d6f8>] ? __spin_lock_init+0x38/0x70
> [ 10.362979] [<ffffffff80255714>] ? init_waitqueue_head+0x24/0x40
> [ 10.362979] [<ffffffff8028ffc0>] ? __ftrace_modify_code+0x0/0xa0
> [ 10.362979] [<ffffffff8027a185>] ? __stop_machine_run+0x85/0xf0
> [ 10.362979] [<ffffffff8028ffc0>] ? __ftrace_modify_code+0x0/0xa0
> [ 10.362979] [<ffffffff8028ffc0>] ? __ftrace_modify_code+0x0/0xa0
> [ 10.362979] [<ffffffff8028ffc0>] ? __ftrace_modify_code+0x0/0xa0
> [ 10.362979] [<ffffffff8027a223>] ? stop_machine_run+0x33/0x60
> [ 10.362979] [<ffffffff8028f3a0>] ? ftrace_run_update_code+0x20/0x30
> [ 10.362979] [<ffffffff8028f7ea>] ? unregister_ftrace_function+0x14a/0x190
> [ 10.362979] [<ffffffff80292e70>] ? tracing_stop_function_trace+0x10/0x20
> [ 10.362979] [<ffffffff80296759>] ? stop_function_trace+0x9/0x20
> [ 10.362979] [<ffffffff80296787>] ? function_trace_ctrl_update+0x17/0x20
> [ 10.362979] [<ffffffff80292d5e>] ?
> trace_selftest_startup_function+0xae/0x140
> [ 10.362979] [<ffffffff8029220d>] ? register_tracer+0x11d/0x1f0
> [ 10.362979] [<ffffffff80665d50>] ? init_function_trace+0x10/0x20
> [ 10.362979] [<ffffffff8064eee4>] ? kernel_init+0x164/0x2f0
> [ 10.362979] [<ffffffff804aeec9>] ? sub_preempt_count+0x9/0x90
> [ 10.362979] [<ffffffff804ab77b>] ? _spin_unlock_irq+0x3b/0x60
> [ 10.362979] [<ffffffff804aab1d>] ? trace_hardirqs_on_thunk+0x3a/0x3f
> [ 10.362979] [<ffffffff80265c85>] ? trace_hardirqs_on_caller+0xf5/0x1b0
> [ 10.362979] [<ffffffff8020d5d8>] ? child_rip+0xa/0x12
> [ 10.362979] [<ffffffff8020cc63>] ? restore_args+0x0/0x30
> [ 10.362979] [<ffffffff8064ed80>] ? kernel_init+0x0/0x2f0
> [ 10.362979] [<ffffffff8020d5ce>] ? child_rip+0x0/0x12
> [ 10.362979]
> [ 10.362979] ---[ end trace 5a5d197966b56a2e ]---
> [ 10.362979] irq event stamp: 3391956
> [ 10.362979] hardirqs last enabled at (3391954): [<ffffffff80265d4d>]
> trace_hardirqs_on+0xd/0x10
> [ 10.362979] hardirqs last disabled at (3391955): [<ffffffff8026173d>]
> trace_hardirqs_off+0xd/0x10
> [ 10.362979] softirqs last enabled at (3391956): [<ffffffff8024399e>]
> __do_softirq+0xfe/0x150
> [ 10.362979] softirqs last disabled at (3391933): [<ffffffff8020d93c>]
> call_softirq+0x1c/0x30
> [ 10.376978] kstopmachine used greatest stack depth: 6000 bytes left
> [ 10.377650] PASSED
>
> config for 5/5 tree will be provided on request. Dmesg from 4/30 tree is also
> available. System had not mounted the root drive before the ftrace crash, so
> I have no available logs or dmesg from the 5/5 tree. If asked, I will attempt
> to setup a netconsole and try to capture the logs there.
>
> DRH

--
Cheers,
Stephen Rothwell sfr@xxxxxxxxxxxxxxxx
http://www.canb.auug.org.au/~sfr/

Attachment: pgp00000.pgp
Description: PGP signature