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 <levinsasha...@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--- -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
