Re: [PATCH] lockdep: Print proper scenario if cross deadlock detected at acquisition time

From: Boqun Feng
Date: Tue Sep 19 2017 - 08:58:17 EST


On Tue, Sep 19, 2017 at 08:52:06PM +0800, Boqun Feng wrote:
> For a potential deadlock about CROSSRELEASE as follow:
>
> P1 P2
> =========== =============
> lock(A)
> lock(X)
> lock(A)
> commit(X)
>
> A: normal lock, X: cross lock
>
> , we could detect it at two places:
>
> 1. commit time:
>
> We have run P1 first, and have dependency A --> X in graph, and
> then we run P2, and find the deadlock.
>
> 2. acquisition time:
>
> We have run P2 first, and have dependency X --> A, in
> graph(because another P3 may run previously and is acquiring for
> lock X), and then we run P1 and find the deadlock.
>
> In current print_circular_lock_scenario(), for 1) we could print the
> right scenario and note that's a deadlock related to CROSSRELEASE,
> however for 2) we print the scenario as a normal lockdep deadlock,
> instead we print something like:

Hmm... this sentence is redundant.. the paragraph should be:

... for 2) we currenlty print the scenario as a normal lockdep deadlock:

Apologies for this.

Regards,
Boqun

>
> | [ 35.310179] ======================================================
> | [ 35.310749] WARNING: possible circular locking dependency detected
> | [ 35.310749] 4.13.0-rc4+ #1 Not tainted
> | [ 35.310749] ------------------------------------------------------
> | [ 35.310749] torture_onoff/766 is trying to acquire lock:
> | [ 35.313943] ((complete)&st->done){+.+.}, at: [<ffffffffb905f5a6>] takedown_cpu+0x86/0xf0
> | [ 35.313943]
> | [ 35.313943] but task is already holding lock:
> | [ 35.313943] (sparse_irq_lock){+.+.}, at: [<ffffffffb90c5e42>] irq_lock_sparse+0x12/0x20
> | [ 35.313943]
> | [ 35.313943] which lock already depends on the new lock.
> ...
> | [ 35.313943] other info that might help us debug this:
> | [ 35.313943]
> | [ 35.313943] Possible unsafe locking scenario:
> | [ 35.313943]
> | [ 35.313943] CPU0 CPU1
> | [ 35.313943] ---- ----
> | [ 35.313943] lock(sparse_irq_lock);
> | [ 35.313943] lock((complete)&st->done);
> | [ 35.313943] lock(sparse_irq_lock);
> | [ 35.313943] lock((complete)&st->done);
> | [ 35.313943]
> | [ 35.313943] *** DEADLOCK ***
>
> It's better to print a proper scenario related to CROSSRELEASE to help
> users find their bugs more easily, so improve this.
>
> Cc: "Paul E. McKenney" <paulmck@xxxxxxxxxxxxxxxxxx>
> Cc: Byungchul Park <byungchul.park@xxxxxxx>
> Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
> Signed-off-by: Boqun Feng <boqun.feng@xxxxxxxxx>
> ---
> The sample of print_circular_lock_scenario() is from Paul Mckenney.
>
> kernel/locking/lockdep.c | 17 +++++++++++++++++
> 1 file changed, 17 insertions(+)
>
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 44c8d0d17170..67a407bcc814 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -1156,6 +1156,23 @@ print_circular_lock_scenario(struct held_lock *src,
> __print_lock_name(target);
> printk(KERN_CONT ");\n");
> printk("\n *** DEADLOCK ***\n\n");
> + } else if (cross_lock(src->instance)) {
> + printk(" Possible unsafe locking scenario by crosslock:\n\n");
> + printk(" CPU0 CPU1\n");
> + printk(" ---- ----\n");
> + printk(" lock(");
> + __print_lock_name(target);
> + printk(KERN_CONT ");\n");
> + printk(" lock(");
> + __print_lock_name(source);
> + printk(KERN_CONT ");\n");
> + printk(" lock(");
> + __print_lock_name(parent == source ? target : parent);
> + printk(KERN_CONT ");\n");
> + printk(" unlock(");
> + __print_lock_name(source);
> + printk(KERN_CONT ");\n");
> + printk("\n *** DEADLOCK ***\n\n");
> } else {
> printk(" Possible unsafe locking scenario:\n\n");
> printk(" CPU0 CPU1\n");
> --
> 2.14.1
>

Attachment: signature.asc
Description: PGP signature