[PATCH 1/3] Tracepoint: fix documentation of RCU lockdep checks

[PATCH 1/3] Tracepoint: fix documentation of RCU lockdep checks

[Mathieu Desnoyers]

The documentation on top of __DECLARE_TRACE() does not match its
implementation since the condition check has been added to the
RCU lockdep checks. Update the documentation to match its
implementation.

Fixes: a05d59a56733 "tracing: Add condition check to RCU lockdep checks"
Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
CC: Dave Hansen <dave@sr71.net>
CC: Steven Rostedt <rostedt@goodmis.org>
---
 include/linux/tracepoint.h | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index a5f7f3e..c8e3030 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -167,10 +167,11 @@ extern void syscall_unregfunc(void);
  * structure. Force alignment to the same alignment as the section start.
  *
  * When lockdep is enabled, we make sure to always do the RCU portions of
- * the tracepoint code, regardless of whether tracing is on or we match the
- * condition.  This lets us find RCU issues triggered with tracepoints even
- * when this tracepoint is off.  This code has no purpose other than poking
- * RCU a bit.
+ * the tracepoint code, regardless of whether tracing is on. However,
+ * don't check if the condition is false, due to interaction with idle
+ * instrumentation. This lets us find RCU issues triggered with tracepoints
+ * even when this tracepoint is off. This code has no purpose other than
+ * poking RCU a bit.
  */
 #define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \
 	extern struct tracepoint __tracepoint_##name;			\
-- 
2.1.4

[PATCH 2/3] ftrace: add ftrace-buffer option

[Mathieu Desnoyers]

In order to use ftrace tracers to generate tracepoints without doing
tracing to its own hardcoded ring buffers, add a ftrace-buffer option
(default: 1). When set to 0, it disables tracing into the ftrace
hardcoded buffers.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
CC: Thomas Gleixner <tglx@linutronix.de>
CC: Steven Rostedt <rostedt@goodmis.org>
CC: Ingo Molnar <mingo@redhat.com>
CC: Peter Zijlstra <peterz@infradead.org>
---
 kernel/trace/trace.c         |  4 +++-
 kernel/trace/trace.h         |  1 +
 kernel/trace/trace_irqsoff.c | 19 +++++++++++--------
 3 files changed, 15 insertions(+), 9 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 6e79408..d664f0e 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -472,7 +472,8 @@ static inline void trace_access_lock_init(void)
 unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
 	TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME |
 	TRACE_ITER_GRAPH_TIME | TRACE_ITER_RECORD_CMD | TRACE_ITER_OVERWRITE |
-	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION;
+	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION |
+	TRACE_ITER_FTRACE_BUFFER;
 
 static void tracer_tracing_on(struct trace_array *tr)
 {
@@ -862,6 +863,7 @@ static const char *trace_options[] = {
 	"irq-info",
 	"markers",
 	"function-trace",
+	"ftrace-buffer",
 	NULL
 };
 
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 74bde81..29968e1 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -930,6 +930,7 @@ enum trace_iterator_flags {
 	TRACE_ITER_IRQ_INFO		= 0x800000,
 	TRACE_ITER_MARKERS		= 0x1000000,
 	TRACE_ITER_FUNCTION		= 0x2000000,
+	TRACE_ITER_FTRACE_BUFFER	= 0x4000000,
 };
 
 /*
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 8523ea3..3e5635d 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -334,9 +334,11 @@ check_critical_timing(struct trace_array *tr,
 	if (!report_latency(tr, delta))
 		goto out_unlock;
 
-	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
-	/* Skip 5 functions to get to the irq/preempt enable function */
-	__trace_stack(tr, flags, 5, pc);
+	if (trace_flags & TRACE_ITER_FTRACE_BUFFER) {
+		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
+		/* Skip 5 functions to get to the irq/preempt enable function */
+		__trace_stack(tr, flags, 5, pc);
+	}
 
 	if (data->critical_sequence != max_sequence)
 		goto out_unlock;
@@ -356,7 +358,8 @@ out_unlock:
 out:
 	data->critical_sequence = max_sequence;
 	data->preempt_timestamp = ftrace_now(cpu);
-	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
+	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
+		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
 }
 
 static inline void
@@ -387,9 +390,8 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
 	data->critical_start = parent_ip ? : ip;
 
 	local_save_flags(flags);
-
-	__trace_function(tr, ip, parent_ip, flags, preempt_count());
-
+	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
+		__trace_function(tr, ip, parent_ip, flags, preempt_count());
 	per_cpu(tracing_cpu, cpu) = 1;
 
 	atomic_dec(&data->disabled);
@@ -422,7 +424,8 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip)
 	atomic_inc(&data->disabled);
 
 	local_save_flags(flags);
-	__trace_function(tr, ip, parent_ip, flags, preempt_count());
+	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
+		__trace_function(tr, ip, parent_ip, flags, preempt_count());
 	check_critical_timing(tr, data, parent_ip ? : ip, cpu);
 	data->critical_start = 0;
 	atomic_dec(&data->disabled);
-- 
2.1.4

Re: [PATCH 2/3] ftrace: add ftrace-buffer option

[Steven Rostedt]

On Mon,  2 Nov 2015 17:42:43 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> In order to use ftrace tracers to generate tracepoints without doing
> tracing to its own hardcoded ring buffers, add a ftrace-buffer option
> (default: 1). When set to 0, it disables tracing into the ftrace
> hardcoded buffers.
> 

This needs a more in depth change log. I have no idea why this is
needed.

