Re: [PATCH v2 1/1] printk: suppress rcu stall warnings caused by slow console devices

[Wander Costa]

On Fri, Nov 12, 2021 at 5:45 AM Petr Mladek <pmladek@xxxxxxxx> wrote:
>
> On Thu 2021-11-11 16:59:04, Wander Lairson Costa wrote:
> > If we have a reasonable large dataset to flush in the printk ring
> > buffer in the presence of a slow console device (like a serial port
> > with a low baud rate configured), the RCU stall detector may report
> > warnings.
> >
> > This patch suppresses RCU stall warnings while flushing the ring buffer
> > to the console.
>
> I have mixed feelings about this patch.
>
> We already touch watchdogs in several situations to avoid this type
> of reports. So, there is a precedent.
>
> On the other hand, it hides a real problem. printk() might cause
> softlockups, livelockups, and even deadlocks. It might really stall
> other processes and CPUs. And the stall report might help to
> understand that the system is not longer responsive because of
> printk().
>
Indeed, other use cases might care about these stalls in printk.
One workaround is to create a syctl to make this feature optional.

> John Ogness is working on the proper solution, handling consoles
> in a kthread. It is not that easy because we need to handle situations
> when kthreads do not work, for example, during early boot, panic(),
> suspend, reboot, kexec. But I believe that we will have it rather
> sooner than later.
>
I gave a try to the print threads patch set and it does solve the
problem. I am not
opposite at all to wait for them to land if it happens in the
foreseeable future.

> A workaround, is to lower console_loglevel and show only the most
> important messages. Sometimes, a reasonable solution is to ratelimit
> repeated messages.
>
> Which brings the question. What is the motivation for this patch,
> please?
>
> Is it motivated by a particular bug report?
> Or does the experience shows that this report causes more harm than
> good?
>
QA has a test case in which they need to load hundreds of SCSI devices,
and they simulate it using the scsi_debug driver:

modprobe scsi_debug virtual_gb=1 add_host=2 num_tgts=600

This dumps a bunch of messages to print and the serial console driver
cannot keep up with the data rate, causing an RCU stall. The stall is reported
in an IRQ context, then the ring buffer flush continues from there,
and then it causes
a soft lockup.

> Best Regards,
> Petr
>

On Fri, Nov 12, 2021 at 5:45 AM Petr Mladek <pmladek@xxxxxxxx> wrote:
>
> On Thu 2021-11-11 16:59:04, Wander Lairson Costa wrote:
> > If we have a reasonable large dataset to flush in the printk ring
> > buffer in the presence of a slow console device (like a serial port
> > with a low baud rate configured), the RCU stall detector may report
> > warnings.
> >
> > This patch suppresses RCU stall warnings while flushing the ring buffer
> > to the console.
>
> I have mixed feelings about this patch.
>
> We already touch watchdogs in several situations to avoid this type
> of reports. So, there is a precedent.
>
> On the other hand, it hides a real problem. printk() might cause
> softlockups, livelockups, and even deadlocks. It might really stall
> other processes and CPUs. And the stall report might help to
> understand that the system is not longer responsive because of
> printk().
>
> John Ogness is working on the proper solution, handling consoles
> in a kthread. It is not that easy because we need to handle situations
> when kthreads do not work, for example, during early boot, panic(),
> suspend, reboot, kexec. But I believe that we will have it rather
> sooner than later.
>
> A workaround, is to lower console_loglevel and show only the most
> important messages. Sometimes, a reasonable solution is to ratelimit
> repeated messages.
>
> Which brings the question. What is the motivation for this patch,
> please?
>
> Is it motivated by a particular bug report?
> Or does the experience shows that this report causes more harm than
> good?
>
> Best Regards,
> Petr
>