This new trace option "console-latency" will enable the latency tracers to trace the console latencies. Previously this has always been implicitely disabled. I guess this is because they are considered to be well known and unavoidable.
However, for some organizations it may nevertheless be desirable to trace them. Basically, we want to be able to tell that there are latencies in the system under test because someone has incorrectly enabled the serial console. Signed-off-by: Viktor Rosendahl <viktor.rosend...@gmail.com> --- include/linux/irqflags.h | 21 +++++++++++++++++++++ kernel/printk/printk.c | 6 ++++-- kernel/trace/trace.h | 1 + kernel/trace/trace_irqsoff.c | 12 ++++++++++++ 4 files changed, 38 insertions(+), 2 deletions(-) diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h index 21619c92c377..34b0424a32dc 100644 --- a/include/linux/irqflags.h +++ b/include/linux/irqflags.h @@ -68,9 +68,30 @@ do { \ defined(CONFIG_PREEMPT_TRACER) extern void stop_critical_timings(void); extern void start_critical_timings(void); + extern bool console_tracing_disabled(void); + +# define console_stop_critical_timings(flag) \ + do { \ + typecheck(bool, flag); \ + flag = console_tracing_disabled(); \ + if (flag) \ + stop_critical_timings(); \ + } while (0) + +# define console_start_critical_timings(flag) \ + do { \ + typecheck(bool, flag); \ + if (flag) \ + start_critical_timings(); \ + } while (0) + #else # define stop_critical_timings() do { } while (0) # define start_critical_timings() do { } while (0) +# define console_stop_critical_timings(flag) \ + do { typecheck(bool, flag); } while (0) +# define console_start_critical_timings(flag) \ + do { typecheck(bool, flag); } while (0) #endif /* diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 17102fd4c136..46ebba6e5fb9 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -2358,6 +2358,7 @@ void console_unlock(void) static char ext_text[CONSOLE_EXT_LOG_MAX]; static char text[LOG_LINE_MAX + PREFIX_MAX]; unsigned long flags; + bool cflag; bool do_cond_resched, retry; if (console_suspended) { @@ -2458,9 +2459,10 @@ void console_unlock(void) */ console_lock_spinning_enable(); - stop_critical_timings(); /* don't trace print latency */ + /* don't trace print latency if it's disabled */ + console_stop_critical_timings(cflag); call_console_drivers(ext_text, ext_len, text, len); - start_critical_timings(); + console_start_critical_timings(cflag); if (console_lock_spinning_disable_and_check()) { printk_safe_exit_irqrestore(flags); diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h index f95027813296..31cdc2e4c382 100644 --- a/kernel/trace/trace.h +++ b/kernel/trace/trace.h @@ -1257,6 +1257,7 @@ extern int trace_get_user(struct trace_parser *parser, const char __user *ubuf, C(PRINTK_MSGONLY, "printk-msg-only"), \ C(CONTEXT_INFO, "context-info"), /* Print pid/cpu/time */ \ C(LATENCY_FMT, "latency-format"), \ + C(CONSOLE_LATENCY, "console-latency"), \ C(RECORD_CMD, "record-cmd"), \ C(RECORD_TGID, "record-tgid"), \ C(OVERWRITE, "overwrite"), \ diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index a745b0cee5d3..bc02be207a7a 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -456,6 +456,18 @@ void stop_critical_timings(void) EXPORT_SYMBOL_GPL(stop_critical_timings); NOKPROBE_SYMBOL(stop_critical_timings); +bool console_tracing_disabled(void) +{ + struct trace_array *tr = irqsoff_trace; + int pc = preempt_count(); + + if (!preempt_trace(pc) && !irq_trace()) + return false; + + return !(tr->trace_flags & TRACE_ITER_CONSOLE_LATENCY); +} +EXPORT_SYMBOL_GPL(console_tracing_disabled); + #ifdef CONFIG_FUNCTION_TRACER static bool function_enabled; -- 2.17.1