* tasklist_lock lockdep warnings on 3.6
@ 2012-07-25 6:42 Sasha Levin
2012-07-30 14:50 ` Sasha Levin
0 siblings, 1 reply; 5+ messages in thread
From: Sasha Levin @ 2012-07-25 6:42 UTC (permalink / raw)
To: Ingo Molnar, Peter Zijlstra, Andrew Morton, tglx
Cc: davej, linux-kernel@vger.kernel.org
Hi all,
I've stumbled on the following while fuzzing with trinity inside a KVM tools guest on 3.6 kernel:
[ 250.495512] ======================================================
[ 250.496020] [ INFO: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected ]
[ 250.496020] 3.5.0-sasha-01646-g39c0dda #269 Tainted: G W
[ 250.496020] ------------------------------------------------------
[ 250.496020] trinity-child15/6956 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
[ 250.496020] (tasklist_lock){.+.+..}, at: [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
[ 250.496020]
[ 250.496020] and this task is already holding:
[ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
[ 250.496020] which would create a new lock dependency:
[ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...} -> (tasklist_lock){.+.+..}
[ 250.496020]
[ 250.496020] but this new dependency connects a HARDIRQ-irq-safe lock:
[ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}
... which became HARDIRQ-irq-safe at:
[ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
[ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
[ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
[ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
[ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
[ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
[ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
[ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
[ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
[ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
[ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
[ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
[ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
[ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
[ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
[ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
[ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
[ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.496020]
[ 250.496020] to a HARDIRQ-irq-unsafe lock:
[ 250.496020] (&(&p->alloc_lock)->rlock){+.+...}
... which became HARDIRQ-irq-unsafe at:
[ 250.496020] ... [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
[ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.496020] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
[ 250.496020] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
[ 250.496020] [<ffffffff8110665c>] kthreadd+0x2c/0x170
[ 250.496020] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.496020]
[ 250.496020] other info that might help us debug this:
[ 250.496020]
[ 250.496020] Chain exists of:
&(&new_timer->it_lock)->rlock --> tasklist_lock --> &(&p->alloc_lock)->rlock
[ 250.496020] Possible interrupt unsafe locking scenario:
[ 250.496020]
[ 250.496020] CPU0 CPU1
[ 250.496020] ---- ----
[ 250.496020] lock(&(&p->alloc_lock)->rlock);
[ 250.496020] local_irq_disable();
[ 250.496020] lock(&(&new_timer->it_lock)->rlock);
[ 250.496020] lock(tasklist_lock);
[ 250.496020] <Interrupt>
[ 250.496020] lock(&(&new_timer->it_lock)->rlock);
[ 250.496020]
[ 250.496020] *** DEADLOCK ***
[ 250.496020]
[ 250.496020] 1 lock held by trinity-child15/6956:
[ 250.496020] #0: (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
[ 250.496020]
the dependencies between HARDIRQ-irq-safe lock and the holding lock:
[ 250.496020] -> (&(&new_timer->it_lock)->rlock){-.-...} ops: 6221 {
[ 250.496020] IN-HARDIRQ-W at:
[ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
[ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
[ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
[ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
[ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
[ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
[ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
[ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
[ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
[ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
[ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
[ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
[ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
[ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
[ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
[ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
[ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
[ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.496020] IN-SOFTIRQ-W at:
[ 250.496020] [<ffffffff81149e67>] mark_irqflags+0xa7/0x190
[ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
[ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
[ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
[ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
[ 250.561155] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
[ 250.561155] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
[ 250.561155] [<ffffffff81190d27>] rcu_start_gp+0x467/0x500
[ 250.561155] [<ffffffff811932c3>] rcu_report_qs_rsp+0x223/0x290
[ 250.561155] [<ffffffff81193581>] rcu_report_qs_rnp+0x251/0x2b0
[ 250.561155] [<ffffffff8119543b>] rcu_check_quiescent_state+0x9b/0xc0
[ 250.561155] [<ffffffff811954e6>] __rcu_process_callbacks+0x86/0xe0
[ 250.561155] [<ffffffff81195618>] rcu_process_callbacks+0xd8/0x210
[ 250.561155] [<ffffffff810e1b95>] __do_softirq+0x1c5/0x450
[ 250.561155] [<ffffffff810e1f25>] run_ksoftirqd+0x105/0x250
[ 250.561155] [<ffffffff8110607d>] kthread+0xad/0xc0
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] INITIAL USE at:
[ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
[ 250.561155] [<ffffffff81104bb7>] __lock_timer+0xa7/0x1a0
[ 250.561155] [<ffffffff81105662>] sys_timer_getoverrun+0x12/0x50
[ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.561155] }
[ 250.561155] ... key at: [<ffffffff8536f7a0>] __key.29517+0x0/0x8
[ 250.561155] ... acquired at:
[ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
[ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
[ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
[ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
[ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
[ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
[ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
[ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
[ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
[ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
[ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
[ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.561155]
[ 250.561155]
[ 250.561155] the dependencies between the lock to be acquired and HARDIRQ-irq-unsafe lock:
[ 250.561155] -> (&(&p->alloc_lock)->rlock){+.+...} ops: 921205 {
[ 250.561155] HARDIRQ-ON-W at:
[ 250.561155] [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
[ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
[ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
[ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] SOFTIRQ-ON-W at:
[ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
[ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
[ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
[ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] INITIAL USE at:
[ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
[ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
[ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] }
[ 250.561155] ... key at: [<ffffffff8532b228>] __key.45219+0x0/0x8
[ 250.561155] ... acquired at:
[ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
[ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
[ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
[ 250.561155] [<ffffffff8189c7e5>] keyctl_session_to_parent+0x105/0x3f0
[ 250.561155] [<ffffffff8189cc25>] sys_keyctl+0x155/0x1a0
[ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.561155]
[ 250.561155] -> (tasklist_lock){.+.+..} ops: 81487 {
[ 250.561155] HARDIRQ-ON-R at:
[ 250.561155] [<ffffffff81149e8c>] mark_irqflags+0xcc/0x190
[ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
[ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
[ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
[ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] SOFTIRQ-ON-R at:
[ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
[ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
[ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
[ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
[ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
[ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
[ 250.561155] INITIAL USE at:
[ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff8369a859>] _raw_write_lock_irq+0x59/0x90
[ 250.561155] [<ffffffff810d686d>] copy_process+0xb0d/0x11a0
[ 250.561155] [<ffffffff810d7034>] do_fork+0x104/0x3d0
[ 250.561155] [<ffffffff81074451>] kernel_thread+0x71/0x80
[ 250.561155] [<ffffffff834f4bed>] rest_init+0x21/0x144
[ 250.561155] [<ffffffff850cbc24>] start_kernel+0x378/0x385
[ 250.561155] [<ffffffff850cb397>] x86_64_start_reservations+0x101/0x105
[ 250.561155] [<ffffffff850cb480>] x86_64_start_kernel+0xe5/0xf4
[ 250.561155] }
[ 250.561155] ... key at: [<ffffffff8481e018>] tasklist_lock+0x18/0x80
[ 250.561155] ... acquired at:
[ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
[ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
[ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
[ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
[ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
[ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
[ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
[ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
[ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
[ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
[ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
[ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
[ 250.561155]
[ 250.561155]
[ 250.561155] stack backtrace:
[ 250.561155] Pid: 6956, comm: trinity-child15 Tainted: G W 3.5.0-sasha-01646-g39c0dda #269
[ 250.561155] Call Trace:
[ 250.561155] [<ffffffff8114868a>] print_bad_irq_dependency+0x2ea/0x310
[ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
[ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
[ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
[ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
[ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
[ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
[ 250.561155] [<ffffffff81071a15>] ? sched_clock+0x15/0x20
[ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
[ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
[ 250.561155] [<ffffffff8114c245>] ? __lock_acquire+0xac5/0xb60
[ 250.561155] [<ffffffff8369a0ac>] ? _raw_spin_unlock_irqrestore+0x7c/0xa0
[ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
[ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
[ 250.561155] [<ffffffff8114dfde>] ? __lock_acquired+0x2ce/0x360
[ 250.561155] [<ffffffff81105a10>] ? exit_itimers+0x50/0x140
[ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
[ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
[ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
[ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
[ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
[ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
[ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
[ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: tasklist_lock lockdep warnings on 3.6
2012-07-25 6:42 tasklist_lock lockdep warnings on 3.6 Sasha Levin
@ 2012-07-30 14:50 ` Sasha Levin
2012-08-02 13:26 ` Dave Jones
0 siblings, 1 reply; 5+ messages in thread
From: Sasha Levin @ 2012-07-30 14:50 UTC (permalink / raw)
To: Ingo Molnar, Peter Zijlstra, Andrew Morton, tglx
Cc: davej, linux-kernel@vger.kernel.org
ping?
I'm still seeing this on linux-next.
On Wed, Jul 25, 2012 at 8:42 AM, Sasha Levin <levinsasha928@gmail.com> wrote:
> Hi all,
>
> I've stumbled on the following while fuzzing with trinity inside a KVM tools guest on 3.6 kernel:
>
> [ 250.495512] ======================================================
> [ 250.496020] [ INFO: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected ]
> [ 250.496020] 3.5.0-sasha-01646-g39c0dda #269 Tainted: G W
> [ 250.496020] ------------------------------------------------------
> [ 250.496020] trinity-child15/6956 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
> [ 250.496020] (tasklist_lock){.+.+..}, at: [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> [ 250.496020]
> [ 250.496020] and this task is already holding:
> [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
> [ 250.496020] which would create a new lock dependency:
> [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...} -> (tasklist_lock){.+.+..}
> [ 250.496020]
> [ 250.496020] but this new dependency connects a HARDIRQ-irq-safe lock:
> [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}
> ... which became HARDIRQ-irq-safe at:
> [ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
> [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> [ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> [ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> [ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
> [ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
> [ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
> [ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
> [ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
> [ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
> [ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
> [ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
> [ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
> [ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
> [ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.496020]
> [ 250.496020] to a HARDIRQ-irq-unsafe lock:
> [ 250.496020] (&(&p->alloc_lock)->rlock){+.+...}
> ... which became HARDIRQ-irq-unsafe at:
> [ 250.496020] ... [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
> [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.496020] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> [ 250.496020] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> [ 250.496020] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> [ 250.496020] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.496020]
> [ 250.496020] other info that might help us debug this:
> [ 250.496020]
> [ 250.496020] Chain exists of:
> &(&new_timer->it_lock)->rlock --> tasklist_lock --> &(&p->alloc_lock)->rlock
>
> [ 250.496020] Possible interrupt unsafe locking scenario:
> [ 250.496020]
> [ 250.496020] CPU0 CPU1
> [ 250.496020] ---- ----
> [ 250.496020] lock(&(&p->alloc_lock)->rlock);
> [ 250.496020] local_irq_disable();
> [ 250.496020] lock(&(&new_timer->it_lock)->rlock);
> [ 250.496020] lock(tasklist_lock);
> [ 250.496020] <Interrupt>
> [ 250.496020] lock(&(&new_timer->it_lock)->rlock);
> [ 250.496020]
> [ 250.496020] *** DEADLOCK ***
> [ 250.496020]
> [ 250.496020] 1 lock held by trinity-child15/6956:
> [ 250.496020] #0: (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
> [ 250.496020]
> the dependencies between HARDIRQ-irq-safe lock and the holding lock:
> [ 250.496020] -> (&(&new_timer->it_lock)->rlock){-.-...} ops: 6221 {
> [ 250.496020] IN-HARDIRQ-W at:
> [ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
> [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> [ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> [ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> [ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
> [ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
> [ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
> [ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
> [ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
> [ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
> [ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
> [ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
> [ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
> [ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
> [ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.496020] IN-SOFTIRQ-W at:
> [ 250.496020] [<ffffffff81149e67>] mark_irqflags+0xa7/0x190
> [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> [ 250.561155] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> [ 250.561155] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> [ 250.561155] [<ffffffff81190d27>] rcu_start_gp+0x467/0x500
> [ 250.561155] [<ffffffff811932c3>] rcu_report_qs_rsp+0x223/0x290
> [ 250.561155] [<ffffffff81193581>] rcu_report_qs_rnp+0x251/0x2b0
> [ 250.561155] [<ffffffff8119543b>] rcu_check_quiescent_state+0x9b/0xc0
> [ 250.561155] [<ffffffff811954e6>] __rcu_process_callbacks+0x86/0xe0
> [ 250.561155] [<ffffffff81195618>] rcu_process_callbacks+0xd8/0x210
> [ 250.561155] [<ffffffff810e1b95>] __do_softirq+0x1c5/0x450
> [ 250.561155] [<ffffffff810e1f25>] run_ksoftirqd+0x105/0x250
> [ 250.561155] [<ffffffff8110607d>] kthread+0xad/0xc0
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] INITIAL USE at:
> [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> [ 250.561155] [<ffffffff81104bb7>] __lock_timer+0xa7/0x1a0
> [ 250.561155] [<ffffffff81105662>] sys_timer_getoverrun+0x12/0x50
> [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.561155] }
> [ 250.561155] ... key at: [<ffffffff8536f7a0>] __key.29517+0x0/0x8
> [ 250.561155] ... acquired at:
> [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.561155]
> [ 250.561155]
> [ 250.561155] the dependencies between the lock to be acquired and HARDIRQ-irq-unsafe lock:
> [ 250.561155] -> (&(&p->alloc_lock)->rlock){+.+...} ops: 921205 {
> [ 250.561155] HARDIRQ-ON-W at:
> [ 250.561155] [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
> [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] SOFTIRQ-ON-W at:
> [ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
> [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] INITIAL USE at:
> [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] }
> [ 250.561155] ... key at: [<ffffffff8532b228>] __key.45219+0x0/0x8
> [ 250.561155] ... acquired at:
> [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> [ 250.561155] [<ffffffff8189c7e5>] keyctl_session_to_parent+0x105/0x3f0
> [ 250.561155] [<ffffffff8189cc25>] sys_keyctl+0x155/0x1a0
> [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.561155]
> [ 250.561155] -> (tasklist_lock){.+.+..} ops: 81487 {
> [ 250.561155] HARDIRQ-ON-R at:
> [ 250.561155] [<ffffffff81149e8c>] mark_irqflags+0xcc/0x190
> [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> [ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
> [ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
> [ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] SOFTIRQ-ON-R at:
> [ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
> [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> [ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
> [ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
> [ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
> [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> [ 250.561155] INITIAL USE at:
> [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff8369a859>] _raw_write_lock_irq+0x59/0x90
> [ 250.561155] [<ffffffff810d686d>] copy_process+0xb0d/0x11a0
> [ 250.561155] [<ffffffff810d7034>] do_fork+0x104/0x3d0
> [ 250.561155] [<ffffffff81074451>] kernel_thread+0x71/0x80
> [ 250.561155] [<ffffffff834f4bed>] rest_init+0x21/0x144
> [ 250.561155] [<ffffffff850cbc24>] start_kernel+0x378/0x385
> [ 250.561155] [<ffffffff850cb397>] x86_64_start_reservations+0x101/0x105
> [ 250.561155] [<ffffffff850cb480>] x86_64_start_kernel+0xe5/0xf4
> [ 250.561155] }
> [ 250.561155] ... key at: [<ffffffff8481e018>] tasklist_lock+0x18/0x80
> [ 250.561155] ... acquired at:
> [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> [ 250.561155]
> [ 250.561155]
> [ 250.561155] stack backtrace:
> [ 250.561155] Pid: 6956, comm: trinity-child15 Tainted: G W 3.5.0-sasha-01646-g39c0dda #269
> [ 250.561155] Call Trace:
> [ 250.561155] [<ffffffff8114868a>] print_bad_irq_dependency+0x2ea/0x310
> [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> [ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
> [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> [ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
> [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> [ 250.561155] [<ffffffff81071a15>] ? sched_clock+0x15/0x20
> [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> [ 250.561155] [<ffffffff8114c245>] ? __lock_acquire+0xac5/0xb60
> [ 250.561155] [<ffffffff8369a0ac>] ? _raw_spin_unlock_irqrestore+0x7c/0xa0
> [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> [ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
> [ 250.561155] [<ffffffff8114dfde>] ? __lock_acquired+0x2ce/0x360
> [ 250.561155] [<ffffffff81105a10>] ? exit_itimers+0x50/0x140
> [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> [ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
> [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: tasklist_lock lockdep warnings on 3.6
2012-07-30 14:50 ` Sasha Levin
@ 2012-08-02 13:26 ` Dave Jones
2012-08-02 14:16 ` Sasha Levin
0 siblings, 1 reply; 5+ messages in thread
From: Dave Jones @ 2012-08-02 13:26 UTC (permalink / raw)
To: Sasha Levin
Cc: Ingo Molnar, Peter Zijlstra, Andrew Morton, tglx,
linux-kernel@vger.kernel.org
On Mon, Jul 30, 2012 at 04:50:46PM +0200, Sasha Levin wrote:
> ping?
>
> I'm still seeing this on linux-next.
Likewise, except I'm seeing it in Linus' tree since shortly after this merge window
began. (https://lkml.org/lkml/2012/7/24/443).
I've spent all of this last week doing multiple attempts at bisecting this without success.
(It doesn't always show up, and even after running the test for over an hour before
marking a build 'good')
Anyone ?
Dave
> On Wed, Jul 25, 2012 at 8:42 AM, Sasha Levin <levinsasha928@gmail.com> wrote:
> > Hi all,
> >
> > I've stumbled on the following while fuzzing with trinity inside a KVM tools guest on 3.6 kernel:
> >
> > [ 250.495512] ======================================================
> > [ 250.496020] [ INFO: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected ]
> > [ 250.496020] 3.5.0-sasha-01646-g39c0dda #269 Tainted: G W
> > [ 250.496020] ------------------------------------------------------
> > [ 250.496020] trinity-child15/6956 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
> > [ 250.496020] (tasklist_lock){.+.+..}, at: [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> > [ 250.496020]
> > [ 250.496020] and this task is already holding:
> > [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
> > [ 250.496020] which would create a new lock dependency:
> > [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...} -> (tasklist_lock){.+.+..}
> > [ 250.496020]
> > [ 250.496020] but this new dependency connects a HARDIRQ-irq-safe lock:
> > [ 250.496020] (&(&new_timer->it_lock)->rlock){-.-...}
> > ... which became HARDIRQ-irq-safe at:
> > [ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
> > [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> > [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> > [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> > [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> > [ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> > [ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> > [ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
> > [ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
> > [ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
> > [ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
> > [ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
> > [ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
> > [ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
> > [ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
> > [ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
> > [ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
> > [ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.496020]
> > [ 250.496020] to a HARDIRQ-irq-unsafe lock:
> > [ 250.496020] (&(&p->alloc_lock)->rlock){+.+...}
> > ... which became HARDIRQ-irq-unsafe at:
> > [ 250.496020] ... [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
> > [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.496020] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> > [ 250.496020] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> > [ 250.496020] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> > [ 250.496020] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.496020]
> > [ 250.496020] other info that might help us debug this:
> > [ 250.496020]
> > [ 250.496020] Chain exists of:
> > &(&new_timer->it_lock)->rlock --> tasklist_lock --> &(&p->alloc_lock)->rlock
> >
> > [ 250.496020] Possible interrupt unsafe locking scenario:
> > [ 250.496020]
> > [ 250.496020] CPU0 CPU1
> > [ 250.496020] ---- ----
> > [ 250.496020] lock(&(&p->alloc_lock)->rlock);
> > [ 250.496020] local_irq_disable();
> > [ 250.496020] lock(&(&new_timer->it_lock)->rlock);
> > [ 250.496020] lock(tasklist_lock);
> > [ 250.496020] <Interrupt>
> > [ 250.496020] lock(&(&new_timer->it_lock)->rlock);
> > [ 250.496020]
> > [ 250.496020] *** DEADLOCK ***
> > [ 250.496020]
> > [ 250.496020] 1 lock held by trinity-child15/6956:
> > [ 250.496020] #0: (&(&new_timer->it_lock)->rlock){-.-...}, at: [<ffffffff81105a10>] exit_itimers+0x50/0x140
> > [ 250.496020]
> > the dependencies between HARDIRQ-irq-safe lock and the holding lock:
> > [ 250.496020] -> (&(&new_timer->it_lock)->rlock){-.-...} ops: 6221 {
> > [ 250.496020] IN-HARDIRQ-W at:
> > [ 250.496020] [<ffffffff81149e3c>] mark_irqflags+0x7c/0x190
> > [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> > [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> > [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> > [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> > [ 250.496020] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> > [ 250.496020] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> > [ 250.496020] [<ffffffff8118ec1e>] rcu_lockdep_current_cpu_online+0x6e/0xa0
> > [ 250.496020] [<ffffffff812a57be>] proc_sys_compare+0x7e/0x130
> > [ 250.496020] [<ffffffff8124a09c>] __d_lookup+0x18c/0x2e0
> > [ 250.496020] [<ffffffff8123d216>] lookup_fast+0x136/0x240
> > [ 250.496020] [<ffffffff8123da1c>] link_path_walk+0x22c/0x8f0
> > [ 250.496020] [<ffffffff8123e137>] path_lookupat+0x57/0x720
> > [ 250.496020] [<ffffffff8123e82c>] do_path_lookup+0x2c/0xc0
> > [ 250.496020] [<ffffffff8123ee14>] user_path_at_empty+0x64/0xa0
> > [ 250.496020] [<ffffffff8123ee5c>] user_path_at+0xc/0x10
> > [ 250.496020] [<ffffffff8122e6be>] sys_chdir+0x1e/0x70
> > [ 250.496020] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.496020] IN-SOFTIRQ-W at:
> > [ 250.496020] [<ffffffff81149e67>] mark_irqflags+0xa7/0x190
> > [ 250.496020] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.496020] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.496020] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> > [ 250.496020] [<ffffffff81104ee2>] posix_timer_fn+0x32/0xd0
> > [ 250.496020] [<ffffffff8110b25e>] __run_hrtimer+0x27e/0x4d0
> > [ 250.496020] [<ffffffff8110c299>] hrtimer_interrupt+0x119/0x220
> > [ 250.561155] [<ffffffff81090215>] smp_apic_timer_interrupt+0x85/0xa0
> > [ 250.561155] [<ffffffff8369c4af>] apic_timer_interrupt+0x6f/0x80
> > [ 250.561155] [<ffffffff81190d27>] rcu_start_gp+0x467/0x500
> > [ 250.561155] [<ffffffff811932c3>] rcu_report_qs_rsp+0x223/0x290
> > [ 250.561155] [<ffffffff81193581>] rcu_report_qs_rnp+0x251/0x2b0
> > [ 250.561155] [<ffffffff8119543b>] rcu_check_quiescent_state+0x9b/0xc0
> > [ 250.561155] [<ffffffff811954e6>] __rcu_process_callbacks+0x86/0xe0
> > [ 250.561155] [<ffffffff81195618>] rcu_process_callbacks+0xd8/0x210
> > [ 250.561155] [<ffffffff810e1b95>] __do_softirq+0x1c5/0x450
> > [ 250.561155] [<ffffffff810e1f25>] run_ksoftirqd+0x105/0x250
> > [ 250.561155] [<ffffffff8110607d>] kthread+0xad/0xc0
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] INITIAL USE at:
> > [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff83699e79>] _raw_spin_lock_irqsave+0x79/0xc0
> > [ 250.561155] [<ffffffff81104bb7>] __lock_timer+0xa7/0x1a0
> > [ 250.561155] [<ffffffff81105662>] sys_timer_getoverrun+0x12/0x50
> > [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.561155] }
> > [ 250.561155] ... key at: [<ffffffff8536f7a0>] __key.29517+0x0/0x8
> > [ 250.561155] ... acquired at:
> > [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> > [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> > [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> > [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> > [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> > [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> > [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> > [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> > [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> > [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> > [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> > [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.561155]
> > [ 250.561155]
> > [ 250.561155] the dependencies between the lock to be acquired and HARDIRQ-irq-unsafe lock:
> > [ 250.561155] -> (&(&p->alloc_lock)->rlock){+.+...} ops: 921205 {
> > [ 250.561155] HARDIRQ-ON-W at:
> > [ 250.561155] [<ffffffff81149ec0>] mark_irqflags+0x100/0x190
> > [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> > [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> > [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] SOFTIRQ-ON-W at:
> > [ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
> > [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> > [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> > [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] INITIAL USE at:
> > [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> > [ 250.561155] [<ffffffff81237ed1>] set_task_comm+0x31/0x1c0
> > [ 250.561155] [<ffffffff8110665c>] kthreadd+0x2c/0x170
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] }
> > [ 250.561155] ... key at: [<ffffffff8532b228>] __key.45219+0x0/0x8
> > [ 250.561155] ... acquired at:
> > [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> > [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> > [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff83699dcb>] _raw_spin_lock+0x3b/0x70
> > [ 250.561155] [<ffffffff8189c7e5>] keyctl_session_to_parent+0x105/0x3f0
> > [ 250.561155] [<ffffffff8189cc25>] sys_keyctl+0x155/0x1a0
> > [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.561155]
> > [ 250.561155] -> (tasklist_lock){.+.+..} ops: 81487 {
> > [ 250.561155] HARDIRQ-ON-R at:
> > [ 250.561155] [<ffffffff81149e8c>] mark_irqflags+0xcc/0x190
> > [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> > [ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
> > [ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
> > [ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] SOFTIRQ-ON-R at:
> > [ 250.561155] [<ffffffff81149ee3>] mark_irqflags+0x123/0x190
> > [ 250.561155] [<ffffffff8114c0b6>] __lock_acquire+0x936/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> > [ 250.561155] [<ffffffff810de1b8>] do_wait+0x178/0x3b0
> > [ 250.561155] [<ffffffff810df64b>] sys_wait4+0xbb/0xe0
> > [ 250.561155] [<ffffffff810f81b0>] wait_for_helper+0x80/0xa0
> > [ 250.561155] [<ffffffff8369cdb4>] kernel_thread_helper+0x4/0x10
> > [ 250.561155] INITIAL USE at:
> > [ 250.561155] [<ffffffff8114c0dc>] __lock_acquire+0x95c/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff8369a859>] _raw_write_lock_irq+0x59/0x90
> > [ 250.561155] [<ffffffff810d686d>] copy_process+0xb0d/0x11a0
> > [ 250.561155] [<ffffffff810d7034>] do_fork+0x104/0x3d0
> > [ 250.561155] [<ffffffff81074451>] kernel_thread+0x71/0x80
> > [ 250.561155] [<ffffffff834f4bed>] rest_init+0x21/0x144
> > [ 250.561155] [<ffffffff850cbc24>] start_kernel+0x378/0x385
> > [ 250.561155] [<ffffffff850cb397>] x86_64_start_reservations+0x101/0x105
> > [ 250.561155] [<ffffffff850cb480>] x86_64_start_kernel+0xe5/0xf4
> > [ 250.561155] }
> > [ 250.561155] ... key at: [<ffffffff8481e018>] tasklist_lock+0x18/0x80
> > [ 250.561155] ... acquired at:
> > [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> > [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> > [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> > [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> > [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> > [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> > [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> > [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> > [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> > [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> > [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> > [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
> > [ 250.561155]
> > [ 250.561155]
> > [ 250.561155] stack backtrace:
> > [ 250.561155] Pid: 6956, comm: trinity-child15 Tainted: G W 3.5.0-sasha-01646-g39c0dda #269
> > [ 250.561155] Call Trace:
> > [ 250.561155] [<ffffffff8114868a>] print_bad_irq_dependency+0x2ea/0x310
> > [ 250.561155] [<ffffffff8114886d>] check_usage+0x1bd/0x1e0
> > [ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
> > [ 250.561155] [<ffffffff811488fa>] check_irq_usage+0x6a/0xe0
> > [ 250.561155] [<ffffffff81148abb>] check_prev_add+0x14b/0x640
> > [ 250.561155] [<ffffffff8109cc55>] ? pvclock_clocksource_read+0x55/0xe0
> > [ 250.561155] [<ffffffff8114906a>] check_prevs_add+0xba/0x1a0
> > [ 250.561155] [<ffffffff81071a15>] ? sched_clock+0x15/0x20
> > [ 250.561155] [<ffffffff811497f0>] validate_chain.isra.22+0x6a0/0x7b0
> > [ 250.561155] [<ffffffff8114c221>] __lock_acquire+0xaa1/0xb60
> > [ 250.561155] [<ffffffff8114c245>] ? __lock_acquire+0xac5/0xb60
> > [ 250.561155] [<ffffffff8369a0ac>] ? _raw_spin_unlock_irqrestore+0x7c/0xa0
> > [ 250.561155] [<ffffffff8114e75a>] lock_acquire+0x1ca/0x270
> > [ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
> > [ 250.561155] [<ffffffff8114dfde>] ? __lock_acquired+0x2ce/0x360
> > [ 250.561155] [<ffffffff81105a10>] ? exit_itimers+0x50/0x140
> > [ 250.561155] [<ffffffff8369a25e>] _raw_read_lock+0x3e/0x80
> > [ 250.561155] [<ffffffff811089da>] ? posix_cpu_timer_del+0x2a/0x110
> > [ 250.561155] [<ffffffff811089da>] posix_cpu_timer_del+0x2a/0x110
> > [ 250.561155] [<ffffffff81105a8d>] exit_itimers+0xcd/0x140
> > [ 250.561155] [<ffffffff810deea8>] do_exit+0x1b8/0x580
> > [ 250.561155] [<ffffffff810df33a>] do_group_exit+0x8a/0xc0
> > [ 250.561155] [<ffffffff810df382>] sys_exit_group+0x12/0x20
> > [ 250.561155] [<ffffffff8369b77d>] system_call_fastpath+0x1a/0x1f
---end quoted text---
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: tasklist_lock lockdep warnings on 3.6
2012-08-02 13:26 ` Dave Jones
@ 2012-08-02 14:16 ` Sasha Levin
2012-08-07 14:27 ` Sasha Levin
0 siblings, 1 reply; 5+ messages in thread
From: Sasha Levin @ 2012-08-02 14:16 UTC (permalink / raw)
To: Dave Jones, Ingo Molnar, Peter Zijlstra, Andrew Morton, tglx,
linux-kernel@vger.kernel.org
On 08/02/2012 03:26 PM, Dave Jones wrote:
> On Mon, Jul 30, 2012 at 04:50:46PM +0200, Sasha Levin wrote:
> > ping?
> >
> > I'm still seeing this on linux-next.
>
> Likewise, except I'm seeing it in Linus' tree since shortly after this merge window
> began. (https://lkml.org/lkml/2012/7/24/443).
>
> I've spent all of this last week doing multiple attempts at bisecting this without success.
> (It doesn't always show up, and even after running the test for over an hour before
> marking a build 'good')
>
> Anyone ?
>
> Dave
I've been able to hit this issue pretty much every time by hitting sysrq-t after about 10 seconds of fuzzing. It shows up in the middle of the sysrq-t spew.
Unfortunately I didn't have time yet to try and bisect it.
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: tasklist_lock lockdep warnings on 3.6
2012-08-02 14:16 ` Sasha Levin
@ 2012-08-07 14:27 ` Sasha Levin
0 siblings, 0 replies; 5+ messages in thread
From: Sasha Levin @ 2012-08-07 14:27 UTC (permalink / raw)
To: Dave Jones, Ingo Molnar, Peter Zijlstra, Andrew Morton, tglx,
linux-kernel@vger.kernel.org, viro, dhowells, james.l.morris,
keyrings
On 08/02/2012 04:16 PM, Sasha Levin wrote:
> On 08/02/2012 03:26 PM, Dave Jones wrote:
>> On Mon, Jul 30, 2012 at 04:50:46PM +0200, Sasha Levin wrote:
>> > ping?
>> >
>> > I'm still seeing this on linux-next.
>>
>> Likewise, except I'm seeing it in Linus' tree since shortly after this merge window
>> began. (https://lkml.org/lkml/2012/7/24/443).
>>
>> I've spent all of this last week doing multiple attempts at bisecting this without success.
>> (It doesn't always show up, and even after running the test for over an hour before
>> marking a build 'good')
>>
>> Anyone ?
>>
>> Dave
>
> I've been able to hit this issue pretty much every time by hitting sysrq-t after about 10 seconds of fuzzing. It shows up in the middle of the sysrq-t spew.
>
> Unfortunately I didn't have time yet to try and bisect it.
>
So I've bisected it. The bisection was automatic most of the time, but I've confirmed that this is indeed the offending commit manually.
d35abdb28824cf74f0a106a0f9c6f3ff700a35bf is the first bad commit
commit d35abdb28824cf74f0a106a0f9c6f3ff700a35bf
Author: Al Viro <viro@zeniv.linux.org.uk>
Date: Sat Jun 30 11:55:24 2012 +0400
hold task_lock around checks in keyctl
Signed-off-by: Al Viro <viro@zeniv.linux.org.uk>
Relevant parties Cc'ed.
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2012-08-07 14:26 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2012-07-25 6:42 tasklist_lock lockdep warnings on 3.6 Sasha Levin
2012-07-30 14:50 ` Sasha Levin
2012-08-02 13:26 ` Dave Jones
2012-08-02 14:16 ` Sasha Levin
2012-08-07 14:27 ` Sasha Levin
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).