Messages in this thread | | | Date | Tue, 30 Sep 2008 11:13:05 +0200 | From | Ingo Molnar <> | Subject | Re: [PATCH 0/6] ftrace: port to the new ring_buffer |
| |
ok, -tip testing found a serious-looking locking bug:
[ 4.044005] calling init_irqsoff_tracer+0x0/0x11 @ 1 [ 4.048005] Testing tracer irqsoff: [ 4.056202] ============================================= [ 4.060000] [ INFO: possible recursive locking detected ] [ 4.060000] 2.6.27-rc8-tip-00917-g01214de-dirty #37512 [ 4.060000] --------------------------------------------- [ 4.060000] swapper/1 is trying to acquire lock: [ 4.060000] (&cpu_buffer->lock){++..}, at: [<c015a216>] ring_buffer_lock+0x3b/0x50 [ 4.060000] [ 4.060000] but task is already holding lock: [ 4.060000] (&cpu_buffer->lock){++..}, at: [<c015a216>] ring_buffer_lock+0x3b/0x50 [ 4.060000] [ 4.060000] other info that might help us debug this: [ 4.060000] 3 locks held by swapper/1: [ 4.060000] #0: (trace_types_lock){--..}, at: [<c015d758>] register_tracer+0x2f/0x14f [ 4.060000] #1: (max_trace_lock){....}, at: [<c015eab0>] check_critical_timing+0x5d/0x113 [ 4.060000] #2: (&cpu_buffer->lock){++..}, at: [<c015a216>] ring_buffer_lock+0x3b/0x50 [ 4.060000] [ 4.060000] stack backtrace: [ 4.060000] Pid: 1, comm: swapper Not tainted 2.6.27-rc8-tip-00917-g01214de-dirty #37512 [ 4.060000] [<c014446d>] validate_chain+0x4e9/0xb4c [ 4.060000] [<c0108b54>] ? native_sched_clock+0xe2/0x101 [ 4.060000] [<c014519a>] __lock_acquire+0x6ca/0x730 [ 4.060000] [<c014525b>] lock_acquire+0x5b/0x81 [ 4.060000] [<c015a216>] ? ring_buffer_lock+0x3b/0x50 [ 4.060000] [<c05908cf>] _spin_lock+0x23/0x50 [ 4.060000] [<c015a216>] ? ring_buffer_lock+0x3b/0x50 [ 4.060000] [<c015a216>] ring_buffer_lock+0x3b/0x50 [ 4.060000] [<c015a2b3>] ring_buffer_reset+0x16/0x46 [ 4.060000] [<c015e16f>] update_max_tr_single+0x65/0xc0 [ 4.060000] [<c015eb15>] check_critical_timing+0xc2/0x113 [ 4.060000] [<c015d270>] ? trace_selftest_startup_irqsoff+0x49/0xac [ 4.060000] [<c015d270>] ? trace_selftest_startup_irqsoff+0x49/0xac [ 4.060000] [<c015ec0c>] time_hardirqs_on+0xa6/0xb9 [ 4.060000] [<c014393c>] ? trace_hardirqs_on+0xb/0xd [ 4.060000] [<c01437fb>] trace_hardirqs_on_caller+0x16/0x14c [ 4.060000] [<c014393c>] trace_hardirqs_on+0xb/0xd [ 4.060000] [<c015d270>] trace_selftest_startup_irqsoff+0x49/0xac [ 4.060000] [<c0128ba9>] ? printk+0x1a/0x1c [ 4.060000] [<c015d7f1>] register_tracer+0xc8/0x14f [ 4.060000] [<c08803fc>] init_irqsoff_tracer+0xd/0x11 [ 4.060000] [<c010104f>] do_one_initcall+0x4f/0x130 [ 4.060000] [<c08803ef>] ? init_irqsoff_tracer+0x0/0x11 [ 4.060000] [<c0121390>] ? wake_up_process+0xf/0x11 [ 4.060000] [<c0134ab2>] ? start_workqueue_thread+0x22/0x25 [ 4.060000] [<c0134d99>] ? __create_workqueue_key+0xa9/0x141 [ 4.060000] [<c086c5c3>] kernel_init+0x17b/0x1e2 [ 4.060000] [<c086c448>] ? kernel_init+0x0/0x1e2 [ 4.060000] [<c0104ab3>] kernel_thread_helper+0x7/0x10 [ 4.060000] ======================= [ 4.064053] PASSED [ 4.066133] initcall init_irqsoff_tracer+0x0/0x11 returned 0 after 15 msecs [ 4.068005] calling init_wakeup_tracer+0x0/0xf @ 1
Ingo
| |