Also, the trace_options code have been redesigned, and this won't apply
to it (see linux-next). Also, if this is only for irqsoff latency
tracers, it should be a tracer option, not a global one.

-- Steve


> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> CC: Thomas Gleixner <tglx@linutronix.de>
> CC: Steven Rostedt <rostedt@goodmis.org>
> CC: Ingo Molnar <mingo@redhat.com>
> CC: Peter Zijlstra <peterz@infradead.org>
> ---
>  kernel/trace/trace.c         |  4 +++-
>  kernel/trace/trace.h         |  1 +
>  kernel/trace/trace_irqsoff.c | 19 +++++++++++--------
>  3 files changed, 15 insertions(+), 9 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 6e79408..d664f0e 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -472,7 +472,8 @@ static inline void trace_access_lock_init(void)
>  unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
>  	TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME |
>  	TRACE_ITER_GRAPH_TIME | TRACE_ITER_RECORD_CMD | TRACE_ITER_OVERWRITE |
> -	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION;
> +	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION |
> +	TRACE_ITER_FTRACE_BUFFER;
>  
>  static void tracer_tracing_on(struct trace_array *tr)
>  {
> @@ -862,6 +863,7 @@ static const char *trace_options[] = {
>  	"irq-info",
>  	"markers",
>  	"function-trace",
> +	"ftrace-buffer",
>  	NULL
>  };
>  
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 74bde81..29968e1 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -930,6 +930,7 @@ enum trace_iterator_flags {
>  	TRACE_ITER_IRQ_INFO		= 0x800000,
>  	TRACE_ITER_MARKERS		= 0x1000000,
>  	TRACE_ITER_FUNCTION		= 0x2000000,
> +	TRACE_ITER_FTRACE_BUFFER	= 0x4000000,
>  };
>  
>  /*
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 8523ea3..3e5635d 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -334,9 +334,11 @@ check_critical_timing(struct trace_array *tr,
>  	if (!report_latency(tr, delta))
>  		goto out_unlock;
>  
> -	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
> -	/* Skip 5 functions to get to the irq/preempt enable function */
> -	__trace_stack(tr, flags, 5, pc);
> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER) {
> +		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
> +		/* Skip 5 functions to get to the irq/preempt enable function */
> +		__trace_stack(tr, flags, 5, pc);
> +	}
>  
>  	if (data->critical_sequence != max_sequence)
>  		goto out_unlock;
> @@ -356,7 +358,8 @@ out_unlock:
>  out:
>  	data->critical_sequence = max_sequence;
>  	data->preempt_timestamp = ftrace_now(cpu);
> -	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
> +		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
>  }
>  
>  static inline void
> @@ -387,9 +390,8 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
>  	data->critical_start = parent_ip ? : ip;
>  
>  	local_save_flags(flags);
> -
> -	__trace_function(tr, ip, parent_ip, flags, preempt_count());
> -
> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
> +		__trace_function(tr, ip, parent_ip, flags, preempt_count());
>  	per_cpu(tracing_cpu, cpu) = 1;
>  
>  	atomic_dec(&data->disabled);
> @@ -422,7 +424,8 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip)
>  	atomic_inc(&data->disabled);
>  
>  	local_save_flags(flags);
> -	__trace_function(tr, ip, parent_ip, flags, preempt_count());
> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
> +		__trace_function(tr, ip, parent_ip, flags, preempt_count());
>  	check_critical_timing(tr, data, parent_ip ? : ip, cpu);
>  	data->critical_start = 0;
>  	atomic_dec(&data->disabled);

Re: [PATCH 2/3] ftrace: add ftrace-buffer option

[Mathieu Desnoyers]

----- On Nov 2, 2015, at 5:56 PM, rostedt rostedt@goodmis.org wrote:

> On Mon,  2 Nov 2015 17:42:43 -0500
> Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> 
>> In order to use ftrace tracers to generate tracepoints without doing
>> tracing to its own hardcoded ring buffers, add a ftrace-buffer option
>> (default: 1). When set to 0, it disables tracing into the ftrace
>> hardcoded buffers.
>> 
> 
> This needs a more in depth change log. I have no idea why this is
> needed.

I can do an updated change log. This is needed for the next patch
in this series, which adds tracepoints in the ftrace irqs and preempt
off tracer, so other tracers such as Perf and LTTng can use them.

> 
> Also, the trace_options code have been redesigned, and this won't apply
> to it (see linux-next).

I can rebase my work on top of linux-next if you are OK with
the general idea.

> Also, if this is only for irqsoff latency
> tracers, it should be a tracer option, not a global one.

I've currently only done the irqsoff latency tracer
part, but I'm wondering whether:

1- we should make it a irqsoff latency tracer option,
2- we should keep it as a global ftrace option, and apply it to
   other ftrace tracers as well,

Thoughts ?

Thanks,

Mathieu

