Re: hotplug lockdep splat (tip)

[Mike Galbraith]

On Mon, 2017-09-04 at 09:55 +0200, Peter Zijlstra wrote:
> On Sun, Sep 03, 2017 at 08:59:35AM +0200, Mike Galbraith wrote:
> > 
> > [  126.626908] Unregister pv shared memory for cpu 1
> > [  126.631041] 
> > [  126.631269] ======================================================
> > [  126.632442] WARNING: possible circular locking dependency detected
> > [  126.633599] 4.13.0.g06260ca-tip-lockdep #2 Tainted: G            E  
> > [  126.634380] ------------------------------------------------------
> > [  126.635124] stress-cpu-hotp/3156 is trying to acquire lock:
> > [  126.635804]  ((complete)&st->done){+.+.}, at: [<ffffffff8108d19a>] takedown_cpu+0x8a/0xf0
> > [  126.636809] 
> > [  126.636809] but task is already holding lock:
> > [  126.637567]  (sparse_irq_lock){+.+.}, at: [<ffffffff81107ac7>] irq_lock_sparse+0x17/0x20
> > [  126.638665] 
> 
> https://lkml.kernel.org/r/20170829193416.GC32112@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

Well, flavor of gripe changed.

[  164.114290] ======================================================
[  164.115146] WARNING: possible circular locking dependency detected
[  164.115751] 4.13.0.g90abd70-tip-lockdep #4 Tainted: G            E  
[  164.116348] ------------------------------------------------------
[  164.116919] cpuhp/0/12 is trying to acquire lock:
[  164.117381]  (cpuhp_state){+.+.}, at: [<ffffffff8108e4aa>] cpuhp_thread_fun+0x2a/0x160
[  164.118097] 
               but now in release context of a crosslock acquired at the following:
[  164.118845]  ((complete)&per_cpu_ptr(&cpuhp_state, i)->done#2){+.+.}, at: [<ffffffff8108e71f>] cpuhp_issue_call+0x13f/0x170
[  164.119789] 
               which lock already depends on the new lock.

[  164.120483] 
               the existing dependency chain (in reverse order) is:
[  164.121121] 
               -> #2 ((complete)&per_cpu_ptr(&cpuhp_state, i)->done#2){+.+.}:
[  164.121840]        __lock_acquire+0x116a/0x11c0
[  164.122382]        lock_acquire+0xbd/0x200
[  164.122741]        wait_for_completion+0x53/0x1a0
[  164.123181]        takedown_cpu+0x8a/0xf0
[  164.123533]        cpuhp_invoke_callback+0x1f6/0x830
[  164.123967]        cpuhp_down_callbacks+0x42/0x80
[  164.124433]        _cpu_down+0x155/0x190
[  164.124779]        do_cpu_down+0x3e/0x60
[  164.125127]        cpu_down+0x10/0x20
[  164.125456]        cpu_subsys_offline+0x14/0x20
[  164.125937]        device_offline+0x8c/0xb0
[  164.126487]        online_store+0x40/0x80
[  164.126943]        dev_attr_store+0x18/0x30
[  164.127335]        sysfs_kf_write+0x44/0x60
[  164.127703]        kernfs_fop_write+0x113/0x1a0
[  164.128141]        __vfs_write+0x28/0x150
[  164.128532]        vfs_write+0xc7/0x1c0
[  164.128871]        SyS_write+0x49/0xa0
[  164.129206]        entry_SYSCALL_64_fastpath+0x1f/0xbe
[  164.129656] 
               -> #1 (sparse_irq_lock){+.+.}:
[  164.130145]        __lock_acquire+0x116a/0x11c0
[  164.130546]        lock_acquire+0xbd/0x200
[  164.130913]        __mutex_lock+0x70/0x8e0
[  164.131276]        mutex_lock_nested+0x1b/0x20
[  164.131664]        irq_lock_sparse+0x17/0x20
[  164.132039]        irq_affinity_online_cpu+0x18/0xd0
[  164.132463]        cpuhp_invoke_callback+0x1f6/0x830
[  164.132928]        cpuhp_up_callbacks+0x37/0xb0
[  164.133487]        cpuhp_thread_fun+0x14f/0x160
[  164.133885]        smpboot_thread_fn+0x11a/0x1e0
[  164.134333]        kthread+0x152/0x190
[  164.134652]        ret_from_fork+0x2a/0x40
[  164.135010] 
               -> #0 (cpuhp_state){+.+.}:
[  164.135454]        cpuhp_thread_fun+0x54/0x160
[  164.135834]        smpboot_thread_fn+0x11a/0x1e0
[  164.136235]        kthread+0x152/0x190
[  164.136558]        ret_from_fork+0x2a/0x40
[  164.136920]        0xffffffffffffffff
[  164.137239] 
               other info that might help us debug this:

[  164.137927] Chain exists of:
                 cpuhp_state --> sparse_irq_lock --> (complete)&per_cpu_ptr(&cpuhp_state, i)->done#2

[  164.139136]  Possible unsafe locking scenario by crosslock:

[  164.139898]        CPU0                    CPU1
[  164.140298]        ----                    ----
[  164.140689]   lock(sparse_irq_lock);
[  164.141015]   lock((complete)&per_cpu_ptr(&cpuhp_state, i)->done#2);
[  164.141565]                                lock(cpuhp_state);
[  164.142077]                                unlock((complete)&per_cpu_ptr(&cpuhp_state, i)->done#2);
[  164.142859] 
                *** DEADLOCK ***

[  164.143382] 1 lock held by cpuhp/0/12:
[  164.143794]  #0:  (&x->wait#2){-...}, at: [<ffffffff810e1afd>] complete+0x1d/0x60
[  164.144461] 
               stack backtrace:
[  164.144837] CPU: 0 PID: 12 Comm: cpuhp/0 Tainted: G            E   4.13.0.g90abd70-tip-lockdep #4
[  164.145594] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.0.0-prebuilt.qemu-project.org 04/01/2014
[  164.146485] Call Trace:
[  164.146707]  dump_stack+0x85/0xc5
[  164.147004]  print_circular_bug+0x2e9/0x2f7
[  164.147369]  check_prev_add+0x666/0x700
[  164.147706]  ? print_bfs_bug+0x40/0x40
[  164.148045]  ? trace_hardirqs_on+0xd/0x10
[  164.148389]  lock_commit_crosslock+0x410/0x5a0
[  164.148780]  complete+0x29/0x60
[  164.149064]  cpuhp_thread_fun+0xa1/0x160
[  164.149433]  ? cpuhp_thread_fun+0x2a/0x160
[  164.149814]  smpboot_thread_fn+0x11a/0x1e0
[  164.150193]  kthread+0x152/0x190
[  164.150482]  ? sort_range+0x30/0x30
[  164.150781]  ? kthread_create_on_node+0x40/0x40
[  164.151184]  ret_from_fork+0x2a/0x40