Re: tty/hvc: possible irq lock inversion dependency detected

2017-03-29 Thread Michael Ellerman 
Denis Kirjanov  writes:

> Hi,
>
> Ok, now we have a new locking issue with interrupts which I found on my P8 
> box.
> I haven't found where we take the console_lock, only in hvc_remove.
>
> BTW, Ben, looks like it's a bug in hvc_remove:
> we take spin_lock and then semaphore lock.

Yeah that does look bogus:

spin_lock_irqsave(>lock, flags);
if (hp->index < MAX_NR_HVC_CONSOLES) {
console_lock();
vtermnos[hp->index] = -1;
cons_ops[hp->index] = NULL;
console_unlock();
}


The console lock is a bit "special", but I don't think it's *that* special.

cheers

tty/hvc: possible irq lock inversion dependency detected

2017-03-27 Thread Denis Kirjanov 
Hi,

Ok, now we have a new locking issue with interrupts which I found on my P8 box.
I haven't found where we take the console_lock, only in hvc_remove.

BTW, Ben, looks like it's a bug in hvc_remove:
we take spin_lock and then semaphore lock.

[178327.461954] =
[178327.462043] [ INFO: possible irq lock inversion dependency detected ]
[178327.462105] 4.11.0-rc3-00022-gc7e790c #1 Not tainted
[178327.462154] -
[178327.462216] swapper/0/0 just changed the state of lock:
[178327.462266]  (&(>lock)->rlock){-.}, at:
[] .hvc_poll+0x4c/0x380
[178327.462348] but this lock took another, HARDIRQ-unsafe lock in the past:
[178327.462409]  (console_lock){+.+.+.}
[178327.462414]

and interrupts could create inverse lock ordering between them.

[178327.462559]
other info that might help us debug this:
[178327.462621]  Possible interrupt unsafe locking scenario:

[178327.462682]CPU0CPU1
[178327.462731]
[178327.462780]   lock(console_lock);
[178327.462820]local_irq_disable();
[178327.462880]lock(&(>lock)->rlock);
[178327.462945]lock(console_lock);
[178327.463008]   
[178327.463034] lock(&(>lock)->rlock);
[178327.463074]
 *** DEADLOCK ***

[178327.463137] no locks held by swapper/0/0.
[178327.463174]
the shortest dependencies between 2nd lock and 1st lock:
[178327.463248]  -> (console_lock){+.+.+.} ops: 6747393622016 {
[178327.463316] HARDIRQ-ON-W at:
[178327.463359]   .lock_acquire+0xf0/0x340
[178327.463410]   .console_lock+0x60/0xa0
[178327.463463]   .con_init+0x24/0x2d0
[178327.463514]   .console_init+0x4c/0x6c
[178327.463566]   .start_kernel+0x3d4/0x584
[178327.463629]   start_here_common+0x1c/0x520
[178327.463690] SOFTIRQ-ON-W at:
[178327.463731]   .lock_acquire+0xf0/0x340
[178327.463782]   .console_lock+0x60/0xa0
[178327.463833]   .con_init+0x24/0x2d0
[178327.463884]   .console_init+0x4c/0x6c
[178327.463935]   .start_kernel+0x3d4/0x584
[178327.463998]   start_here_common+0x1c/0x520
[178327.464059] RECLAIM_FS-ON-W at:
[178327.464100]  .lockdep_trace_alloc+0xa8/0x180
[178327.464163]  .kmem_cache_alloc_trace+0x5c/0x4f0
[178327.464227]  .device_create_groups_vargs+0x74/0x1b0
[178327.464301]  .device_create+0x2c/0x40
[178327.464364]  .fb_console_init+0x64/0x1cc
[178327.464426]  .do_one_initcall+0x5c/0x1c0
[178327.464489]  .kernel_init_freeable+0x2d4/0x3ac
[178327.464551]  .kernel_init+0x1c/0x130
[178327.464614]  .ret_from_kernel_thread+0x58/0x70
[178327.464674] INITIAL USE at:
[178327.464715]  0x1a492c0
[178327.464754]  0x1a58870
[178327.464792]  0x1a5b94c
[178327.464830]  0x2781bcc
[178327.464869]  0x2782108
[178327.464907]  0x191b448
[178327.464945]   }
[178327.464973]   ... key  at: []
console_lock_dep_map+0x0/0x30
[178327.465046]   ... acquired at:
[178327.465085].console_lock+0x60/0xa0
[178327.465124].hvc_remove+0xa8/0xf0
[178327.465163].hvc_opal_remove+0x28/0x90
[178327.465201].platform_drv_remove+0x44/0x80
[178327.465251].driver_probe_device+0x144/0x4d0
[178327.465302].__driver_attach+0x10c/0x110
[178327.465352].bus_for_each_dev+0x84/0xf0
[178327.465391].driver_attach+0x24/0x40
[178327.465429].bus_add_driver+0x278/0x300
[178327.465468].driver_register+0x8c/0x170
[178327.465507].__platform_driver_register+0x48/0x60
[178327.465557].hvc_opal_init+0x30/0x4c
[178327.465596].do_one_initcall+0x5c/0x1c0
[178327.465635].kernel_init_freeable+0x2d4/0x3ac
[178327.465685].kernel_init+0x1c/0x130
[178327.465725].ret_from_kernel_thread+0x58/0x70

[178327.465799] -> (&(>lock)->rlock){-.} ops: 8160437862400 {
[178327.465867]IN-HARDIRQ-W at:
[178327.465908] .lock_acquire+0xf0/0x340
[178327.465960] ._raw_spin_lock_irqsave+0x68/0xd0
[178327.466022] .hvc_poll+0x4c/0x380
[178327.466074] .hvc_handle_interrupt+0x14/0x40
[178327.466136] .__handle_irq_event_percpu+0xe4/0x630
[178327.466199] .handle_irq_event_percpu+0x28/0x80
[178327.466262] .handle_irq_event+0x54/0xa0
[178327.466324] .handle_level_irq+0xf8/0x1f0
[178327.466387]