> 
> -- Steve
> 
> 
>> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
>> CC: Thomas Gleixner <tglx@linutronix.de>
>> CC: Steven Rostedt <rostedt@goodmis.org>
>> CC: Ingo Molnar <mingo@redhat.com>
>> CC: Peter Zijlstra <peterz@infradead.org>
>> ---
>>  kernel/trace/trace.c         |  4 +++-
>>  kernel/trace/trace.h         |  1 +
>>  kernel/trace/trace_irqsoff.c | 19 +++++++++++--------
>>  3 files changed, 15 insertions(+), 9 deletions(-)
>> 
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index 6e79408..d664f0e 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -472,7 +472,8 @@ static inline void trace_access_lock_init(void)
>>  unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
>>  	TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME |
>>  	TRACE_ITER_GRAPH_TIME | TRACE_ITER_RECORD_CMD | TRACE_ITER_OVERWRITE |
>> -	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION;
>> +	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION |
>> +	TRACE_ITER_FTRACE_BUFFER;
>>  
>>  static void tracer_tracing_on(struct trace_array *tr)
>>  {
>> @@ -862,6 +863,7 @@ static const char *trace_options[] = {
>>  	"irq-info",
>>  	"markers",
>>  	"function-trace",
>> +	"ftrace-buffer",
>>  	NULL
>>  };
>>  
>> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
>> index 74bde81..29968e1 100644
>> --- a/kernel/trace/trace.h
>> +++ b/kernel/trace/trace.h
>> @@ -930,6 +930,7 @@ enum trace_iterator_flags {
>>  	TRACE_ITER_IRQ_INFO		= 0x800000,
>>  	TRACE_ITER_MARKERS		= 0x1000000,
>>  	TRACE_ITER_FUNCTION		= 0x2000000,
>> +	TRACE_ITER_FTRACE_BUFFER	= 0x4000000,
>>  };
>>  
>>  /*
>> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
>> index 8523ea3..3e5635d 100644
>> --- a/kernel/trace/trace_irqsoff.c
>> +++ b/kernel/trace/trace_irqsoff.c
>> @@ -334,9 +334,11 @@ check_critical_timing(struct trace_array *tr,
>>  	if (!report_latency(tr, delta))
>>  		goto out_unlock;
>>  
>> -	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
>> -	/* Skip 5 functions to get to the irq/preempt enable function */
>> -	__trace_stack(tr, flags, 5, pc);
>> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER) {
>> +		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
>> +		/* Skip 5 functions to get to the irq/preempt enable function */
>> +		__trace_stack(tr, flags, 5, pc);
>> +	}
>>  
>>  	if (data->critical_sequence != max_sequence)
>>  		goto out_unlock;
>> @@ -356,7 +358,8 @@ out_unlock:
>>  out:
>>  	data->critical_sequence = max_sequence;
>>  	data->preempt_timestamp = ftrace_now(cpu);
>> -	__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
>> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
>> +		__trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
>>  }
>>  
>>  static inline void
>> @@ -387,9 +390,8 @@ start_critical_timing(unsigned long ip, unsigned long
>> parent_ip)
>>  	data->critical_start = parent_ip ? : ip;
>>  
>>  	local_save_flags(flags);
>> -
>> -	__trace_function(tr, ip, parent_ip, flags, preempt_count());
>> -
>> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
>> +		__trace_function(tr, ip, parent_ip, flags, preempt_count());
>>  	per_cpu(tracing_cpu, cpu) = 1;
>>  
>>  	atomic_dec(&data->disabled);
>> @@ -422,7 +424,8 @@ stop_critical_timing(unsigned long ip, unsigned long
>> parent_ip)
>>  	atomic_inc(&data->disabled);
>>  
>>  	local_save_flags(flags);
>> -	__trace_function(tr, ip, parent_ip, flags, preempt_count());
>> +	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
>> +		__trace_function(tr, ip, parent_ip, flags, preempt_count());
>>  	check_critical_timing(tr, data, parent_ip ? : ip, cpu);
>>  	data->critical_start = 0;
> >  	atomic_dec(&data->disabled);

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [PATCH 2/3] ftrace: add ftrace-buffer option

[Steven Rostedt]

On Mon, 2 Nov 2015 23:01:08 +0000 (UTC)
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> ----- On Nov 2, 2015, at 5:56 PM, rostedt rostedt@goodmis.org wrote:
> 
> > On Mon,  2 Nov 2015 17:42:43 -0500
> > Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> > 
> >> In order to use ftrace tracers to generate tracepoints without doing
> >> tracing to its own hardcoded ring buffers, add a ftrace-buffer option
> >> (default: 1). When set to 0, it disables tracing into the ftrace
> >> hardcoded buffers.
> >> 
> > 
> > This needs a more in depth change log. I have no idea why this is
> > needed.
> 
> I can do an updated change log. This is needed for the next patch
> in this series, which adds tracepoints in the ftrace irqs and preempt
> off tracer, so other tracers such as Perf and LTTng can use them.
> 
> > 
> > Also, the trace_options code have been redesigned, and this won't apply
> > to it (see linux-next).
> 
> I can rebase my work on top of linux-next if you are OK with
> the general idea.
> 
> > Also, if this is only for irqsoff latency
> > tracers, it should be a tracer option, not a global one.
> 
> I've currently only done the irqsoff latency tracer
> part, but I'm wondering whether:
> 
> 1- we should make it a irqsoff latency tracer option,
> 2- we should keep it as a global ftrace option, and apply it to
>    other ftrace tracers as well,
> 
> Thoughts ?
> 
>

Tomorrow I'll take a deeper look at patch 3 to try to understand.

-- Steve

Re: [PATCH 2/3] ftrace: add ftrace-buffer option

[Steven Rostedt]

On Mon,  2 Nov 2015 17:42:43 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> In order to use ftrace tracers to generate tracepoints without doing
> tracing to its own hardcoded ring buffers, add a ftrace-buffer option
> (default: 1). When set to 0, it disables tracing into the ftrace
> hardcoded buffers.
> 

This should be a tracer specific option. And it shouldn't be called
"ftrace-buffer" as that is a very confusing name.

Perhaps I can add an option that will prevent the snapshots as well.
Perhaps an option called "quiet", and a "no_snapshot" one too. I can
create the no snapshot one. But this should be converted to "quiet" and
added as a tracer specific option.

