Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1725628 > unrolled thread

[PATCH 2/2] tracing: Add support for critical section events

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-03 11:00 +0200
    Re: [PATCH 2/2] tracing: Add support for critical section events Peter Zijlstra <peterz@infradead.org> - 2017-09-04 10:00 +0200
      Re: [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-04 21:10 +0200
        Re: [PATCH 2/2] tracing: Add support for critical section events Peter Zijlstra <peterz@infradead.org> - 2017-09-04 21:50 +0200
          Re: [PATCH 2/2] tracing: Add support for critical section events Steven Rostedt <rostedt@goodmis.org> - 2017-09-05 01:40 +0200
            Re: [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-05 03:00 +0200
              Re: [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-05 05:30 +0200
                Re: [PATCH 2/2] tracing: Add support for critical section events Peter Zijlstra <peterz@infradead.org> - 2017-09-05 09:00 +0200
                  Re: [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-05 18:40 +0200
                    Re: [PATCH 2/2] tracing: Add support for critical section events Peter Zijlstra <peterz@infradead.org> - 2017-09-06 10:50 +0200
                      Re: [PATCH 2/2] tracing: Add support for critical section events Joel Fernandes <joelaf@google.com> - 2017-09-07 02:30 +0200

#1725628 — [PATCH 2/2] tracing: Add support for critical section events

Critical section trace events can be used for tracing the start and
end of a critical section which can be used by a trace viewer like
systrace to graphically view the start and end of a critical section and
correlate them with latencies and scheduling issues.

Reason for starting critical section:
Either preemption or interrupts were turned off.
Reason for ending critical section:
Both preemption and interrupts are now turned back on.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: kernel-team@android.com
Signed-off-by: Joel Fernandes <joelaf@google.com>
---
 include/linux/ftrace.h          |  2 +-
 include/linux/irqflags.h        |  3 +-
 include/trace/events/critical.h | 45 +++++++++++++++++++
 kernel/trace/Kconfig            |  5 +++
 kernel/trace/Makefile           |  1 +
 kernel/trace/trace_irqsoff.c    | 97 +++++++++++++++++++++++++++++++++++++++--
 6 files changed, 147 insertions(+), 6 deletions(-)
 create mode 100644 include/trace/events/critical.h

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 6383115e9d2c..6020c473a198 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -742,7 +742,7 @@ static inline unsigned long get_lock_parent_ip(void)
   static inline void time_hardirqs_off(unsigned long a0, unsigned long a1) { }
 #endif
 
-#ifdef CONFIG_PREEMPT_TRACER
+#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_CRITICAL_SECTION_EVENTS)
   extern void trace_preempt_on(unsigned long a0, unsigned long a1);
   extern void trace_preempt_off(unsigned long a0, unsigned long a1);
 #else
diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h
index 9bc050bc81b2..79c372fe9dcb 100644
--- a/include/linux/irqflags.h
+++ b/include/linux/irqflags.h
@@ -61,7 +61,8 @@ do {						\
 #endif
 
 #if defined(CONFIG_IRQSOFF_TRACER) || \
-	defined(CONFIG_PREEMPT_TRACER)
+	defined(CONFIG_PREEMPT_TRACER) || \
+	defined(CONFIG_CRITICAL_SECTION_EVENTS)
  extern void stop_critical_timings(void);
  extern void start_critical_timings(void);
 #else
diff --git a/include/trace/events/critical.h b/include/trace/events/critical.h
new file mode 100644
index 000000000000..bd07a6a50252
--- /dev/null
+++ b/include/trace/events/critical.h
@@ -0,0 +1,45 @@
+#ifdef CONFIG_CRITICAL_SECTION_EVENTS
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM critical
+
+#if !defined(_TRACE_CRITICAL_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CRITICAL_H
+
+#include <linux/ktime.h>
+#include <linux/tracepoint.h>
+#include <linux/string.h>
+#include <asm/sections.h>
+
+DECLARE_EVENT_CLASS(critical_template,
+
+	TP_PROTO(unsigned long ip, unsigned long parent_ip),
+
+	TP_ARGS(ip, parent_ip),
+
+	TP_STRUCT__entry(
+		__field(u32, caller_offs)
+		__field(u32, parent_offs)
+	),
+
+	TP_fast_assign(
+		__entry->caller_offs = (u32)(ip - (unsigned long)_stext);
+		__entry->parent_offs = (u32)(parent_ip - (unsigned long)_stext);
+	),
+
+	TP_printk("caller=%pF parent=%pF\n",
+		  (void *)((unsigned long)(_stext) + __entry->caller_offs),
+		  (void *)((unsigned long)(_stext) + __entry->parent_offs))
+);
+
+DEFINE_EVENT(critical_template, critical_start,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+
+DEFINE_EVENT(critical_template, critical_stop,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+#endif /* _TRACE_CRITICAL_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
+#endif
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 434c840e2d82..c08b23fcae6d 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -209,6 +209,11 @@ config PREEMPT_TRACER
 	  enabled. This option and the irqs-off timing option can be
 	  used together or separately.)
 
+config CRITICAL_SECTION_EVENTS
+	bool "Trace critical sections as trace events"
+	select TRACE_IRQFLAGS
+	default n
+
 config SCHED_TRACER
 	bool "Scheduling Latency Tracer"
 	select GENERIC_TRACER
diff --git a/kernel/trace/Makefile b/kernel/trace/Makefile
index 90f2701d92a7..265135e35b79 100644
--- a/kernel/trace/Makefile
+++ b/kernel/trace/Makefile
@@ -36,6 +36,7 @@ obj-$(CONFIG_CONTEXT_SWITCH_TRACER) += trace_sched_switch.o
 obj-$(CONFIG_FUNCTION_TRACER) += trace_functions.o
 obj-$(CONFIG_IRQSOFF_TRACER) += trace_irqsoff.o
 obj-$(CONFIG_PREEMPT_TRACER) += trace_irqsoff.o
+obj-$(CONFIG_CRITICAL_SECTION_EVENTS) += trace_irqsoff.o
 obj-$(CONFIG_SCHED_TRACER) += trace_sched_wakeup.o
 obj-$(CONFIG_HWLAT_TRACER) += trace_hwlat.o
 obj-$(CONFIG_NOP_TRACER) += trace_nop.o
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index edd52ee8b756..7f59f41fbdc0 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -13,9 +13,69 @@
 #include <linux/uaccess.h>
 #include <linux/module.h>
 #include <linux/ftrace.h>
+#define CREATE_TRACE_POINTS
+#include <trace/events/critical.h>
 
 #include "trace.h"
 
+#ifdef CONFIG_CRITICAL_SECTION_EVENTS
+static DEFINE_PER_CPU(int, tracing_events_cpu);
+
+/*
+ * Called when either preempt or irq are turned off
+ */
+static inline void
+start_critical_event(unsigned long ip, unsigned long parent_ip)
+{
+	if (this_cpu_read(tracing_events_cpu))
+		return;
+
+	this_cpu_write(tracing_events_cpu, 1);
+	trace_critical_start(ip, parent_ip);
+}
+
+/*
+ * Called when both preempt and irq are turned back on
+ */
+static inline void
+stop_critical_event(unsigned long ip, unsigned long parent_ip)
+{
+	if (!this_cpu_read(tracing_events_cpu))
+		return;
+
+	trace_critical_stop(ip, parent_ip);
+	this_cpu_write(tracing_events_cpu, 0);
+}
+
+static inline int
+__trace_critical_start_enabled(void)
+{
+	if (irqs_disabled() || preempt_count())
+		return 1;
+
+	return 0;
+}
+
+static inline int
+__trace_critical_stop_enabled(void)
+{
+	if ((irqs_disabled() && !preempt_count()) ||
+	    (!irqs_disabled() && preempt_count()))
+		return 1;
+
+	return 0;
+}
+#else
+
+static inline void start_critical_event(unsigned long ip,
+					unsigned long pip) { }
+static inline void stop_critical_event(unsigned long ip,
+					unsigned long pip) { }
+
+static inline int __trace_critical_start_enabled(void) { return 0; }
+static inline int __trace_critical_stop_enabled(void) { return 0; }
+#endif
+
 #if defined(CONFIG_IRQSOFF_TRACER) || defined(CONFIG_PREEMPT_TRACER)
 static struct trace_array		*irqsoff_trace __read_mostly;
 static int				tracer_enabled __read_mostly;
@@ -710,7 +770,7 @@ void time_hardirqs_off(unsigned long a0, unsigned long a1)
 }
 #endif
 #else /* !CONFIG_PROVE_LOCKING */
-# ifdef CONFIG_IRQSOFF_TRACER
+# if defined(CONFIG_IRQSOFF_TRACER) || defined(CONFIG_CRITICAL_SECTION_EVENTS)
 
 /*
  * Stubs:
@@ -733,6 +793,9 @@ inline void print_irqtrace_events(struct task_struct *curr)
  */
 void trace_hardirqs_on(void)
 {
+	if (__trace_critical_stop_enabled())
+		stop_critical_event(CALLER_ADDR0, CALLER_ADDR1);
+
 	if (!preempt_trace() && irq_trace())
 		stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
 }
@@ -740,6 +803,9 @@ EXPORT_SYMBOL(trace_hardirqs_on);
 
 void trace_hardirqs_off(void)
 {
+	if (__trace_critical_start_enabled())
+		start_critical_event(CALLER_ADDR0, CALLER_ADDR1);
+
 	if (!preempt_trace() && irq_trace())
 		start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
 }
@@ -747,6 +813,9 @@ EXPORT_SYMBOL(trace_hardirqs_off);
 
 __visible void trace_hardirqs_on_caller(unsigned long caller_addr)
 {
+	if (__trace_critical_stop_enabled())
+		stop_critical_event(CALLER_ADDR0, caller_addr);
+
 	if (!preempt_trace() && irq_trace())
 		stop_critical_timing(CALLER_ADDR0, caller_addr);
 }
@@ -754,32 +823,44 @@ EXPORT_SYMBOL(trace_hardirqs_on_caller);
 
 __visible void trace_hardirqs_off_caller(unsigned long caller_addr)
 {
+	if (__trace_critical_start_enabled())
+		start_critical_event(CALLER_ADDR0, caller_addr);
+
 	if (!preempt_trace() && irq_trace())
 		start_critical_timing(CALLER_ADDR0, caller_addr);
 }
 EXPORT_SYMBOL(trace_hardirqs_off_caller);
 
-#endif /*  CONFIG_IRQSOFF_TRACER */
+#endif /*  CONFIG_IRQSOFF_TRACER || CONFIG_CRITICAL_SECTION_EVENTS */
 #endif /* CONFIG_PROVE_LOCKING */
 
-#ifdef CONFIG_PREEMPT_TRACER
+#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_CRITICAL_SECTION_EVENTS)
 void trace_preempt_on(unsigned long a0, unsigned long a1)
 {
+	if (__trace_critical_stop_enabled())
+		stop_critical_event(a0, a1);
+
 	if (preempt_trace() && !irq_trace())
 		stop_critical_timing(a0, a1);
 }
 
 void trace_preempt_off(unsigned long a0, unsigned long a1)
 {
+	if (__trace_critical_start_enabled())
+		start_critical_event(a0, a1);
+
 	if (preempt_trace() && !irq_trace())
 		start_critical_timing(a0, a1);
 }
-#endif /* CONFIG_PREEMPT_TRACER */
+#endif /* CONFIG_PREEMPT_TRACER || CONFIG_CRITICAL_SECTION_EVENTS */
 
 
 /* start and stop critical timings used to for stoppage (in idle) */
 void start_critical_timings(void)
 {
+	if (__trace_critical_start_enabled())
+		start_critical_event(CALLER_ADDR0, CALLER_ADDR1);
+
 	if (preempt_trace() || irq_trace())
 		start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
 }
@@ -787,6 +868,14 @@ EXPORT_SYMBOL_GPL(start_critical_timings);
 
 void stop_critical_timings(void)
 {
+	/*
+	 * we have to use *_start_enabled instead of *_stop_enabled
+	 * because the condition for stopping critical timings is
+	 * whether a critical section was entered before entering idle
+	 */
+	if (__trace_critical_start_enabled())
+		stop_critical_event(CALLER_ADDR0, CALLER_ADDR1);
+
 	if (preempt_trace() || irq_trace())
 		stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
 }
-- 
2.14.1.581.gf28d330327-goog

[toc] | [next] | [standalone]

#1725908

On Sun, Sep 03, 2017 at 01:50:51AM -0700, Joel Fernandes wrote:
> Critical section trace events can be used for tracing the start and
> end of a critical section which can be used by a trace viewer like
> systrace to graphically view the start and end of a critical section and
> correlate them with latencies and scheduling issues.
> 
> Reason for starting critical section:
> Either preemption or interrupts were turned off.
> Reason for ending critical section:
> Both preemption and interrupts are now turned back on.

Please don't use the name critical section for this. Also IRQ and
preempt already have a gazillion trace hooks, why do we need more?

[toc] | [prev] | [next] | [standalone]

#1726225

Hi Peter,

On Mon, Sep 4, 2017 at 12:56 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Sun, Sep 03, 2017 at 01:50:51AM -0700, Joel Fernandes wrote:
>> Critical section trace events can be used for tracing the start and
>> end of a critical section which can be used by a trace viewer like
>> systrace to graphically view the start and end of a critical section and
>> correlate them with latencies and scheduling issues.
>>
>> Reason for starting critical section:
>> Either preemption or interrupts were turned off.
>> Reason for ending critical section:
>> Both preemption and interrupts are now turned back on.
>
> Please don't use the name critical section for this.

I can change the name to something else, but at the moment I can't
think of anything better. Could you suggest a better name? Also btw,
'critical timings' is the terminology used within the irqsoff tracer
so this is in line with that.

> Also IRQ and preempt already have a gazillion trace hooks, why do we need more?

I think I didn't CC you on the coverletter (that's my bad). That's Ok
I'll point to links below.
The goal of the patch is not to add more hooks, but to make it
possible for userspace to use the trace-events mechanism to see these
events, so that these events can be seen along with other trace events
when using event tracing, using a convenient trace event interface
which can be enabled by userspace. This makes it possible to visually
see these events as a timeline along with other kernel and userspace
events. See more description in my coverletter [1] and a screenshot of
how this is used [2] by the systrace trace viewer. These patches make
it possible for this.

Also, this work is along the same lines of what we discussed in a
recent conference about adding irqsoff and preemptoff as real trace
events, and then using synthetic events (which can combine start and
end event into a single event) to redo the irqsoff tracer, so in that
sense it is in the right direction. Synthetic events is some time away
though from being merged AFAIK.

thanks,

- Joel

[1] https://lkml.org/lkml/2017/9/3/15
[2] http://imgur.com/download/TZplEVp
[3] all patches:
    https://patchwork.kernel.org/patch/9936047/
    https://patchwork.kernel.org/patch/9936045/

[toc] | [prev] | [next] | [standalone]

#1726232

On Mon, Sep 04, 2017 at 12:04:44PM -0700, Joel Fernandes wrote:
> Hi Peter,
> 
> On Mon, Sep 4, 2017 at 12:56 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> > On Sun, Sep 03, 2017 at 01:50:51AM -0700, Joel Fernandes wrote:
> >> Critical section trace events can be used for tracing the start and
> >> end of a critical section which can be used by a trace viewer like
> >> systrace to graphically view the start and end of a critical section and
> >> correlate them with latencies and scheduling issues.
> >>
> >> Reason for starting critical section:
> >> Either preemption or interrupts were turned off.
> >> Reason for ending critical section:
> >> Both preemption and interrupts are now turned back on.
> >
> > Please don't use the name critical section for this.
> 
> I can change the name to something else, but at the moment I can't
> think of anything better. Could you suggest a better name? Also btw,
> 'critical timings' is the terminology used within the irqsoff tracer
> so this is in line with that.

So 'critical section' is what some mis-guided people call the locked
region of a lock :-) Using it for something else is prone to cause more
confusion...

I would simply call them what they are: irq_disable,irq_enable
preempt_disable,preempt_enable.

> > Also IRQ and preempt already have a gazillion trace hooks, why do we need more?
> 
> The goal of the patch is not to add more hooks, but to make it
> possible for userspace to use the trace-events mechanism to see these
> events, so that these events can be seen along with other trace events
> when using event tracing, using a convenient trace event interface
> which can be enabled by userspace. 

But only when you're already building a debug kernel and we already have
these irq/preempt trace things in, right?

> This makes it possible to visually
> see these events as a timeline along with other kernel and userspace
> events. See more description in my coverletter [1] and a screenshot of
> how this is used [2] by the systrace trace viewer. These patches make
> it possible for this.

Yeah, for some reason these graphics things don't work for me... And
regular traces already have the irq-off and preempt-depth column, which
typically is enough. But I suppose I can see the value of allowing
explicit events for them.

> Also, this work is along the same lines of what we discussed in a
> recent conference about adding irqsoff and preemptoff as real trace
> events, and then using synthetic events (which can combine start and
> end event into a single event) to redo the irqsoff tracer, so in that
> sense it is in the right direction. Synthetic events is some time away
> though from being merged AFAIK.

I have no memories of that, but that sounds OK :-)

[toc] | [prev] | [next] | [standalone]

#1726286

On Mon, 4 Sep 2017 21:44:26 +0200
Peter Zijlstra <peterz@infradead.org> wrote:

> > I can change the name to something else, but at the moment I can't
> > think of anything better. Could you suggest a better name? Also btw,
> > 'critical timings' is the terminology used within the irqsoff tracer
> > so this is in line with that.  
> 
> So 'critical section' is what some mis-guided people call the locked
> region of a lock :-) Using it for something else is prone to cause more
> confusion...
> 
> I would simply call them what they are: irq_disable,irq_enable
> preempt_disable,preempt_enable.

Yes please. The "critical section" naming came from the code that was
from the latency tracer days of the real time patch (pre-ftrace). The
irqsoff tracer has the least modification from the original code, and
probably should be rewritten one of these days.

-- Steve

[toc] | [prev] | [next] | [standalone]

#1726297

On Mon, Sep 4, 2017 at 4:34 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Mon, 4 Sep 2017 21:44:26 +0200
> Peter Zijlstra <peterz@infradead.org> wrote:
>
>> > I can change the name to something else, but at the moment I can't
>> > think of anything better. Could you suggest a better name? Also btw,
>> > 'critical timings' is the terminology used within the irqsoff tracer
>> > so this is in line with that.
>>
>> So 'critical section' is what some mis-guided people call the locked
>> region of a lock :-) Using it for something else is prone to cause more
>> confusion...
>>
>> I would simply call them what they are: irq_disable,irq_enable
>> preempt_disable,preempt_enable.
>
> Yes please. The "critical section" naming came from the code that was
> from the latency tracer days of the real time patch (pre-ftrace). The
> irqsoff tracer has the least modification from the original code, and
> probably should be rewritten one of these days.

