On Wed, Oct 09, 2019 at 12:08:24AM +0200, Viktor Rosendahl (BMW) wrote: > 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 (BMW) <viktor.rosend...@gmail.com> > --- > include/linux/irqflags.h | 22 ++++++++++++++++++++++ > kernel/printk/printk.c | 6 ++++-- > kernel/trace/trace.h | 1 + > kernel/trace/trace_irqsoff.c | 18 ++++++++++++++++++ > 4 files changed, 45 insertions(+), 2 deletions(-) > > diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h > index 21619c92c377..3de891723331 100644 > --- a/include/linux/irqflags.h > +++ b/include/linux/irqflags.h > @@ -13,6 +13,7 @@ > #define _LINUX_TRACE_IRQFLAGS_H > > #include <linux/typecheck.h> > +#include <linux/types.h> > #include <asm/irqflags.h> > > /* Currently trace_softirqs_on/off is used only by lockdep */ > @@ -68,9 +69,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 ca65327a6de8..f27e96273453 100644 > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c > @@ -2369,6 +2369,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) { > @@ -2469,9 +2470,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 591c7a873235..10d12c8f7f77 100644 > --- a/kernel/trace/trace.h > +++ b/kernel/trace/trace.h > @@ -1261,6 +1261,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..576e2162114e 100644 > --- a/kernel/trace/trace_irqsoff.c > +++ b/kernel/trace/trace_irqsoff.c > @@ -456,6 +456,24 @@ 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 tracing is disabled, then the question of whether to trace console > + * latencies is moot. By always returning false here we save the caller > + * the calls to start/stop_critical_timings(). These calls would not do > + * anything anyway. > + */
I thought you were going to drop this patch, or at least I had suggested so but did not hear a reply from you: https://lkml.org/lkml/2019/10/3/464 Thanks for adding the comments though. Steve, what do you think about this patch? I am worried the extra flag may go obsolete at some point if the console latencies are fixed and we have yet another knob. thanks, - Joel > + 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 >