-- Steve


> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> CC: Thomas Gleixner <tglx@linutronix.de>
> CC: Steven Rostedt <rostedt@goodmis.org>
> CC: Ingo Molnar <mingo@redhat.com>
> CC: Peter Zijlstra <peterz@infradead.org>
> ---
>  kernel/trace/trace.c         |  4 +++-
>  kernel/trace/trace.h         |  1 +
>  kernel/trace/trace_irqsoff.c | 19 +++++++++++--------
>  3 files changed, 15 insertions(+), 9 deletions(-)

Re: [PATCH 2/3] ftrace: add ftrace-buffer option

[Mathieu Desnoyers]

----- On Nov 23, 2015, at 4:46 PM, rostedt rostedt@goodmis.org wrote:

> On Mon,  2 Nov 2015 17:42:43 -0500
> Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> 
>> In order to use ftrace tracers to generate tracepoints without doing
>> tracing to its own hardcoded ring buffers, add a ftrace-buffer option
>> (default: 1). When set to 0, it disables tracing into the ftrace
>> hardcoded buffers.
>> 
> 
> This should be a tracer specific option. And it shouldn't be called
> "ftrace-buffer" as that is a very confusing name.
> 
> Perhaps I can add an option that will prevent the snapshots as well.
> Perhaps an option called "quiet", and a "no_snapshot" one too. I can
> create the no snapshot one. But this should be converted to "quiet" and
> added as a tracer specific option.

Sure, I can add the "quiet" option to the irqsoff/irqspreemptoff
tracers if that's the route you recommend,

Thanks!

Mathieu

> 
> -- Steve
> 
> 
>> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
>> CC: Thomas Gleixner <tglx@linutronix.de>
>> CC: Steven Rostedt <rostedt@goodmis.org>
>> CC: Ingo Molnar <mingo@redhat.com>
>> CC: Peter Zijlstra <peterz@infradead.org>
>> ---
>>  kernel/trace/trace.c         |  4 +++-
>>  kernel/trace/trace.h         |  1 +
>>  kernel/trace/trace_irqsoff.c | 19 +++++++++++--------
> >  3 files changed, 15 insertions(+), 9 deletions(-)

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[PATCH v2 3/3] trace: emit tracepoint in preempt and irqs off tracer

[Mathieu Desnoyers]

Allow Ftrace, Perf, and LTTng to hook on the irqsoff tracer and trace
irqsoff and preemptoff critical sections.

How to setup the irqsoff tracer for this use-case (needed for use with
Ftrace, Perf, or LTTng): if the tracing_thresh value is set, all
durations beyond the specified threshold will emit a
"core_critical_timing_hit" tracepoint. If unset, then the max duration
will be tracked. The current max duration can be reset using the
tracing_max_latency file.

echo 0 > /sys/kernel/debug/tracing/options/function-trace  # don't need function tracing
echo 0 > /sys/kernel/debug/tracing/options/ftrace-buffer
echo preemptirqsoff > /sys/kernel/debug/tracing/current_tracer
echo 2 > /sys/kernel/debug/tracing/tracing_thresh      # set threshold (e.g. 2 µs)
echo 1 > /sys/kernel/debug/tracing/tracing_on

The following two commands can also be useful to tweak the
irqsoff tracer:
echo 0 > /sys/kernel/debug/tracing/tracing_max_latency # reset max latency
echo 0 > /sys/kernel/debug/tracing/tracing_thresh      # disable threshold

*** An example usage of Ftrace hooking on this tracepoint: ***

echo 1 > /sys/kernel/debug/tracing/events/core/core_critical_timing_hit/enable
cat /sys/kernel/debug/tracing/trace_pipe
[...]
    bash-2380   19d..3 52794942us : core_critical_timing_hit: ip=0xffffffff811021de parent_ip=0xffffffff818d1b17 delta_ns=3402 irqs_disabled=0 preempt_disabled=1 in_softirq=0 in_irq=0 in_nmi=0

*** An example usage of Perf hooking on this tracepoint: ***

perf record -g -e core:core_critical_timing_hit -c 1 sleep 30
perf report -g

+  100.00%   100.00%  sleep    [kernel.vmlinux]  [k] check_critical_timing
+   92.75%     0.00%  sleep    [kernel.vmlinux]  [k] preempt_count_sub
+   92.75%     0.00%  sleep    [kernel.vmlinux]  [k] trace_preempt_on
+   65.22%     0.00%  sleep    [kernel.vmlinux]  [k] page_fault
+   65.22%     0.00%  sleep    [kernel.vmlinux]  [k] do_page_fault
+   63.77%     0.00%  sleep    [kernel.vmlinux]  [k] __do_page_fault
+   63.77%     0.00%  sleep    [kernel.vmlinux]  [k] handle_mm_fault
+   56.52%     0.00%  sleep    [kernel.vmlinux]  [k] _raw_spin_unlock
+   30.43%     0.00%  sleep    ld-2.19.so        [.] _dl_sysdep_start
[...]

*** An example usage of LTTng hooking on this tracepoint: ***

(as root)
lttng-sessiond -d

(then, as root or tracing group)
lttng create --live
lttng enable-event -k core_critical_timing_hit
lttng start
lttng view
[...]
[17:34:17.090669588] (+1.569689755) compudjdev core_critical_timing_hit: { cpu_id = 3 }, { ip = 0xFFFFFFFF81102135, parent_ip = 0xFFFFFFFFA0798E13, delta_ns = 252994, irqs_disabled = 0, preempt_disabled = 1, in_softirq = 0, in_irq = 0, in_nmi = 0 }

