On Mon, Dec 20, 2021 at 12:45 PM Greg Kroah-Hartman
<gregkh@xxxxxxxxxxxxxxxxxxx> wrote:
>
> On Thu, Nov 04, 2021 at 02:17:31PM -0300, wander@xxxxxxxxxx wrote:
> > From: Wander Lairson Costa <wander@xxxxxxxxxx>
> >
> > Note: I am using a small test app + driver located at [0] for the
> > problem description. serco is a driver whose write function dispatches
> > to the serial controller. sertest is a user-mode app that writes n bytes
> > to the serial console using the serco driver.
> >
> > Recently I got a report of a soft lockup while loading a bunch a
> > scsi_debug devices (> 500).
> >
> > While investigating it, I noticed that the serial console throughput
> > (called by the printk code) is way below the configured speed of 115200
> > bps in a HP Proliant DL380 Gen9 server. I was expecting something above
> > 10KB/s, but I got 2.5KB/s. I then built a simple driver [0] to isolate
> > the console from the printk code. Here it is:
> >
> > $ time ./sertest -n 2500 /tmp/serco
> >
> > real 0m0.997s
> > user 0m0.000s
> > sys 0m0.997s
> >
> > With the help of the function tracer, I then noticed the serial
> > controller was taking around 410us seconds to dispatch one single byte:
> >
> > $ trace-cmd record -p function_graph -g serial8250_console_write \
> > ./sertest -n 1 /tmp/serco
> >
> > $ trace-cmd report
> >
> > | serial8250_console_write() {
> > 0.384 us | _raw_spin_lock_irqsave();
> > 1.836 us | io_serial_in();
> > 1.667 us | io_serial_out();
> > | uart_console_write() {
> > | serial8250_console_putchar() {
> > | wait_for_xmitr() {
> > 1.870 us | io_serial_in();
> > 2.238 us | }
> > 1.737 us | io_serial_out();
> > 4.318 us | }
> > 4.675 us | }
> > | wait_for_xmitr() {
> > 1.635 us | io_serial_in();
> > | __const_udelay() {
> > 1.125 us | delay_tsc();
> > 1.429 us | }
> > ...
> > ...
> > ...
> > 1.683 us | io_serial_in();
> > | __const_udelay() {
> > 1.248 us | delay_tsc();
> > 1.486 us | }
> > 1.671 us | io_serial_in();
> > 411.342 us | }
> >
> > In another machine, I measured a throughput of 11.5KB/s, with the serial
> > controller taking between 80-90us to send each byte. That matches the
> > expected throughput for a configuration of 115200 bps.
> >
> > This patch changes the serial8250_console_write to use the 16550 fifo
> > if available. In my artificial benchmark I could get a throughput
> > increase up to 100% in some cases, but in the real case described at the
> > beginning the gain was of about 25%.
> >
> > [0] https://github.com/walac/serial-console-test
> >
> > Signed-off-by: Wander Lairson Costa <wander@xxxxxxxxxx>
> > ---
> > drivers/tty/serial/8250/8250.h | 3 ++
> > drivers/tty/serial/8250/8250_port.c | 63 +++++++++++++++++++++++++----
> > 2 files changed, 59 insertions(+), 7 deletions(-)
> >
> > diff --git a/drivers/tty/serial/8250/8250.h b/drivers/tty/serial/8250/8250.h
> > index 6473361525d1..c711bf118cc1 100644
> > --- a/drivers/tty/serial/8250/8250.h
> > +++ b/drivers/tty/serial/8250/8250.h
> > @@ -83,6 +83,9 @@ struct serial8250_config {
> > #define UART_CAP_MINI BIT(17) /* Mini UART on BCM283X family lacks:
> > * STOP PARITY EPAR SPAR WLEN5 WLEN6
> > */
> > +#define UART_CAP_CWFIFO BIT(18) /* Use the UART Fifo in
> > + * serial8250_console_write
> > + */
>
> Why do you need a new bit? Why can't you just do this change for all
> devices that have a fifo? Why would you _not_ want to do this for all
> devices that have a fifo?
>
The v1 patch [1] didn't have this extra bit. Andy suggested [2] to add
it so we only enabled this new code on tested controllers as a
precaution.
If it doesn't make sense to you, feel free to consider the v1 patch [1].
[1] https://lore.kernel.org/all/20211029201402.428284-1-wander@xxxxxxxxxx/
[2] https://lore.kernel.org/all/CAHp75Vf6DjNcPWpE4Dh3SuzUMJbFQjq1UNCkrCa60uw35SpqKg@xxxxxxxxxxxxxx/
> thanks,
>
> greg k-h
>
