Re: [PATCH] serial: core: prevent softlockups on slow consoles

From: Vitaly Kuznetsov
Date: Wed Sep 02 2015 - 12:10:04 EST


Peter Hurley <peter@xxxxxxxxxxxxxxxxxx> writes:

> Hi Vitaly,
>
> On 08/31/2015 10:34 AM, Vitaly Kuznetsov wrote:
>> Hyper-V serial port is very slow on multi-vCPU guest
>
> How slow and why?
>

Not sure why, but here is a trace:

1) | serial8250_console_putchar() {
1) | wait_for_xmitr() {
1) ! 848.371 us | io_serial_in();
1) ! 849.815 us | }
1) ! 832.455 us | io_serial_out();
1) ! 1684.686 us | }

This is just one char. In case we have a couple hundred lines in output
buffer we can easily spend several seconds there. + virtualization
specifics kicks in and our vCPU doing the output can be preempted in
favor of other guest.

>> this causes
>> soflockups on intensive console writes. Touch nmi watchdog after putting
>> every char on port to avoid the issue for all serial drivers, the overhead
>> should be small.
>
> Once per message should be sufficient.

Sure, but we don't have messages in uart_console_write(), we output the
whole buffer here. Or do you mean just moving touch_nmi_watchdog() call
under the if (*s == '\n') clause?
>
> Although I have no objection to adding this to uart_console_write() for
> all serial drivers, please remove it from drivers that already do this.
>

Not sure we can remove it from wait_for_xmitr() in 8250_core.c and
pch_uart.c as in UPF_CONS_FLOW case we wait up to 1 second there -
especially if we start calling touch_nmi_watchdog() once per line of
text in uart_console_write().

touch_nmi_watchdog() call from pch_console_write(),
lpc32xx_hsuart_console_write() and serial8250_console_write() can
probably be removed (we'll be calling it after printing first line).

>> This is just a part of the fix: serial8250_console_write() disables irqs
>> for all its execution time
>
> Interrupts are disabled by printk()/console_unlock() right now anyway;
> very thorny problem to fix with lots of complications.

Probably, but I think we can have some sort of an output limit (size or
time based) and print our buffer partialy rescheduling next print in
case there are some leftovers. But I haven't looked into the code yet...

>
> Regards,
> Peter Hurley
>
>> (which on such slow consoles can be dozens of
>> seconds), it should be possible to observe devices being stuck on this
>> CPU. We need to find a better way, e.g. do output in batches enabling irqs
>> in between.
>>
>> Signed-off-by: Vitaly Kuznetsov <vkuznets@xxxxxxxxxx>
>> ---
>> drivers/tty/serial/serial_core.c | 3 ++-
>> 1 file changed, 2 insertions(+), 1 deletion(-)
>>
>> diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
>> index f368520..cc05785 100644
>> --- a/drivers/tty/serial/serial_core.c
>> +++ b/drivers/tty/serial/serial_core.c
>> @@ -33,7 +33,7 @@
>> #include <linux/serial.h> /* for serial_state and serial_icounter_struct */
>> #include <linux/serial_core.h>
>> #include <linux/delay.h>
>> -#include <linux/mutex.h>
>
> Why isn't this required anymore?
>

Because I screwed up, it is an unintentional change :-( Sorry. But as I
got no errors while compiling maybe it isn't needed...

>> +#include <linux/nmi.h>
>>
>> #include <asm/irq.h>
>> #include <asm/uaccess.h>
>> @@ -1792,6 +1792,7 @@ void uart_console_write(struct uart_port *port, const char *s,
>> if (*s == '\n')
>> putchar(port, '\r');
>> putchar(port, *s);
>> + touch_nmi_watchdog();
>> }
>> }
>> EXPORT_SYMBOL_GPL(uart_console_write);
>>

--
Vitaly
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/