Sounds good to me. For the subsystem, could you guys suggest a name? I
was thinking "atomic_section"?

Something like:

subsystem: atomic_section
events:
  irqsoff_disable
  irqsoff_enable
  preemptoff_disable
  preemptoff_enable

and additionally (to do what my patch does):
  preemptirqsoff_enable
  preemptirqsoff_disable

Does this sound good to you?

I did bulk of the work today for moving code from the irqsoff tracer
into a common area that's irqsoff tracer specific, and now I'm getting
close to the point of creating the above tracepoints and posting
another series, but I wanted to get your thoughts on the above.

I like this new approach better because the next logically step ontop
of this work can be to rewrite irqsoff tracer by using probes on the
above tracepoints (which I'll do once we can get these in).

thanks,

- Joel

[toc] | [prev] | [next] | [standalone]

#1726327

On Mon, Sep 4, 2017 at 5:54 PM, Joel Fernandes <joelaf@google.com> wrote:
> On Mon, Sep 4, 2017 at 4:34 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
>> On Mon, 4 Sep 2017 21:44:26 +0200
>> Peter Zijlstra <peterz@infradead.org> wrote:
>>
>>> > I can change the name to something else, but at the moment I can't
>>> > think of anything better. Could you suggest a better name? Also btw,
>>> > 'critical timings' is the terminology used within the irqsoff tracer
>>> > so this is in line with that.
>>>
>>> So 'critical section' is what some mis-guided people call the locked
>>> region of a lock :-) Using it for something else is prone to cause more
>>> confusion...
>>>
>>> I would simply call them what they are: irq_disable,irq_enable
>>> preempt_disable,preempt_enable.
>>
>> Yes please. The "critical section" naming came from the code that was
>> from the latency tracer days of the real time patch (pre-ftrace). The
>> irqsoff tracer has the least modification from the original code, and
>> probably should be rewritten one of these days.
>
> Sounds good to me. For the subsystem, could you guys suggest a name? I
> was thinking "atomic_section"?
>
> Something like:
>
> subsystem: atomic_section
> events:
>   irqsoff_disable
>   irqsoff_enable
>   preemptoff_disable
>   preemptoff_enable
>
> and additionally (to do what my patch does):
>   preemptirqsoff_enable
>   preemptirqsoff_disable

