lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:	Fri, 04 Nov 2011 22:24:46 -0400
From:	Steven Rostedt <rostedt@...dmis.org>
To:	Jiri Olsa <jolsa@...hat.com>
Cc:	fweisbec@...il.com, mingo@...hat.com, linux-kernel@...r.kernel.org
Subject: Re: [PATCH] tracing/latency: Fix header output for latency tracers

Sorry for the late reply, I'm still purging through my Inbox from over
the week in Prague.


On Tue, 2011-09-13 at 16:03 +0200, Jiri Olsa wrote:
> In case the the graph tracer (CONFIG_FUNCTION_GRAPH_TRACER) or even the
> function tracer (CONFIG_FUNCTION_TRACER) are not set, the latency tracers
> do not display proper latency header.
> 
> The involved/fixed latency tracers are:
>         wakeup_rt
>         wakeup
>         preemptirqsoff
>         preemptoff
>         irqsoff
> 
> The patch adds proper handling of tracer configuration options for latency
> tracers, and displaying correct header info accordingly.
> 
> * The current output (for wakeup tracer) with both graph and function
>   tracers disabled is:
> 
>   # tracer: wakeup
>   #
>      cat-1163    0d..4    1us :   1163:120:R   + [000]     6:  0:R migration/0
>      cat-1163    0d..4    2us+: ttwu_do_activate.clone.1 <-try_to_wake_up
>      cat-1163    0d..3    4us : __schedule <-preempt_schedule
>      cat-1163    0d..3    4us :   1163:120:R ==> [000]     6:  0:R migration/0
> 
> 
> * The fixed output is:
> 
>   # tracer: wakeup
>   #
>   # wakeup latency trace v1.1.5 on 3.1.0-rc4-tip+
>   # --------------------------------------------------------------------
>   # latency: 91 us, #4/4, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:2)
>   #    -----------------
>   #    | task: watchdog/0-7 (uid:0 nice:0 policy:1 rt_prio:99)
>   #    -----------------
>   #
>     <idle>-0       0d.h5    1us :      0:120:R   + [000]     7:  0:R watchdog/0
>     <idle>-0       0d.h5    2us+: ttwu_do_activate.clone.1 <-try_to_wake_up
>     <idle>-0       0d..3   17us : __schedule <-schedule
>     <idle>-0       0d..3   17us :      0:120:R ==> [000]     7:  0:R watchdog/0

Why the above header? Why not just use the latency header for all of
them?

-- Steve

> 
> 
> * There's slightly different output (for wakeup_rt tracer) when function
>   tracer is enabled, currently:
> 
>   # tracer: wakeup_rt
>   #
>      cat-1168    1d..4    0us :   1168:120:R   + [001]     8:  0:R migration/1
>      cat-1168    1d..4    1us : ttwu_do_activate.clone.1 <-try_to_wake_up
>      cat-1168    1d..3    1us : check_preempt_curr <-ttwu_do_wakeup
>      ...
> 
> 
> * After the fix:
> 
>   # tracer: wakeup_rt
>   #
>   # wakeup_rt latency trace v1.1.5 on 3.1.0-rc4-tip+
>   # --------------------------------------------------------------------
>   # latency: 209 us, #113/113, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:2)
>   #    -----------------
>   #    | task: watchdog/0-7 (uid:0 nice:0 policy:1 rt_prio:99)
>   #    -----------------
>   #
>   #                  _------=> CPU#            
>   #                 / _-----=> irqs-off        
>   #                | / _----=> need-resched    
>   #                || / _---=> hardirq/softirq 
>   #                ||| / _--=> preempt-depth   
>   #                |||| /     delay             
>   #  cmd     pid   ||||| time  |   caller      
>   #     \   /      |||||  \    |   /           
>      cat-1168    1d..4    0us :   1168:120:R   + [001]     8:  0:R migration/1
>      cat-1168    1d..4    1us : ttwu_do_activate.clone.1 <-try_to_wake_up
>      cat-1168    1d..3    1us : check_preempt_curr <-ttwu_do_wakeup
>      ...
> 
> 
> Signed-off-by: Jiri Olsa <jolsa@...hat.com>
> ---
>  kernel/trace/trace.c              |   12 ++++++++++++
>  kernel/trace/trace.h              |    1 +
>  kernel/trace/trace_irqsoff.c      |   13 ++++++++++++-
>  kernel/trace/trace_sched_wakeup.c |   13 ++++++++++++-
>  4 files changed, 37 insertions(+), 2 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index e5df02c..7086345 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -2139,6 +2139,18 @@ enum print_line_t print_trace_line(struct trace_iterator *iter)
>  	return print_trace_fmt(iter);
>  }
>  
> +void trace_latency_header(struct seq_file *m)
> +{
> +	struct trace_iterator *iter = m->private;
> +
> +	/* print nothing if the buffers are empty */
> +	if (trace_empty(iter))
> +		return;
> +
> +	if (iter->iter_flags & TRACE_FILE_LAT_FMT)
> +		print_trace_header(m, iter);
> +}
> +
>  void trace_default_header(struct seq_file *m)
>  {
>  	struct trace_iterator *iter = m->private;
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 616846b..db40865 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -370,6 +370,7 @@ void trace_graph_function(struct trace_array *tr,
>  		    unsigned long ip,
>  		    unsigned long parent_ip,
>  		    unsigned long flags, int pc);
> +void trace_latency_header(struct seq_file *m);
>  void trace_default_header(struct seq_file *m);
>  void print_trace_header(struct seq_file *m, struct trace_iterator *iter);
>  int trace_empty(struct trace_iterator *iter);
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 667aa8c..2a0aee6 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -280,9 +280,20 @@ static enum print_line_t irqsoff_print_line(struct trace_iterator *iter)
>  }
>  
>  static void irqsoff_graph_return(struct ftrace_graph_ret *trace) { }
> -static void irqsoff_print_header(struct seq_file *s) { }
>  static void irqsoff_trace_open(struct trace_iterator *iter) { }
>  static void irqsoff_trace_close(struct trace_iterator *iter) { }
> +
> +#ifdef CONFIG_FUNCTION_TRACER
> +static void irqsoff_print_header(struct seq_file *s)
> +{
> +	trace_default_header(s);
> +}
> +#else
> +static void irqsoff_print_header(struct seq_file *s)
> +{
> +	trace_latency_header(s);
> +}
> +#endif /* CONFIG_FUNCTION_TRACER */
>  #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
>  
>  /*
> diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
> index e4a70c0..ff791ea 100644
> --- a/kernel/trace/trace_sched_wakeup.c
> +++ b/kernel/trace/trace_sched_wakeup.c
> @@ -280,9 +280,20 @@ static enum print_line_t wakeup_print_line(struct trace_iterator *iter)
>  }
>  
>  static void wakeup_graph_return(struct ftrace_graph_ret *trace) { }
> -static void wakeup_print_header(struct seq_file *s) { }
>  static void wakeup_trace_open(struct trace_iterator *iter) { }
>  static void wakeup_trace_close(struct trace_iterator *iter) { }
> +
> +#ifdef CONFIG_FUNCTION_TRACER
> +static void wakeup_print_header(struct seq_file *s)
> +{
> +	trace_default_header(s);
> +}
> +#else
> +static void wakeup_print_header(struct seq_file *s)
> +{
> +	trace_latency_header(s);
> +}
> +#endif /* CONFIG_FUNCTION_TRACER */
>  #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
>  
>  /*


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