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

From: Michal Hocko
Date: Mon Oct 07 2019 - 08:44:01 EST


On Mon 07-10-19 08:11:44, Qian Cai wrote:
> On Mon, 2019-10-07 at 13:37 +0200, Michal Hocko wrote:
> > On Mon 07-10-19 07:04:00, Qian Cai wrote:
> > >
> > >
> > > > On Oct 7, 2019, at 4:07 AM, Michal Hocko <mhocko@xxxxxxxxxx> wrote:
> > > >
> > > > I do not think that removing the printk is the right long term solution.
> > > > While I do agree that removing the debugging printk __offline_isolated_pages
> > > > does make sense because it is essentially of a very limited use, this
> > > > doesn't really solve the underlying problem. There are likely other
> > > > printks from zone->lock. It would be much more saner to actually
> > > > disallow consoles to allocate any memory while printk is called from an
> > > > atomic context.
> > >
> > > No, there is only a handful of places called printk() from
> > > zone->lock. It is normal that the callers will quietly process
> > > âstruct zoneâ modification in a short section with zone->lock
> > > held.
> >
> > It is extremely error prone to have any zone->lock vs. printk
> > dependency. I do not want to play an endless whack a mole.
> >
> > > No, it is not about âallocate any memory while printk is called from an
> > > atomic contextâ. It is opposite lock chain from different processors which has the same effect. For example,
> > >
> > > CPU0: CPU1: CPU2:
> > > console_owner
> > > sclp_lock
> > > sclp_lock zone_lock
> > > zone_lock
> > > console_owner
> >
> > Why would sclp_lock ever take a zone->lock (apart from an allocation).
> > So really if sclp_lock is a lock that might be taken from many contexts
> > and generate very subtle lock dependencies then it should better be
> > really careful what it is calling into.
> >
> > In other words you are trying to fix a wrong end of the problem. Fix the
> > console to not allocate or depend on MM by other means.
>
> It looks there are way too many places that could generate those indirect lock
> chains that are hard to eliminate them all. Here is anther example, where it
> has,

Yeah and I strongly suspect they are consoles which are broken and need
to be fixed rathert than the problem papered over.

I do realize how tempting it is to remove all printks from the
zone->lock but do realize that as soon as the allocator starts using any
other locks then we are back to square one and the problem is there
again. We would have to drop _all_ printks from any locked section in
the allocator and I do not think this is viable.

Really, the only way forward is to make these consoles be more careful
of external dependencies.

I am also wondering, this code is there for a long time (or is there any
recent change?), why are we seeing reports only now? Are those consoles
rarely used or you are simply luck to hit those? Or are those really
representing a deadlock? Maybe the lockdep is just confused? I am not
familiar with the code but console_owner_lock is doing some complex
stuff to hand over the context.

> console_owner -> port_lock
> port_lock -> zone_lock
>
> [ÂÂ297.425922] -> #3 (&(&zone->lock)->rlock){-.-.}:
> [ÂÂ297.425925]ÂÂÂÂÂÂÂÂ__lock_acquire+0x5b3/0xb40
> [ÂÂ297.425925]ÂÂÂÂÂÂÂÂlock_acquire+0x126/0x280
> [ÂÂ297.425926]ÂÂÂÂÂÂÂÂ_raw_spin_lock+0x2f/0x40
> [ÂÂ297.425927]ÂÂÂÂÂÂÂÂrmqueue_bulk.constprop.21+0xb6/0x1160
> [ÂÂ297.425928]ÂÂÂÂÂÂÂÂget_page_from_freelist+0x898/0x22c0
> [ÂÂ297.425928]ÂÂÂÂÂÂÂÂ__alloc_pages_nodemask+0x2f3/0x1cd0
> [ÂÂ297.425929]ÂÂÂÂÂÂÂÂalloc_pages_current+0x9c/0x110
> [ÂÂ297.425930]ÂÂÂÂÂÂÂÂallocate_slab+0x4c6/0x19c0
> [ÂÂ297.425931]ÂÂÂÂÂÂÂÂnew_slab+0x46/0x70
> [ÂÂ297.425931]ÂÂÂÂÂÂÂÂ___slab_alloc+0x58b/0x960
> [ÂÂ297.425932]ÂÂÂÂÂÂÂÂ__slab_alloc+0x43/0x70
> [ÂÂ297.425933]ÂÂÂÂÂÂÂÂ__kmalloc+0x3ad/0x4b0
> [ÂÂ297.425933]ÂÂÂÂÂÂÂÂ__tty_buffer_request_room+0x100/0x250
> [ÂÂ297.425934]ÂÂÂÂÂÂÂÂtty_insert_flip_string_fixed_flag+0x67/0x110
> [ÂÂ297.425935]ÂÂÂÂÂÂÂÂpty_write+0xa2/0xf0
> [ÂÂ297.425936]ÂÂÂÂÂÂÂÂn_tty_write+0x36b/0x7b0
> [ÂÂ297.425936]ÂÂÂÂÂÂÂÂtty_write+0x284/0x4c0
> [ÂÂ297.425937]ÂÂÂÂÂÂÂÂ__vfs_write+0x50/0xa0
> [ÂÂ297.425938]ÂÂÂÂÂÂÂÂvfs_write+0x105/0x290
> [ÂÂ297.425939]ÂÂÂÂÂÂÂÂredirected_tty_write+0x6a/0xc0
> [ÂÂ297.425939]ÂÂÂÂÂÂÂÂdo_iter_write+0x248/0x2a0
> [ÂÂ297.425940]ÂÂÂÂÂÂÂÂvfs_writev+0x106/0x1e0
> [ÂÂ297.425941]ÂÂÂÂÂÂÂÂdo_writev+0xd4/0x180
> [ÂÂ297.425941]ÂÂÂÂÂÂÂÂ__x64_sys_writev+0x45/0x50
> [ÂÂ297.425942]ÂÂÂÂÂÂÂÂdo_syscall_64+0xcc/0x76c
> [ÂÂ297.425943]ÂÂÂÂÂÂÂÂentry_SYSCALL_64_after_hwframe+0x49/0xbe

--
Michal Hocko
SUSE Labs