From: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To: Peter Zijlstra <peterz@infradead.org>
Cc: Dave Jones <davej@redhat.com>,
Linux Kernel <linux-kernel@vger.kernel.org>
Subject: Re: lockdep circular locking error (rcu_node_level_0 vs rq->lock)
Date: Tue, 12 Jul 2011 13:51:26 -0700 [thread overview]
Message-ID: <20110712205126.GM2326@linux.vnet.ibm.com> (raw)
In-Reply-To: <1310502014.2309.7.camel@laptop>
On Tue, Jul 12, 2011 at 10:20:14PM +0200, Peter Zijlstra wrote:
> On Mon, 2011-07-11 at 19:19 -0400, Dave Jones wrote:
> > I was doing an install in a kvm guest, which wedged itself at the end.
> > This was in the host dmesg.
> >
> >
> > [ INFO: possible circular locking dependency detected ]
> > 3.0.0-rc6+ #91
> > -------------------------------------------------------
> > libvirtd/5720 is trying to acquire lock:
> > (rcu_node_level_0){..-.-.}, at: [<ffffffff814c6c12>] rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> >
> > but task is already holding lock:
> > (&rq->lock){-.-.-.}, at: [<ffffffff8105408e>] sched_ttwu_pending+0x39/0x5b
> >
> > which lock already depends on the new lock.
> >
> >
> > the existing dependency chain (in reverse order) is:
> >
> > -> #3 (&rq->lock){-.-.-.}:
> > [<ffffffff8108dfc5>] lock_acquire+0xf3/0x13e
> > [<ffffffff814cf0ab>] _raw_spin_lock+0x40/0x73
> > [<ffffffff8104663a>] __task_rq_lock+0x5e/0x8b
> > [<ffffffff8105506d>] wake_up_new_task+0x46/0x10d
> > [<ffffffff8105a1c9>] do_fork+0x231/0x331
> > [<ffffffff81010c80>] kernel_thread+0x75/0x77
> > [<ffffffff814abe82>] rest_init+0x26/0xdc
> > [<ffffffff81d3dbc2>] start_kernel+0x401/0x40c
> > [<ffffffff81d3d2c4>] x86_64_start_reservations+0xaf/0xb3
> > [<ffffffff81d3d3ca>] x86_64_start_kernel+0x102/0x111
> >
> > -> #2 (&p->pi_lock){-.-.-.}:
> > [<ffffffff8108dfc5>] lock_acquire+0xf3/0x13e
> > [<ffffffff814cf238>] _raw_spin_lock_irqsave+0x4f/0x89
> > [<ffffffff81054e3d>] try_to_wake_up+0x2e/0x1db
> > [<ffffffff81054ffc>] default_wake_function+0x12/0x14
> > [<ffffffff81079008>] autoremove_wake_function+0x18/0x3d
> > [<ffffffff81045010>] __wake_up_common+0x4d/0x83
> > [<ffffffff8104634e>] __wake_up+0x39/0x4d
> > [<ffffffff810c3cd6>] rcu_report_exp_rnp+0x52/0x8b
> > [<ffffffff810c4f18>] __rcu_read_unlock+0x1d0/0x231
> > [<ffffffff8115202a>] rcu_read_unlock+0x26/0x28
> > [<ffffffff8115465d>] __d_lookup+0x103/0x115
> > [<ffffffff8114b9eb>] walk_component+0x1b1/0x3af
> > [<ffffffff8114bd8a>] link_path_walk+0x1a1/0x43b
> > [<ffffffff8114c148>] path_lookupat+0x5a/0x2af
> > [<ffffffff8114d222>] do_path_lookup+0x28/0x97
> > [<ffffffff8114d658>] user_path_at+0x59/0x96
> > [<ffffffff81145214>] sys_readlinkat+0x33/0x95
> > [<ffffffff81145291>] sys_readlink+0x1b/0x1d
> > [<ffffffff814d5c02>] system_call_fastpath+0x16/0x1b
> >
> > -> #1 (sync_rcu_preempt_exp_wq.lock){......}:
> > [<ffffffff8108dfc5>] lock_acquire+0xf3/0x13e
> > [<ffffffff814cf238>] _raw_spin_lock_irqsave+0x4f/0x89
> > [<ffffffff81046337>] __wake_up+0x22/0x4d
> > [<ffffffff810c3cd6>] rcu_report_exp_rnp+0x52/0x8b
> > [<ffffffff810c4f18>] __rcu_read_unlock+0x1d0/0x231
> > [<ffffffff8115202a>] rcu_read_unlock+0x26/0x28
> > [<ffffffff8115465d>] __d_lookup+0x103/0x115
> > [<ffffffff8114b9eb>] walk_component+0x1b1/0x3af
> > [<ffffffff8114bd8a>] link_path_walk+0x1a1/0x43b
> > [<ffffffff8114c148>] path_lookupat+0x5a/0x2af
> > [<ffffffff8114d222>] do_path_lookup+0x28/0x97
> > [<ffffffff8114d658>] user_path_at+0x59/0x96
> > [<ffffffff81145214>] sys_readlinkat+0x33/0x95
> > [<ffffffff81145291>] sys_readlink+0x1b/0x1d
> > [<ffffffff814d5c02>] system_call_fastpath+0x16/0x1b
> >
> > -> #0 (rcu_node_level_0){..-.-.}:
> > [<ffffffff8108d7e5>] __lock_acquire+0xa2f/0xd0c
> > [<ffffffff8108dfc5>] lock_acquire+0xf3/0x13e
> > [<ffffffff814cf0ab>] _raw_spin_lock+0x40/0x73
> > [<ffffffff814c6c12>] rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> > [<ffffffff810c4ed6>] __rcu_read_unlock+0x18e/0x231
> > [<ffffffff810463f4>] rcu_read_unlock+0x26/0x28
> > [<ffffffff8104b6db>] cpuacct_charge+0x58/0x61
> > [<ffffffff81052f18>] update_curr+0x107/0x134
> > [<ffffffff8105349b>] check_preempt_wakeup+0xc9/0x1d0
> > [<ffffffff81049775>] check_preempt_curr+0x2f/0x6e
> > [<ffffffff81053f5e>] ttwu_do_wakeup+0x7b/0x111
> > [<ffffffff81054050>] ttwu_do_activate.constprop.76+0x5c/0x61
> > [<ffffffff8105409e>] sched_ttwu_pending+0x49/0x5b
> > [<ffffffff810540be>] scheduler_ipi+0xe/0x10
> > [<ffffffff810224f6>] smp_reschedule_interrupt+0x1b/0x1d
> > [<ffffffff814d6b33>] reschedule_interrupt+0x13/0x20
> > [<ffffffff813fcc18>] rcu_read_unlock+0x26/0x28
> > [<ffffffff813fe308>] sock_def_readable+0x88/0x8d
> > [<ffffffff81497760>] unix_stream_sendmsg+0x264/0x2ff
> > [<ffffffff813f83c4>] sock_aio_write+0x112/0x126
> > [<ffffffff8114093b>] do_sync_write+0xbf/0xff
> > [<ffffffff81141012>] vfs_write+0xb6/0xf6
> > [<ffffffff81141206>] sys_write+0x4d/0x74
> > [<ffffffff814d5c02>] system_call_fastpath+0x16/0x1b
> >
> > other info that might help us debug this:
> >
> > Chain exists of:
> > rcu_node_level_0 --> &p->pi_lock --> &rq->lock
> >
> > Possible unsafe locking scenario:
> >
> > CPU0 CPU1
> > ---- ----
> > lock(&rq->lock);
> > lock(&p->pi_lock);
> > lock(&rq->lock);
> > lock(rcu_node_level_0);
> >
> > *** DEADLOCK ***
> >
> > 1 lock held by libvirtd/5720:
> > #0: (&rq->lock){-.-.-.}, at: [<ffffffff8105408e>] sched_ttwu_pending+0x39/0x5b
> >
> > stack backtrace:
> > Pid: 5720, comm: libvirtd Not tainted 3.0.0-rc6+ #91
> > Call Trace:
> > <IRQ> [<ffffffff814c51cf>] print_circular_bug+0x1f8/0x209
> > [<ffffffff8108d7e5>] __lock_acquire+0xa2f/0xd0c
> > [<ffffffff8107e905>] ? sched_clock_local+0x12/0x75
> > [<ffffffff814c6c12>] ? rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> > [<ffffffff8108dfc5>] lock_acquire+0xf3/0x13e
> > [<ffffffff814c6c12>] ? rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> > [<ffffffff8108adab>] ? lock_release_holdtime.part.10+0x59/0x62
> > [<ffffffff814cf0ab>] _raw_spin_lock+0x40/0x73
> > [<ffffffff814c6c12>] ? rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> > [<ffffffff814cf855>] ? _raw_spin_unlock+0x47/0x54
> > [<ffffffff814c6c12>] rcu_report_unblock_qs_rnp.part.5+0x3f/0x60
> > [<ffffffff810c4e00>] ? __rcu_read_unlock+0xb8/0x231
> > [<ffffffff810c4ed6>] __rcu_read_unlock+0x18e/0x231
> > [<ffffffff810463f4>] rcu_read_unlock+0x26/0x28
> > [<ffffffff8104b6db>] cpuacct_charge+0x58/0x61
> > [<ffffffff81052f18>] update_curr+0x107/0x134
> > [<ffffffff8105349b>] check_preempt_wakeup+0xc9/0x1d0
> > [<ffffffff81049775>] check_preempt_curr+0x2f/0x6e
> > [<ffffffff81053f5e>] ttwu_do_wakeup+0x7b/0x111
> > [<ffffffff81054050>] ttwu_do_activate.constprop.76+0x5c/0x61
> > [<ffffffff8105409e>] sched_ttwu_pending+0x49/0x5b
> > [<ffffffff810540be>] scheduler_ipi+0xe/0x10
> > [<ffffffff810224f6>] smp_reschedule_interrupt+0x1b/0x1d
> > [<ffffffff814d6b33>] reschedule_interrupt+0x13/0x20
> > <EOI> [<ffffffff8107e905>] ? sched_clock_local+0x12/0x75
> > [<ffffffff810c4d91>] ? __rcu_read_unlock+0x49/0x231
> > [<ffffffff8108dea5>] ? lock_release+0x1b1/0x1de
> > [<ffffffff813fcc18>] rcu_read_unlock+0x26/0x28
> > [<ffffffff813fe308>] sock_def_readable+0x88/0x8d
> > [<ffffffff81497760>] unix_stream_sendmsg+0x264/0x2ff
> > [<ffffffff813f83c4>] sock_aio_write+0x112/0x126
> > [<ffffffff8121cd95>] ? inode_has_perm+0x6a/0x77
> > [<ffffffff8114093b>] do_sync_write+0xbf/0xff
> > [<ffffffff81219562>] ? security_file_permission+0x2e/0x33
> > [<ffffffff81140d71>] ? rw_verify_area+0xb6/0xd3
> > [<ffffffff81141012>] vfs_write+0xb6/0xf6
> > [<ffffffff811426a0>] ? fget_light+0x97/0xa2
> > [<ffffffff81141206>] sys_write+0x4d/0x74
> > [<ffffffff81078f85>] ? remove_wait_queue+0x1a/0x3a
> > [<ffffffff814d5c02>] system_call_fastpath+0x16/0x1b
>
> Hi Paul, RCU is doing really bad things here, rcu_read_unlock() ->
> rcu_read_unlock_special() can do all kinds of nasty, including as per
> the above call back into the scheduler, which is kinda a death-warrant
> seeing as the scheduler itself can use RCU.
As we discussed on IRC, it doesn't look like RCU can safely defer
this processing. For example, if softirqd is lower priority than an
RCU priority boosted task, softirqd might never get a chance to lower
the priority. Plus this could mess up the accounting for the rt_mutex
used to carry out the priority boosting. And for reporting the end of
an expedited RCU grace period, the possibly long-term deferral could
easily defeat the whole purpose of expediting.
So I am hoping that your idea of doing rcu_read_lock() before acquiring
rq locks (and pi locks) and doing rcu_read_unlock() after releasing them
does work out!
Thanx, Paul
next prev parent reply other threads:[~2011-07-12 20:51 UTC|newest]
Thread overview: 9+ messages / expand[flat|nested] mbox.gz Atom feed top
2011-07-11 23:19 lockdep circular locking error (rcu_node_level_0 vs rq->lock) Dave Jones
2011-07-12 20:20 ` Peter Zijlstra
2011-07-12 20:51 ` Paul E. McKenney [this message]
2011-07-12 21:44 ` Peter Zijlstra
2011-07-12 22:54 ` Paul E. McKenney
2011-07-13 8:24 ` Peter Zijlstra
2011-07-13 16:33 ` Paul E. McKenney
2011-07-14 4:29 ` Paul E. McKenney
2011-07-14 5:26 ` Paul E. McKenney
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20110712205126.GM2326@linux.vnet.ibm.com \
--to=paulmck@linux.vnet.ibm.com \
--cc=davej@redhat.com \
--cc=linux-kernel@vger.kernel.org \
--cc=peterz@infradead.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox