Re: [PATCH v2] mm/page_isolation: fix a deadlock with printk()

From: Qian Cai
Date: Wed Oct 09 2019 - 11:25:44 EST


On Wed, 2019-10-09 at 15:56 +0200, Peter Oberparleiter wrote:
> On 08.10.2019 18:08, Qian Cai wrote:
> > On Tue, 2019-10-08 at 14:56 +0200, Christian Borntraeger wrote:
> > > Adding Peter Oberparleiter.
> > > Peter, can you have a look?
> > >
> > > On 08.10.19 10:27, Michal Hocko wrote:
> > > > On Tue 08-10-19 09:43:57, Petr Mladek wrote:
> > > > > On Mon 2019-10-07 16:49:37, Michal Hocko wrote:
> > > > > > [Cc s390 maintainers - the lockdep is http://lkml.kernel.org/r/1570228005-24979-1-git-send-email-cai@xxxxxx
> > > > > > Petr has explained it is a false positive
> > > > > > http://lkml.kernel.org/r/20191007143002.l37bt2lzqtnqjqxu@xxxxxxxxxxxxxxx]
> > > > > > On Mon 07-10-19 16:30:02, Petr Mladek wrote:
> > > > > > [...]
> > > > > > > I believe that it cannot really happen because:
> > > > > > >
> > > > > > > static int __init
> > > > > > > sclp_console_init(void)
> > > > > > > {
> > > > > > > [...]
> > > > > > > rc = sclp_rw_init();
> > > > > > > [...]
> > > > > > > register_console(&sclp_console);
> > > > > > > return 0;
> > > > > > > }
> > > > > > >
> > > > > > > sclp_rw_init() is called before register_console(). And
> > > > > > > console_unlock() will never call sclp_console_write() before
> > > > > > > the console is registered.
> > > > > > >
> > > > > > > AFAIK, lockdep only compares existing chain of locks. It does
> > > > > > > not know about console registration that would make some
> > > > > > > code paths mutually exclusive.
> > > > > > >
> > > > > > > I believe that it is a false positive. I do not know how to
> > > > > > > avoid this lockdep report. I hope that it will disappear
> > > > > > > by deferring all printk() calls rather soon.
> > > > > >
> > > > > > Thanks a lot for looking into this Petr. I have also checked the code
> > > > > > and I really fail to see why the allocation has to be done under the
> > > > > > lock in the first place. sclp_read_sccb and sclp_init_sccb are global
> > > > > > variables but I strongly suspect that they need a synchronization during
> > > > > > early init, callbacks are registered only later IIUC:
> > > > >
> > > > > Good idea. It would work when the init function is called only once.
> > > > > But see below.
> > > > >
> > > > > > diff --git a/drivers/s390/char/sclp.c b/drivers/s390/char/sclp.c
> > > > > > index d2ab3f07c008..4b1c033e3255 100644
> > > > > > --- a/drivers/s390/char/sclp.c
> > > > > > +++ b/drivers/s390/char/sclp.c
> > > > > > @@ -1169,13 +1169,13 @@ sclp_init(void)
> > > > > > unsigned long flags;
> > > > > > int rc = 0;
> > > > > >
> > > > > > + sclp_read_sccb = (void *) __get_free_page(GFP_ATOMIC | GFP_DMA);
> > > > > > + sclp_init_sccb = (void *) __get_free_page(GFP_ATOMIC | GFP_DMA);
> > > > > > spin_lock_irqsave(&sclp_lock, flags);
> > > > > > /* Check for previous or running initialization */
> > > > > > if (sclp_init_state != sclp_init_state_uninitialized)
> > > > > > goto fail_unlock;
> > > > >
> > > > > It seems that sclp_init() could be called several times in parallel.
> > > > > I see it called from sclp_register() and sclp_initcall().
> > > >
> > > > Interesting. Something for s390 people to answer I guess.
> > > > Anyway, this should be quite trivial to workaround by a cmpxch or alike.
> > > >
> >
> > The above fix is simply insufficient,
> >
> > 00: [ÂÂÂÂ3.654307] WARNING: possible circular locking dependency detectedÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654309] 5.4.0-rc1-next-20191004+ #4 Not taintedÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654311] ------------------------------------------------------ÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654313] swapper/0/1 is trying to acquire lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654314] 00000000553f3fb8 (sclp_lock){-.-.}, at: sclp_add_request+0x34
> > 00: /0x308ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654320]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654322] but task is already holding lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654323] 00000000550c9fc0 (console_owner){....}, at: console_unlock+0x
> > 00: 328/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654329]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> > 00: [ÂÂÂÂ3.654331] which lock already depends on the new lock.ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
>
> I can confirm that both this lockdep warning as well as the original one
> are both false positives: lockdep warns that code in sclp_init could
> trigger a deadlock via the chain
>
> sclp_lock --> &(&zone->lock)->rlock --> console_owner
>
> but
>
> a) before sclp_init successfully completes, register_console is not
> called, so there is no connection between console_owner -> sclp_lock
> b) after sclp_init completed, it won't be called again, so any
> dependency that requires a call-chain including sclp_init is
> impossible to achieve
>
> Apparently lockdep cannot determine that sclp_init won't be called again.
> I'm attaching a patch that moves sclp_init to __init so that lockdep has
> a chance of knowing that the function will be gone after init.
>
> This patch is intended for testing only though, to see if there are other
> paths to similar possible deadlocks. I still need to decide if its worth
> changing the code to remove false positives in lockdep.
>
> A generic solution would be preferable from my point of view though,
> because otherwise each console driver owner would need to ensure that any
> lock taken in their console.write implementation is never held while
> memory is allocated/released.
>
> diff --git a/drivers/s390/char/sclp.c b/drivers/s390/char/sclp.c
> index d2ab3f07c008..13219e43d488 100644
> --- a/drivers/s390/char/sclp.c
> +++ b/drivers/s390/char/sclp.c
> @@ -140,7 +140,6 @@ static void sclp_request_timeout(bool force_restart);
> static void sclp_process_queue(void);
> static void __sclp_make_read_req(void);
> static int sclp_init_mask(int calculate);
> -static int sclp_init(void);
>
> static void
> __sclp_queue_read_req(void)
> @@ -670,7 +669,8 @@ __sclp_get_mask(sccb_mask_t *receive_mask, sccb_mask_t *send_mask)
> }
> }
>
> -/* Register event listener. Return 0 on success, non-zero otherwise. */
> +/* Register event listener. Return 0 on success, non-zero otherwise. Early
> + * callers (<= arch_initcall) must call sclp_init() first. */
> int
> sclp_register(struct sclp_register *reg)
> {
> @@ -679,9 +679,8 @@ sclp_register(struct sclp_register *reg)
> sccb_mask_t send_mask;
> int rc;
>
> - rc = sclp_init();
> - if (rc)
> - return rc;
> + if (sclp_init_state != sclp_init_state_initialized)
> + return -EINVAL;
> spin_lock_irqsave(&sclp_lock, flags);
> /* Check event mask for collisions */
> __sclp_get_mask(&receive_mask, &send_mask);
> @@ -1163,8 +1162,7 @@ static struct platform_device *sclp_pdev;
>
> /* Initialize SCLP driver. Return zero if driver is operational, non-zero
> * otherwise. */
> -static int
> -sclp_init(void)
> +int __init sclp_init(void)
> {
> unsigned long flags;
> int rc = 0;
> diff --git a/drivers/s390/char/sclp.h b/drivers/s390/char/sclp.h
> index 196333013e54..463660261379 100644
> --- a/drivers/s390/char/sclp.h
> +++ b/drivers/s390/char/sclp.h
> @@ -296,6 +296,7 @@ struct sclp_register {
> };
>
> /* externals from sclp.c */
> +int __init sclp_init(void);
> int sclp_add_request(struct sclp_req *req);
> void sclp_sync_wait(void);
> int sclp_register(struct sclp_register *reg);
> diff --git a/drivers/s390/char/sclp_con.c b/drivers/s390/char/sclp_con.c
> index 8966a1c1b548..a08ef2c8379e 100644
> --- a/drivers/s390/char/sclp_con.c
> +++ b/drivers/s390/char/sclp_con.c
> @@ -319,6 +319,9 @@ sclp_console_init(void)
> /* SCLP consoles are handled together */
> if (!(CONSOLE_IS_SCLP || CONSOLE_IS_VT220))
> return 0;
> + rc = sclp_init();
> + if (rc)
> + return rc;
> rc = sclp_rw_init();
> if (rc)
> return rc;
> diff --git a/drivers/s390/char/sclp_vt220.c b/drivers/s390/char/sclp_vt220.c
> index 3f9a6ef650fa..28b23e22248b 100644
> --- a/drivers/s390/char/sclp_vt220.c
> +++ b/drivers/s390/char/sclp_vt220.c
> @@ -694,6 +694,11 @@ static int __init __sclp_vt220_init(int num_pages)
> sclp_vt220_init_count++;
> if (sclp_vt220_init_count != 1)
> return 0;
> + rc = sclp_init();
> + if (rc) {
> + sclp_vt220_init_count--;
> + return rc;
> + }
> spin_lock_init(&sclp_vt220_lock);
> INIT_LIST_HEAD(&sclp_vt220_empty);
> INIT_LIST_HEAD(&sclp_vt220_outqueue);

Unfortunately, the patch does not help here. I guess the lockdep does not really
differential __init or not because those places can still have a chance to
deadlock in general after interrupt and preempt are enabled even during the boot
but it is just not the case here.

00: [ÂÂÂÂ2.812088] WARNING: possible circular locking dependency detectedÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812090] 5.4.0-rc2-next-20191009+ #4 Not taintedÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812092] ------------------------------------------------------ÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812094] swapper/0/1 is trying to acquire lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812095] 0000000036a07ed8 (sclp_lock){-.-.}, at: sclp_add_request+0x34
00: /0x308ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812102]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812103] but task is already holding lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812105] 00000000366d9ec0 (console_owner){....}, at: console_unlock+0x
00: 328/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812111]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812113] which lock already depends on the new lock.ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812114]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812115]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812117] the existing dependency chain (in reverse order) is:ÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812118]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812120] -> #2 (console_owner){....}:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812126]ÂÂÂÂÂÂÂÂlock_acquire+0x21a/0x468ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812127]ÂÂÂÂÂÂÂÂconsole_unlock+0x3a6/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812129]ÂÂÂÂÂÂÂÂvprintk_emit+0x184/0x3c8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812131]ÂÂÂÂÂÂÂÂvprintk_default+0x44/0x50ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812132]ÂÂÂÂÂÂÂÂprintk+0xa8/0xc0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812134]ÂÂÂÂÂÂÂÂget_random_u64+0x40/0x108ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812135]ÂÂÂÂÂÂÂÂadd_to_free_area_random+0x188/0x1c0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812137]ÂÂÂÂÂÂÂÂfree_one_page+0x72/0x128ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812139]ÂÂÂÂÂÂÂÂ__free_pages_ok+0x51c/0xc90ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812141]ÂÂÂÂÂÂÂÂmemblock_free_all+0x30a/0x3b0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812142]ÂÂÂÂÂÂÂÂmem_init+0x84/0x200ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812144]ÂÂÂÂÂÂÂÂstart_kernel+0x384/0x6a0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812145]ÂÂÂÂÂÂÂÂstartup_continue+0x70/0xd0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812146]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812147] -> #1 (&(&zone->lock)->rlock){....}:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812154]ÂÂÂÂÂÂÂÂlock_acquire+0x21a/0x468ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812155]ÂÂÂÂÂÂÂÂ_raw_spin_lock+0x54/0x68ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812157]ÂÂÂÂÂÂÂÂget_page_from_freelist+0x8b6/0x2d28ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812159]ÂÂÂÂÂÂÂÂ__alloc_pages_nodemask+0x246/0x658ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812161]ÂÂÂÂÂÂÂÂ__get_free_pages+0x34/0x78ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812162]ÂÂÂÂÂÂÂÂsclp_init+0xce/0x640ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812164]ÂÂÂÂÂÂÂÂsclp_console_init+0x4e/0x1c0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812166]ÂÂÂÂÂÂÂÂconsole_init+0x2c8/0x410ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812168]ÂÂÂÂÂÂÂÂstart_kernel+0x530/0x6a0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812169]ÂÂÂÂÂÂÂÂstartup_continue+0x70/0xd0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812170]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812171] -> #0 (sclp_lock){-.-.}:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812177]ÂÂÂÂÂÂÂÂcheck_noncircular+0x338/0x3e0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812179]ÂÂÂÂÂÂÂÂ__lock_acquire+0x1e66/0x2d88ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812181]ÂÂÂÂÂÂÂÂlock_acquire+0x21a/0x468ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812182]ÂÂÂÂÂÂÂÂ_raw_spin_lock_irqsave+0xcc/0xe8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812184]ÂÂÂÂÂÂÂÂsclp_add_request+0x34/0x308ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812186]ÂÂÂÂÂÂÂÂsclp_conbuf_emit+0x100/0x138ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812187]ÂÂÂÂÂÂÂÂsclp_console_write+0x96/0x3b8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812189]ÂÂÂÂÂÂÂÂconsole_unlock+0x6dc/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812191]ÂÂÂÂÂÂÂÂvprintk_emit+0x184/0x3c8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812192]ÂÂÂÂÂÂÂÂvprintk_default+0x44/0x50ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812194]ÂÂÂÂÂÂÂÂprintk+0xa8/0xc0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812196]ÂÂÂÂÂÂÂÂiommu_debugfs_setup+0xf2/0x108ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812198]ÂÂÂÂÂÂÂÂiommu_init+0x6c/0x78ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812200]ÂÂÂÂÂÂÂÂdo_one_initcall+0x162/0x680ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812201]ÂÂÂÂÂÂÂÂkernel_init_freeable+0x4e8/0x5a8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812203]ÂÂÂÂÂÂÂÂkernel_init+0x2a/0x188ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812205]ÂÂÂÂÂÂÂÂret_from_fork+0x30/0x34ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812206]ÂÂÂÂÂÂÂÂkernel_thread_starter+0x0/0xcÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812207]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812209] other info that might help us debug this:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812210]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812211] Chain exists of:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812212]ÂÂÂsclp_lock --> &(&zone->lock)->rlock --> console_ownerÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812221]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812222]ÂÂPossible unsafe locking scenario:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812223]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812225]ÂÂÂÂÂÂÂÂCPU0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂCPU1ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812227]ÂÂÂÂÂÂÂÂ----ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ----ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812228]ÂÂÂlock(console_owner);ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812232]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(&(&zone->lock)->rlock);ÂÂ
00: [ÂÂÂÂ2.812236]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(console_owner);ÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812239]ÂÂÂlock(sclp_lock);ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812243]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812244]ÂÂ*** DEADLOCK ***ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812245]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812247] 2 locks held by swapper/0/1:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812248]ÂÂ#0: 00000000366da100 (console_lock){+.+.}, at: vprintk_emit+
00: 0x178/0x3c8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812255]ÂÂ#1: 00000000366d9ec0 (console_owner){....}, at: console_unlo
00: ck+0x328/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812262]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812264] stack backtrace:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812266] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.4.0-rc2-next-2019
00: 1009+ #4ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812268] Hardware name: IBM 2964 N96 400 (z/VM 6.4.0)ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812269] Call Trace:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812271] ([<000000003591e230>] show_stack+0x110/0x1b0)ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812273]ÂÂ[<00000000361e025e>] dump_stack+0x126/0x178ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812276]ÂÂ[<0000000035a149b8>] check_noncircular+0x338/0x3e0ÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812277]ÂÂ[<0000000035a1a9a6>] __lock_acquire+0x1e66/0x2d88ÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812279]ÂÂ[<0000000035a17cc2>] lock_acquire+0x21a/0x468ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812281]ÂÂ[<000000003621bce4>] _raw_spin_lock_irqsave+0xcc/0xe8ÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812283]ÂÂ[<0000000035ff534c>] sclp_add_request+0x34/0x308ÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812285]ÂÂ[<0000000035ffc6b8>] sclp_conbuf_emit+0x100/0x138ÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812287]ÂÂ[<0000000035ffc7d6>] sclp_console_write+0x96/0x3b8ÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812289]ÂÂ[<0000000035a2b4fc>] console_unlock+0x6dc/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812291]ÂÂ[<0000000035a2dd0c>] vprintk_emit+0x184/0x3c8ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812293]ÂÂ[<0000000035a2df94>] vprintk_default+0x44/0x50ÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812295]ÂÂ[<0000000035a2ea40>] printk+0xa8/0xc0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812297]ÂÂ[<0000000035f4e5ea>] iommu_debugfs_setup+0xf2/0x108ÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812299]ÂÂ[<0000000036b90554>] iommu_init+0x6c/0x78ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812301]ÂÂ[<0000000035900fda>] do_one_initcall+0x162/0x680ÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812303]ÂÂ[<0000000036b4f9f0>] kernel_init_freeable+0x4e8/0x5a8ÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812305]ÂÂ[<0000000036206bda>] kernel_init+0x2a/0x188ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812306]ÂÂ[<000000003621cfdc>] ret_from_fork+0x30/0x34ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812308]ÂÂ[<000000003621cfe0>] kernel_thread_starter+0x0/0xcÂÂÂÂÂÂÂÂÂÂ
00: [ÂÂÂÂ2.812310] INFO: lockdep is turned off.