Tracepoints core_critical_timing_start and core_critical_timing_stop are
also available. They trigger at a much higher rate than
core_critical_timing_hit.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
CC: Thomas Gleixner <tglx@linutronix.de>
CC: Steven Rostedt <rostedt@goodmis.org>
CC: Ingo Molnar <mingo@redhat.com>
CC: Peter Zijlstra <peterz@infradead.org>
---
Changes since v1:
- Remove unneeded tracepoint jump label bypass.
- Enhance TP_printk() formatting.
- Use new ftrace-buffer option in changelog.
- Add core_critical_timing_start/stop tracepoints.
---
 include/trace/events/core.h  | 96 ++++++++++++++++++++++++++++++++++++++++++++
 kernel/trace/trace_irqsoff.c | 17 ++++++--
 2 files changed, 109 insertions(+), 4 deletions(-)
 create mode 100644 include/trace/events/core.h

diff --git a/include/trace/events/core.h b/include/trace/events/core.h
new file mode 100644
index 0000000..ccc3430
--- /dev/null
+++ b/include/trace/events/core.h
@@ -0,0 +1,96 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM core
+
+#if !defined(_TRACE_CORE_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CORE_H
+
+#include <linux/tracepoint.h>
+#include <linux/irqflags.h>
+#include <linux/preempt.h>
+
+/*
+ * Tracepoint for critical timings max/threshold hit.
+ */
+TRACE_EVENT(core_critical_timing_hit,
+
+	TP_PROTO(unsigned long ip, unsigned long parent_ip,
+			unsigned long flags, int preempt_cnt,
+			cycles_t delta_ns),
+
+	TP_ARGS(ip, parent_ip, flags, preempt_cnt, delta_ns),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long, ip		)
+		__field(	unsigned long, parent_ip	)
+		__field(	cycles_t, delta_ns		)
+		__field(	unsigned long, flags		)
+		__field(	int, preempt_cnt		)
+	),
+
+	TP_fast_assign(
+		__entry->ip		= ip;
+		__entry->parent_ip	= parent_ip;
+		__entry->delta_ns	= delta_ns;
+		__entry->flags		= flags;
+		__entry->preempt_cnt	= preempt_cnt;
+	),
+
+	TP_printk("ip=0x%lx parent_ip=0x%lx delta_ns=%llu irqs_disabled=%u preempt_disabled=%u in_softirq=%u in_irq=%u in_nmi=%u",
+		  __entry->ip, __entry->parent_ip,
+		  (unsigned long long) __entry->delta_ns,
+		  !!raw_irqs_disabled_flags(__entry->flags),
+		  !!(__entry->preempt_cnt & PREEMPT_MASK),
+		  !!(__entry->preempt_cnt & SOFTIRQ_MASK),
+		  !!(__entry->preempt_cnt & HARDIRQ_MASK),
+		  !!(__entry->preempt_cnt & NMI_MASK))
+);
+
+/*
+ * Tracepoint for critical timings start/stop.
+ */
+DECLARE_EVENT_CLASS(core_critical_timing,
+
+	TP_PROTO(unsigned long ip, unsigned long parent_ip,
+			unsigned long flags, int preempt_cnt),
+
+	TP_ARGS(ip, parent_ip, flags, preempt_cnt),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long, ip		)
+		__field(	unsigned long, parent_ip	)
+		__field(	unsigned long, flags		)
+		__field(	int, preempt_cnt		)
+	),
+
+	TP_fast_assign(
+		__entry->ip		= ip;
+		__entry->parent_ip	= parent_ip;
+		__entry->flags		= flags;
+		__entry->preempt_cnt	= preempt_cnt;
+	),
+
+	TP_printk("ip=0x%lx parent_ip=0x%lx irqs_disabled=%u preempt_disabled=%u in_softirq=%u in_irq=%u in_nmi=%u",
+		  __entry->ip, __entry->parent_ip,
+		  !!raw_irqs_disabled_flags(__entry->flags),
+		  !!(__entry->preempt_cnt & PREEMPT_MASK),
+		  !!(__entry->preempt_cnt & SOFTIRQ_MASK),
+		  !!(__entry->preempt_cnt & HARDIRQ_MASK),
+		  !!(__entry->preempt_cnt & NMI_MASK))
+);
+
+DEFINE_EVENT(core_critical_timing, core_critical_timing_start,
+	TP_PROTO(unsigned long ip, unsigned long parent_ip,
+		unsigned long flags, int preempt_cnt),
+	TP_ARGS(ip, parent_ip, flags, preempt_cnt)
+);
+
+DEFINE_EVENT(core_critical_timing, core_critical_timing_stop,
+	TP_PROTO(unsigned long ip, unsigned long parent_ip,
+		unsigned long flags, int preempt_cnt),
+	TP_ARGS(ip, parent_ip, flags, preempt_cnt)
+);
+
+#endif /* _TRACE_CORE_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 3e5635d..abfb77e 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -14,6 +14,9 @@
 #include <linux/module.h>
 #include <linux/ftrace.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/core.h>
+
 #include "trace.h"
 
 static struct trace_array		*irqsoff_trace __read_mostly;
@@ -339,6 +342,8 @@ check_critical_timing(struct trace_array *tr,
 		/* Skip 5 functions to get to the irq/preempt enable function */
 		__trace_stack(tr, flags, 5, pc);
 	}
+	trace_core_critical_timing_hit(CALLER_ADDR0, parent_ip, flags, pc,
+			delta);
 
 	if (data->critical_sequence != max_sequence)
 		goto out_unlock;
