Re: [ Linux 4.4 stable ] missing 'printk: set may_schedule for some of console_trylock() callers'

[Petr Mladek]

On Wed 2017-07-26 01:33:25, Sergey Senozhatsky wrote:
> Hello,
> 
> On (07/25/17 06:57), Greg KH wrote:
> > On Tue, Jul 25, 2017 at 10:28:16AM +0200, Michael Wang wrote:
> > > Hi, greg k-h
> > > 
> > > During our testing with 4.4.73 we got soft lockup like:
> > > 
> > >  NMI watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [systemd-udevd:856]
> > >  ...
> > >  Call Trace:
> > >   [<ffffffff8109d139>] vprintk_emit+0x319/0x4a0
> > >   [<ffffffff8112182d>] printk_emit+0x33/0x3b
> > >   [<ffffffff812f9e9c>] ? simple_strtoull+0x2c/0x50 
> > >   [<ffffffff8109d39a>] devkmsg_write+0xaa/0x100
> > >   [<ffffffff8109d2f0>] ? vprintk+0x30/0x30
> > >   [<ffffffff811915f2>] do_readv_writev+0x1c2/0x270 
> > >   [<ffffffff8117899d>] ? kmem_cache_free+0x7d/0x1a0
> > >   [<ffffffff81191729>] vfs_writev+0x39/0x50
> > >   [<ffffffff8119240a>] SyS_writev+0x4a/0xd0
> > >   [<ffffffff8158bc97>] entry_SYSCALL_64_fastpath+0x12/0x6a
> > > 
> > > Currently in 4.4 the console_unlock() called by vprintk_emit() is with
> > > preemption disabled, so the cond_resched is not working, and soft lockup
> > > appear if it take too much time on writing data into every console.
> > > 
> > > We found the upstream patch:
> > >   commit 6b97a20d3a79 printk: set may_schedule for some of console_trylock() callers
> > > 
> > > which should have addressed this issue, but not included in the latest 4.4.78 stable
> > > yet, is there any plan on backport it in future?
> 
> returning back to the patch,
> 
> there are two things related to it I can quickly think of:
> 
> 1) the patch needs a fix-up commit 257ab443118bffc ("printk: Correctly
>    handle preemption in console_unlock()")
> 
> 2) it may affect users
>    this is a bit weird... but, in fact, console_unlock() must always
>    run with disabled preemption. otherwise, we schedule with the
>    console_sem locked, which is risky and pointless. executing
>    console_unlock() with preemption disabled is, obviously, dangerous,
>    that's why consle_unlock() should stop doing the endless loop and
>    instead must offload (after some time) the printing duty to another
>    kthread/CPU.
> 
>    more closer to the point,
>    we've got reports that in some cases due to additional points of
>    scheduling in console_unlock() doing massive print outs (like showing
>    backtraces of all tasks, or OOM dump) now takes more time (it really
>    depends on the conditions).
> 
> 
> so the patch addresses some of trivial lockup cases and in general not
> that bad, but at the same time it's not a complete solution and it has
> some side effects.

Also note that the patch has an effect only when the kernel is built
with PREEMPT_COUNT enabled. Otherwise, printk() is not able to detect
preemtible context and skips the extra cond_resched().

The rest was explained by Sergey. In short, the proper solution is to
allow offloading from console_unlock(). Unfortunately, it is not easy
to do it a way that would be acceptable in all situations. But I hope
that we are getting close.

Best Regards,
Petr