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.
While investigating a bug in the RHEL kernel, I noticed that the serial
console throughput is way below the configured speed of 115200 bps in
a HP Proliant DL380 Gen9. I was expecting something above 10KB/s, but
I got 2.5KB/s.
$ 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 benchmarks I got around 25% improvement in the slow
machine, and no performance penalty in the fast machine.
Signed-off-by: Wander Lairson Costa <wander@redhat.com>
Link: https://lore.kernel.org/r/20211222112831.1968392-2-wander@redhat.com
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
5021d709b3