@@ -365,7 +370,7 @@ out:
 static inline void
 start_critical_timing(unsigned long ip, unsigned long parent_ip)
 {
-	int cpu;
+	int cpu, pc;
 	struct trace_array *tr = irqsoff_trace;
 	struct trace_array_cpu *data;
 	unsigned long flags;
@@ -390,8 +395,10 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
 	data->critical_start = parent_ip ? : ip;
 
 	local_save_flags(flags);
+	pc = preempt_count();
 	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
-		__trace_function(tr, ip, parent_ip, flags, preempt_count());
+		__trace_function(tr, ip, parent_ip, flags, pc);
+	trace_core_critical_timing_start(ip, parent_ip, flags, pc);
 	per_cpu(tracing_cpu, cpu) = 1;
 
 	atomic_dec(&data->disabled);
@@ -400,7 +407,7 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
 static inline void
 stop_critical_timing(unsigned long ip, unsigned long parent_ip)
 {
-	int cpu;
+	int cpu, pc;
 	struct trace_array *tr = irqsoff_trace;
 	struct trace_array_cpu *data;
 	unsigned long flags;
@@ -424,8 +431,10 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip)
 	atomic_inc(&data->disabled);
 
 	local_save_flags(flags);
+	pc = preempt_count();
 	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
-		__trace_function(tr, ip, parent_ip, flags, preempt_count());
+		__trace_function(tr, ip, parent_ip, flags, pc);
+	trace_core_critical_timing_stop(ip, parent_ip, flags, pc);
 	check_critical_timing(tr, data, parent_ip ? : ip, cpu);
 	data->critical_start = 0;
 	atomic_dec(&data->disabled);
-- 
2.1.4

Re: [PATCH v2 3/3] trace: emit tracepoint in preempt and irqs off tracer

[Mathieu Desnoyers]

----- On Nov 2, 2015, at 5:42 PM, Mathieu Desnoyers mathieu.desnoyers@efficios.com wrote:

> Allow Ftrace, Perf, and LTTng to hook on the irqsoff tracer and trace
> irqsoff and preemptoff critical sections.

Hi Steven,

I guess you ended up being busy lately. Your feedback on this patchset
is still very welcome.

Thanks,

Mathieu

> 
> How to setup the irqsoff tracer for this use-case (needed for use with
> Ftrace, Perf, or LTTng): if the tracing_thresh value is set, all
> durations beyond the specified threshold will emit a
> "core_critical_timing_hit" tracepoint. If unset, then the max duration
> will be tracked. The current max duration can be reset using the
> tracing_max_latency file.
> 
> echo 0 > /sys/kernel/debug/tracing/options/function-trace  # don't need function
> tracing
> echo 0 > /sys/kernel/debug/tracing/options/ftrace-buffer
> echo preemptirqsoff > /sys/kernel/debug/tracing/current_tracer
> echo 2 > /sys/kernel/debug/tracing/tracing_thresh      # set threshold (e.g. 2
> µs)
> echo 1 > /sys/kernel/debug/tracing/tracing_on
> 
> The following two commands can also be useful to tweak the
> irqsoff tracer:
> echo 0 > /sys/kernel/debug/tracing/tracing_max_latency # reset max latency
> echo 0 > /sys/kernel/debug/tracing/tracing_thresh      # disable threshold
> 
> *** An example usage of Ftrace hooking on this tracepoint: ***
> 
> echo 1 > /sys/kernel/debug/tracing/events/core/core_critical_timing_hit/enable
> cat /sys/kernel/debug/tracing/trace_pipe
> [...]
>    bash-2380   19d..3 52794942us : core_critical_timing_hit: ip=0xffffffff811021de
>    parent_ip=0xffffffff818d1b17 delta_ns=3402 irqs_disabled=0 preempt_disabled=1
>    in_softirq=0 in_irq=0 in_nmi=0
> 
> *** An example usage of Perf hooking on this tracepoint: ***
> 
> perf record -g -e core:core_critical_timing_hit -c 1 sleep 30
> perf report -g
> 
> +  100.00%   100.00%  sleep    [kernel.vmlinux]  [k] check_critical_timing
> +   92.75%     0.00%  sleep    [kernel.vmlinux]  [k] preempt_count_sub
> +   92.75%     0.00%  sleep    [kernel.vmlinux]  [k] trace_preempt_on
> +   65.22%     0.00%  sleep    [kernel.vmlinux]  [k] page_fault
> +   65.22%     0.00%  sleep    [kernel.vmlinux]  [k] do_page_fault
> +   63.77%     0.00%  sleep    [kernel.vmlinux]  [k] __do_page_fault
> +   63.77%     0.00%  sleep    [kernel.vmlinux]  [k] handle_mm_fault
> +   56.52%     0.00%  sleep    [kernel.vmlinux]  [k] _raw_spin_unlock
> +   30.43%     0.00%  sleep    ld-2.19.so        [.] _dl_sysdep_start
> [...]
> 
> *** An example usage of LTTng hooking on this tracepoint: ***
> 
> (as root)
> lttng-sessiond -d
> 
> (then, as root or tracing group)
> lttng create --live
> lttng enable-event -k core_critical_timing_hit
> lttng start
> lttng view
> [...]
> [17:34:17.090669588] (+1.569689755) compudjdev core_critical_timing_hit: {
> cpu_id = 3 }, { ip = 0xFFFFFFFF81102135, parent_ip = 0xFFFFFFFFA0798E13,
> delta_ns = 252994, irqs_disabled = 0, preempt_disabled = 1, in_softirq = 0,
> in_irq = 0, in_nmi = 0 }
> 
> Tracepoints core_critical_timing_start and core_critical_timing_stop are
> also available. They trigger at a much higher rate than
> core_critical_timing_hit.
> 
> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> CC: Thomas Gleixner <tglx@linutronix.de>
> CC: Steven Rostedt <rostedt@goodmis.org>
> CC: Ingo Molnar <mingo@redhat.com>
> CC: Peter Zijlstra <peterz@infradead.org>
> ---
> Changes since v1:
> - Remove unneeded tracepoint jump label bypass.
> - Enhance TP_printk() formatting.
> - Use new ftrace-buffer option in changelog.
> - Add core_critical_timing_start/stop tracepoints.
> ---
> include/trace/events/core.h  | 96 ++++++++++++++++++++++++++++++++++++++++++++
> kernel/trace/trace_irqsoff.c | 17 ++++++--
> 2 files changed, 109 insertions(+), 4 deletions(-)
> create mode 100644 include/trace/events/core.h
> 
> diff --git a/include/trace/events/core.h b/include/trace/events/core.h
> new file mode 100644
> index 0000000..ccc3430
> --- /dev/null
> +++ b/include/trace/events/core.h
> @@ -0,0 +1,96 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM core
> +
> +#if !defined(_TRACE_CORE_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_CORE_H
> +
> +#include <linux/tracepoint.h>
> +#include <linux/irqflags.h>
> +#include <linux/preempt.h>
> +
> +/*
> + * Tracepoint for critical timings max/threshold hit.
> + */
> +TRACE_EVENT(core_critical_timing_hit,
> +
> +	TP_PROTO(unsigned long ip, unsigned long parent_ip,
> +			unsigned long flags, int preempt_cnt,
> +			cycles_t delta_ns),
> +
> +	TP_ARGS(ip, parent_ip, flags, preempt_cnt, delta_ns),
> +
> +	TP_STRUCT__entry(
> +		__field(	unsigned long, ip		)
> +		__field(	unsigned long, parent_ip	)
> +		__field(	cycles_t, delta_ns		)
> +		__field(	unsigned long, flags		)
> +		__field(	int, preempt_cnt		)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->ip		= ip;
> +		__entry->parent_ip	= parent_ip;
> +		__entry->delta_ns	= delta_ns;
> +		__entry->flags		= flags;
> +		__entry->preempt_cnt	= preempt_cnt;
> +	),
> +
> +	TP_printk("ip=0x%lx parent_ip=0x%lx delta_ns=%llu irqs_disabled=%u
> preempt_disabled=%u in_softirq=%u in_irq=%u in_nmi=%u",
> +		  __entry->ip, __entry->parent_ip,
> +		  (unsigned long long) __entry->delta_ns,
> +		  !!raw_irqs_disabled_flags(__entry->flags),
> +		  !!(__entry->preempt_cnt & PREEMPT_MASK),
> +		  !!(__entry->preempt_cnt & SOFTIRQ_MASK),
> +		  !!(__entry->preempt_cnt & HARDIRQ_MASK),
> +		  !!(__entry->preempt_cnt & NMI_MASK))
> +);
> +
> +/*
> + * Tracepoint for critical timings start/stop.
> + */
> +DECLARE_EVENT_CLASS(core_critical_timing,
> +
> +	TP_PROTO(unsigned long ip, unsigned long parent_ip,
> +			unsigned long flags, int preempt_cnt),
> +
> +	TP_ARGS(ip, parent_ip, flags, preempt_cnt),
> +
> +	TP_STRUCT__entry(
> +		__field(	unsigned long, ip		)
> +		__field(	unsigned long, parent_ip	)
> +		__field(	unsigned long, flags		)
> +		__field(	int, preempt_cnt		)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->ip		= ip;
> +		__entry->parent_ip	= parent_ip;
> +		__entry->flags		= flags;
> +		__entry->preempt_cnt	= preempt_cnt;
> +	),
> +
> +	TP_printk("ip=0x%lx parent_ip=0x%lx irqs_disabled=%u preempt_disabled=%u
> in_softirq=%u in_irq=%u in_nmi=%u",
> +		  __entry->ip, __entry->parent_ip,
> +		  !!raw_irqs_disabled_flags(__entry->flags),
> +		  !!(__entry->preempt_cnt & PREEMPT_MASK),
> +		  !!(__entry->preempt_cnt & SOFTIRQ_MASK),
> +		  !!(__entry->preempt_cnt & HARDIRQ_MASK),
> +		  !!(__entry->preempt_cnt & NMI_MASK))
> +);
> +
> +DEFINE_EVENT(core_critical_timing, core_critical_timing_start,
> +	TP_PROTO(unsigned long ip, unsigned long parent_ip,
> +		unsigned long flags, int preempt_cnt),
> +	TP_ARGS(ip, parent_ip, flags, preempt_cnt)
> +);
> +
> +DEFINE_EVENT(core_critical_timing, core_critical_timing_stop,
> +	TP_PROTO(unsigned long ip, unsigned long parent_ip,
> +		unsigned long flags, int preempt_cnt),
> +	TP_ARGS(ip, parent_ip, flags, preempt_cnt)
> +);
> +
> +#endif /* _TRACE_CORE_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 3e5635d..abfb77e 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -14,6 +14,9 @@
> #include <linux/module.h>
> #include <linux/ftrace.h>
> 
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/core.h>
> +
> #include "trace.h"
> 
> static struct trace_array		*irqsoff_trace __read_mostly;
> @@ -339,6 +342,8 @@ check_critical_timing(struct trace_array *tr,
> 		/* Skip 5 functions to get to the irq/preempt enable function */
> 		__trace_stack(tr, flags, 5, pc);
> 	}
> +	trace_core_critical_timing_hit(CALLER_ADDR0, parent_ip, flags, pc,
> +			delta);
> 
> 	if (data->critical_sequence != max_sequence)
> 		goto out_unlock;
> @@ -365,7 +370,7 @@ out:
> static inline void
> start_critical_timing(unsigned long ip, unsigned long parent_ip)
> {
> -	int cpu;
> +	int cpu, pc;
> 	struct trace_array *tr = irqsoff_trace;
> 	struct trace_array_cpu *data;
> 	unsigned long flags;
> @@ -390,8 +395,10 @@ start_critical_timing(unsigned long ip, unsigned long
> parent_ip)
> 	data->critical_start = parent_ip ? : ip;
> 
> 	local_save_flags(flags);
> +	pc = preempt_count();
> 	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
> -		__trace_function(tr, ip, parent_ip, flags, preempt_count());
> +		__trace_function(tr, ip, parent_ip, flags, pc);
> +	trace_core_critical_timing_start(ip, parent_ip, flags, pc);
> 	per_cpu(tracing_cpu, cpu) = 1;
> 
> 	atomic_dec(&data->disabled);
> @@ -400,7 +407,7 @@ start_critical_timing(unsigned long ip, unsigned long
> parent_ip)
> static inline void
> stop_critical_timing(unsigned long ip, unsigned long parent_ip)
> {
> -	int cpu;
> +	int cpu, pc;
> 	struct trace_array *tr = irqsoff_trace;
> 	struct trace_array_cpu *data;
> 	unsigned long flags;
> @@ -424,8 +431,10 @@ stop_critical_timing(unsigned long ip, unsigned long
> parent_ip)
> 	atomic_inc(&data->disabled);
> 
> 	local_save_flags(flags);
> +	pc = preempt_count();
> 	if (trace_flags & TRACE_ITER_FTRACE_BUFFER)
> -		__trace_function(tr, ip, parent_ip, flags, preempt_count());
> +		__trace_function(tr, ip, parent_ip, flags, pc);
> +	trace_core_critical_timing_stop(ip, parent_ip, flags, pc);
> 	check_critical_timing(tr, data, parent_ip ? : ip, cpu);
> 	data->critical_start = 0;
> 	atomic_dec(&data->disabled);
> --
> 2.1.4

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [PATCH v2 3/3] trace: emit tracepoint in preempt and irqs off tracer

[Steven Rostedt]

On Wed, 18 Nov 2015 14:39:31 +0000 (UTC)
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> ----- On Nov 2, 2015, at 5:42 PM, Mathieu Desnoyers mathieu.desnoyers@efficios.com wrote:
> 
> > Allow Ftrace, Perf, and LTTng to hook on the irqsoff tracer and trace
> > irqsoff and preemptoff critical sections.  
> 
> Hi Steven,
> 
> I guess you ended up being busy lately. Your feedback on this patchset
> is still very welcome.

Bah, I started looking at this three times and was pulled away each
time. I still want to finish my review. I'm going to be traveling today
so I don't want to guarantee anything. I'm driving this time so there's
not going to be a "review it on the plane" possibility.

-- Steve

> 
> Thanks,
> 

Re: [PATCH v2 3/3] trace: emit tracepoint in preempt and irqs off tracer

[Thomas Gleixner]

On Wed, 18 Nov 2015, Steven Rostedt wrote:
> Bah, I started looking at this three times and was pulled away each
> time. I still want to finish my review. I'm going to be traveling today
> so I don't want to guarantee anything. I'm driving this time so there's
> not going to be a "review it on the plane" possibility.

Get one of those self driving cars already!

Re: [PATCH 1/3] Tracepoint: fix documentation of RCU lockdep checks

[Steven Rostedt]

On Mon,  2 Nov 2015 17:42:42 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> The documentation on top of __DECLARE_TRACE() does not match its
> implementation since the condition check has been added to the
> RCU lockdep checks. Update the documentation to match its
> implementation.
> 

Thanks, I can pull this now for 4.4.

-- Steve

> Fixes: a05d59a56733 "tracing: Add condition check to RCU lockdep checks"
> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> CC: Dave Hansen <dave@sr71.net>
> CC: Steven Rostedt <rostedt@goodmis.org>
> ---
>  include/linux/tracepoint.h | 9 +++++----
>  1 file changed, 5 insertions(+), 4 deletions(-)
> 
> diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
> index a5f7f3e..c8e3030 100644
> --- a/include/linux/tracepoint.h
> +++ b/include/linux/tracepoint.h
> @@ -167,10 +167,11 @@ extern void syscall_unregfunc(void);
>   * structure. Force alignment to the same alignment as the section start.
>   *
>   * When lockdep is enabled, we make sure to always do the RCU portions of
> - * the tracepoint code, regardless of whether tracing is on or we match the
> - * condition.  This lets us find RCU issues triggered with tracepoints even
> - * when this tracepoint is off.  This code has no purpose other than poking
> - * RCU a bit.
> + * the tracepoint code, regardless of whether tracing is on. However,
> + * don't check if the condition is false, due to interaction with idle
> + * instrumentation. This lets us find RCU issues triggered with tracepoints
> + * even when this tracepoint is off. This code has no purpose other than
> + * poking RCU a bit.
>   */
>  #define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \
>  	extern struct tracepoint __tracepoint_##name;			\