Apologies, I meant (without the "off"):

subsystem: atomic_section
events:
  irqs_disable
  irqs_enable
  preempt_disable
  preempt_enable

and additionally (similar to what my patch does):
  preemptirq_enable
  preemptirq_disable


Could you let me know if we are in agreement about this naming?

thanks,

-Joel

[toc] | [prev] | [next] | [standalone]

#1726381

On Mon, Sep 04, 2017 at 08:26:13PM -0700, Joel Fernandes wrote:

> Apologies, I meant (without the "off"):
> 
> subsystem: atomic_section
> events:
>   irqs_disable
>   irqs_enable
>   preempt_disable
>   preempt_enable
> 
> and additionally (similar to what my patch does):
>   preemptirq_enable
>   preemptirq_disable
> 

What do you need the last for?

[toc] | [prev] | [next] | [standalone]

#1726841

On Mon, Sep 4, 2017 at 11:52 PM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Mon, Sep 04, 2017 at 08:26:13PM -0700, Joel Fernandes wrote:
>
>> Apologies, I meant (without the "off"):
>>
>> subsystem: atomic_section
>> events:
>>   irqs_disable
>>   irqs_enable
>>   preempt_disable
>>   preempt_enable
>>
>> and additionally (similar to what my patch does):
>>   preemptirq_enable
>>   preemptirq_disable
>>
>
> What do you need the last for?

