On Thu, Oct 03, 2019 at 12:44:09AM +0200, Viktor Rosendahl wrote: > On 10/2/19 2:52 AM, Joel Fernandes wrote: > > On Fri, Sep 20, 2019 at 05:22:19PM +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 | 12 ++++++++++++ > > > 4 files changed, 39 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 1888f6a3b694..036460a7e4cd 100644 > > > --- a/kernel/printk/printk.c > > > +++ b/kernel/printk/printk.c > > > @@ -2359,6 +2359,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) { > > > @@ -2459,9 +2460,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 4913ed1138aa..93a8b82c27e4 100644 > > > --- a/kernel/trace/trace.h > > > +++ b/kernel/trace/trace.h > > > @@ -1262,6 +1262,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; > > > > Why this condition here? Why not just make the call to > > stop_critical_timings() dependent on the new flag you are adding? Please > > explain it more and add some comments. > > > > It is a kind of optimization for the common case, i.e. that the tracer > is not enabled. > > The idea is that if the preemptirqsoff tracing is disabled, then the > question of whether or not to trace console latencies is moot and by > telling the caller that it is not disabled, we will prevent the caller > from making the calls to stop_critical_timings() and > start_critical_timings(). These calls would only return without doing > anything if the condition "!preempt_trace(pc) && !irq_trace()" is true, > since they use the inverse condition "preempt_trace(pc) || irq_trace()" > to test whether or not they should do anything. > > I have to admit that this may be a useless micro optimization that > makes the code harder to understand and maintain for a benefit that > is so small that it would be hard to measure. > > I feel a bit unsure whether I should try to improve it by adding a > comment, and perhaps putting the condition into a macro that > could then also be used by the start/stop_critical_timings() functions, > or if I should just get rid of the optimization. I guess this console > code is not a particularly hot code path anyway. > > Please let me know what you think.
Oh, I see what you are doing now. I think you can just add a comment on top of the if block explaining this. But IIRC the printk code is being rewritten to not have real-time latency issues, so may be this patch will become obsolete pretty soon? Unless you really need this patch for your series, I would should just drop it. thanks, - Joel > best regards, > > Viktor > > > thanks, > > > > - Joel > > > > > > > + > > > + 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 > > > >