linux/kernel/printk
Marco Elver 701850dc0c printk, tracing: fix console tracepoint
The original intent of the 'console' tracepoint per the commit 9510035849
("printk/tracing: Add console output tracing") had been to "[...] record
any printk messages into the trace, regardless of the current console
loglevel. This can help correlate (existing) printk debugging with other
tracing."

Petr points out [1] that calling trace_console_rcuidle() in
call_console_driver() had been the wrong thing for a while, because
"printk() always used console_trylock() and the message was flushed to
the console only when the trylock succeeded. And it was always deferred
in NMI or when printed via printk_deferred()."

With the commit 09c5ba0aa2 ("printk: add kthread console printers"),
things only got worse, and calls to call_console_driver() no longer
happen with typical printk() calls but always appear deferred [2].

As such, the tracepoint can no longer serve its purpose to clearly
correlate printk() calls and other tracing, as well as breaks usecases
that expect every printk() call to result in a callback of the console
tracepoint. Notably, the KFENCE and KCSAN test suites, which want to
capture console output and assume a printk() immediately gives us a
callback to the console tracepoint.

Fix the console tracepoint by moving it into printk_sprint() [3].

One notable difference is that by moving tracing into printk_sprint(),
the 'text' will no longer include the "header" (loglevel and timestamp),
but only the raw message. Arguably this is less of a problem now that
the console tracepoint happens on the printk() call and isn't delayed.

Link: https://lore.kernel.org/all/Ym+WqKStCg%2FEHfh3@alley/ [1]
Link: https://lore.kernel.org/all/CA+G9fYu2kS0wR4WqMRsj2rePKV9XLgOU1PiXnMvpT+Z=c2ucHA@mail.gmail.com/ [2]
Link: https://lore.kernel.org/all/87fslup9dx.fsf@jogness.linutronix.de/ [3]
Reported-by: Linux Kernel Functional Testing <lkft@linaro.org>
Signed-off-by: Marco Elver <elver@google.com>
Cc: John Ogness <john.ogness@linutronix.de>
Cc: Petr Mladek <pmladek@suse.com>
Reviewed-by: Petr Mladek <pmladek@suse.com>
Acked-by: John Ogness <john.ogness@linutronix.de>
Acked-by: Steven Rostedt (Google) <rostedt@goodmis.org>
Signed-off-by: Petr Mladek <pmladek@suse.com>
Link: https://lore.kernel.org/r/20220503073844.4148944-1-elver@google.com
2022-05-06 10:55:24 +02:00
..
braille.c printk: Replace strncmp() with str_has_prefix() 2019-08-16 09:54:08 +02:00
braille.h License cleanup: add SPDX GPL-2.0 license identifier to files with no license 2017-11-02 11:10:55 +01:00
console_cmdline.h printk: Fix preferred console selection with multiple matches 2020-02-18 09:34:42 +01:00
index.c printk: avoid -Wsometimes-uninitialized warning 2021-10-04 10:28:43 +02:00
internal.h printk: fix build warning when CONFIG_PRINTK=n 2022-01-22 08:33:36 +02:00
Makefile printk: move printk sysctl to printk/sysctl.c 2022-01-22 08:33:35 +02:00
printk_ringbuffer.c printk: ringbuffer: Improve prb_next_seq() performance 2022-01-26 16:00:32 +01:00
printk_ringbuffer.h printk: ringbuffer: Improve prb_next_seq() performance 2022-01-26 16:00:32 +01:00
printk_safe.c printk: remove NMI tracking 2021-07-26 15:09:44 +02:00
printk.c printk, tracing: fix console tracepoint 2022-05-06 10:55:24 +02:00
sysctl.c printk: Fix incorrect __user type in proc_dointvec_minmax_sysadmin() 2022-02-03 11:27:38 -08:00