The last 2 events above behave as 'disable' means either preempt or
irq got disabled, and 'enable' means *both* preempt and irq are
enabled (after either one of them was disabled).

This has the advantage of not generating events when we're already in
an atomic section when using these events, for example acquiring spin
locks in an interrupt handler might increase the preempt count and
generate 'preempt_disable' events, but not preemptirq_disable events.
This has the effect of reducing the spam in the traces when all we
care about is being in an atomic section or not. These events happen a
lot so to conserve space in the trace buffer, the user may want to
just enable the latter 2 events. Does that sound Ok to you?

thanks,

- Joel

[toc] | [prev] | [next] | [standalone]

#1727241

On Tue, Sep 05, 2017 at 09:35:11AM -0700, Joel Fernandes wrote:
> On Mon, Sep 4, 2017 at 11:52 PM, Peter Zijlstra <peterz@infradead.org> wrote:
> > On Mon, Sep 04, 2017 at 08:26:13PM -0700, Joel Fernandes wrote:
> >
> >> Apologies, I meant (without the "off"):
> >>
> >> subsystem: atomic_section
> >> events:
> >>   irqs_disable
> >>   irqs_enable
> >>   preempt_disable
> >>   preempt_enable
> >>
> >> and additionally (similar to what my patch does):
> >>   preemptirq_enable
> >>   preemptirq_disable
> >>
> >
> > What do you need the last for?
> 
> The last 2 events above behave as 'disable' means either preempt or
> irq got disabled, and 'enable' means *both* preempt and irq are
> enabled (after either one of them was disabled).
> 
> This has the advantage of not generating events when we're already in
> an atomic section when using these events, for example acquiring spin
> locks in an interrupt handler might increase the preempt count and
> generate 'preempt_disable' events, but not preemptirq_disable events.
> This has the effect of reducing the spam in the traces when all we
> care about is being in an atomic section or not. These events happen a
> lot so to conserve space in the trace buffer, the user may want to
> just enable the latter 2 events. Does that sound Ok to you?

