Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Message-ID: <1570561573.5576.307.camel@lca.pw>
Subject: Re: [PATCH v2] mm/page_isolation: fix a deadlock with printk()
From:   Qian Cai <cai@lca.pw>
To:     Michal Hocko <mhocko@kernel.org>
Cc:     Christian Borntraeger <borntraeger@de.ibm.com>,
        Petr Mladek <pmladek@suse.com>,
        Peter Oberparleiter <oberpar@linux.ibm.com>,
        akpm@linux-foundation.org, sergey.senozhatsky.work@gmail.com,
        rostedt@goodmis.org, peterz@infradead.org, linux-mm@kvack.org,
        john.ogness@linutronix.de, david@redhat.com,
        linux-kernel@vger.kernel.org,
        Heiko Carstens <heiko.carstens@de.ibm.com>,
        Vasily Gorbik <gor@linux.ibm.com>
Date:   Tue, 08 Oct 2019 15:06:13 -0400
In-Reply-To: <20191008183525.GQ6681@dhcp22.suse.cz>
References: <1570228005-24979-1-git-send-email-cai@lca.pw>
         <20191007143002.l37bt2lzqtnqjqxu@pathway.suse.cz>
         <20191007144937.GO2381@dhcp22.suse.cz>
         <20191008074357.f33f6pbs4cw5majk@pathway.suse.cz>
         <20191008082752.GB6681@dhcp22.suse.cz>
         <aefe7f75-b0ec-9e99-a77e-87324edb24e0@de.ibm.com>
         <1570550917.5576.303.camel@lca.pw> <20191008183525.GQ6681@dhcp22.suse.cz>
Content-Type: text/plain; charset="UTF-8"
Mime-Version: 1.0
Content-Transfer-Encoding: 8bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Tue, 2019-10-08 at 20:35 +0200, Michal Hocko wrote:
> On Tue 08-10-19 12:08:37, 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@lca.pw
> > > > > >  Petr has explained it is a false positive
> > > > > >  http://lkml.kernel.org/r/20191007143002.l37bt2lzqtnqjqxu@pathway.suse.cz]
> > > > > > 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,
> 
> Isn't this yet another init time lockdep false possitive?

Again, this is not 100% false positive for sure yet.

> 
> > 00: [    3.654337] -> #3 (console_owner){....}:                                 
> > 00: [    3.654343]        lock_acquire+0x21a/0x468                              
> > 00: [    3.654345]        console_unlock+0x3a6/0xa30                            
> > 00: [    3.654346]        vprintk_emit+0x184/0x3c8                              
> > 00: [    3.654348]        vprintk_default+0x44/0x50                             
> > 00: [    3.654349]        printk+0xa8/0xc0                                      
> > 00: [    3.654351]        get_random_u64+0x40/0x108                             
> > 00: [    3.654360]        add_to_free_area_random+0x188/0x1c0                   
> > 00: [    3.654364]        free_one_page+0x72/0x128                              
> > 00: [    3.654366]        __free_pages_ok+0x51c/0xca0                           
> > 00: [    3.654368]        memblock_free_all+0x30a/0x3b0                         
> > 00: [    3.654370]        mem_init+0x84/0x200                                   
> > 00: [    3.654371]        start_kernel+0x384/0x6a0                              
> > 00: [    3.654373]        startup_continue+0x70/0xd0                            
> 
> This one is actually a nice example why trying to get printk out of the
> zone->lock is simply not viable. This one is likely a printk to warn
> that the random pool is not fully intiailized. Just because the
> allocator tries to randomize the initial free memory pool. You are not
> going to remove that printk, right?

Well, Sergey had a patch to convert that one to printk_deferred(), but even with
his patch, it will still trigger the lockdep splat here because the lock
dependency between zone->lock --> console_owner is still there from memory
offline.

> 
> I fully agree that this class of lockdep splats are annoying especially
> when they make the lockdep unusable but please discuss this with lockdep
> maintainers and try to find some solution rather than go and try to
> workaround the problem all over the place. If there are places that
> would result in a cleaner code then go for it but please do not make the
> code worse just because of a non existent problem flagged by a false
> positive.

It makes me wonder what make you think it is a false positive for sure.