Hurm,... how about placing a filter on the other 4, such that we only
emit the event on 0<->x state transitions? IIRC tracing already has
filter bits and eBPF bits on that allow something like that.

That avoids having to introduce more tracepoints and gets you the same
results.

[toc] | [prev] | [next] | [standalone]

#1727844

Hi Peter,

On Wed, Sep 6, 2017 at 1:40 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Tue, Sep 05, 2017 at 09:35:11AM -0700, Joel Fernandes wrote:
>> On Mon, Sep 4, 2017 at 11:52 PM, Peter Zijlstra <peterz@infradead.org> wrote:
>> > On Mon, Sep 04, 2017 at 08:26:13PM -0700, Joel Fernandes wrote:
>> >
>> >> Apologies, I meant (without the "off"):
>> >>
>> >> subsystem: atomic_section
>> >> events:
>> >>   irqs_disable
>> >>   irqs_enable
>> >>   preempt_disable
>> >>   preempt_enable
>> >>
>> >> and additionally (similar to what my patch does):
>> >>   preemptirq_enable
>> >>   preemptirq_disable
>> >>
>> >
>> > What do you need the last for?
>>
>> The last 2 events above behave as 'disable' means either preempt or
>> irq got disabled, and 'enable' means *both* preempt and irq are
>> enabled (after either one of them was disabled).
>>
>> This has the advantage of not generating events when we're already in
>> an atomic section when using these events, for example acquiring spin
>> locks in an interrupt handler might increase the preempt count and
>> generate 'preempt_disable' events, but not preemptirq_disable events.
>> This has the effect of reducing the spam in the traces when all we
>> care about is being in an atomic section or not. These events happen a
>> lot so to conserve space in the trace buffer, the user may want to
>> just enable the latter 2 events. Does that sound Ok to you?
>
> Hurm,... how about placing a filter on the other 4, such that we only
> emit the event on 0<->x state transitions? IIRC tracing already has
> filter bits and eBPF bits on that allow something like that.
>
> That avoids having to introduce more tracepoints and gets you the same
> results.

Sure, that sounds fine to me. I dropped the last 2 events from a
repost of the series since we can add that in (combined preempt and
irq) at a later time using similar methods as you're suggesting.

thanks,

-Joel

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web