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


Groups > linux.kernel > #1742369

[PATCH v7 2/2] tracing: Add support for preempt and irq enable/disable events

Path csiph.com!weretis.net!feeder4.news.weretis.net!news.unit0.net!news.panservice.it!bofh.it!news.nic.it!robomod
From Joel Fernandes <joelaf@google.com>
Newsgroups linux.kernel
Subject [PATCH v7 2/2] tracing: Add support for preempt and irq enable/disable events
Date Fri, 29 Sep 2017 23:30:02 +0200
Message-ID <uvb18-3ao-17@gated-at.bofh.it> (permalink)
References <uvb18-3ao-19@gated-at.bofh.it>
Dkim-Signature v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references; bh=ujh8P/OA9mGMEGVWFAZJuKDlpAcHl9JvOzMgerhi3y8=; b=Mg2xfjOpyDMdXtgpQqUYXFXdslJHsj8JDSkFNyWOOftqmWzd5uBFjlZc0t6n3jKE5w 0NN7tlQtuENTi4D0F8gv9s2i2B5MPZnphEB6fENr+xTRs5hwG7PBWjRTVUGp3uhOiCxQ OzOz+/e/QIkJy0KRhJzWO1suyDgDx8dpc4uRLBFZZSn+g2wdDiy2oMzDsujyPMEMFVfh 5GxZvbWVY5LIw4qDFfgFCoOlXzrW5CShpCY+h2Z8onChoQX2J+i/D8KVyeD/YgPcJkwd eu3rlN2JWvrITgcccjOx0jRn8Wa+ojY4rxLBy9r9iH7bPsaJMaqxyUvmx5XVKo4/NvQC ig1w==
X-Google-Dkim-Signature v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references; bh=ujh8P/OA9mGMEGVWFAZJuKDlpAcHl9JvOzMgerhi3y8=; b=nWQNY3cXQE7iEJqEcIVxRDTgaihScAxrO5uBCBqfyIwJvaD97SwPO7sKDm/Z8x3yvm wIPcbrlpALcM2pWLzxDho1RljvrpaGGTy1KIsyI2HD+JF7Yf0gSnvKML3FOuWIzZdo8c a4xmFUER6cbOyegk9DEjUMPf64FtInMW7mCfhb2pVt6YY2X/+LLnFqViF9LXvFDohjmq yZ6deipBNR17Bg00SSYcllsdBkcx0Y9hsMRdrTVJ/ihJcj4ulzyuoTTKQJ0D1LhvnDtE sV1Mb3Lxb8MsRaTSdiAkPWdtiFcRd6TUCufZbOU4jPpvAI6mFaH87D47F6s8v8t31gJB mXIg==
X-Gm-Message-State AHPjjUh5d5gMrW4Hol+zcw0iBQaKWs82+mWjt6A1vaeFgaaoQJ6ZMhEq oohMiyhyzDUWwbJpbp/PhjYcMdpTYFU=
X-Google-SMTP-Source AOwi7QCHrm+CEliPQE8LysJySAIHesfTmvk5lF0v6Asqk3gNXG4VgwU3h3Bl5B+zX6orRAwXmL8UsA==
X-Received by 10.84.238.201 with SMTP id l9mr8131026pln.159.1506720170019; Fri, 29 Sep 2017 14:22:50 -0700 (PDT)
X-Mailer git-send-email 2.14.2.822.g60be5d43e6-goog
Sender robomod@news.nic.it
List-ID <linux-kernel.vger.kernel.org>
X-Mailing-List linux-kernel@vger.kernel.org
Approved robomod@news.nic.it
Lines 236
Organization linux.* mail to news gateway
X-Original-Cc kernel-team@android.com, Joel Fernandes <joelaf@google.com>, Steven Rostedt <rostedt@goodmis.org>, Peter Zilstra <peterz@infradead.org>
X-Original-Date Fri, 29 Sep 2017 14:22:45 -0700
X-Original-Message-ID <20170929212245.24168-2-joelaf@google.com>
X-Original-References <20170929212245.24168-1-joelaf@google.com>
X-Original-Sender linux-kernel-owner@vger.kernel.org
Xref csiph.com linux.kernel:1742369

Show key headers only | View raw


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

This also serves as a prelude to using synthetic events or probes to
rewrite the preempt and irqsoff tracers, along with numerous benefits of
using trace events features for these events.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Peter Zilstra <peterz@infradead.org>
Cc: kernel-team@android.com
Signed-off-by: Joel Fernandes <joelaf@google.com>
---
 include/linux/ftrace.h            |  3 +-
 include/trace/events/preemptirq.h | 66 +++++++++++++++++++++++++++++++++++++++
 kernel/trace/Kconfig              |  9 ++++++
 kernel/trace/Makefile             |  1 +
 kernel/trace/trace_irqsoff.c      | 41 +++++++++++++++++++++++-
 5 files changed, 118 insertions(+), 2 deletions(-)
 create mode 100644 include/trace/events/preemptirq.h

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 2e028854bac7..768e49b8c80f 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -742,7 +742,8 @@ 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_DEBUG_PREEMPT) && defined(CONFIG_PREEMPTIRQ_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/trace/events/preemptirq.h b/include/trace/events/preemptirq.h
new file mode 100644
index 000000000000..734b7e2a3890
--- /dev/null
+++ b/include/trace/events/preemptirq.h
@@ -0,0 +1,66 @@
+#ifdef CONFIG_PREEMPTIRQ_EVENTS
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM preemptirq
+
+#if !defined(_TRACE_PREEMPTIRQ_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_PREEMPTIRQ_H
+
+#include <linux/ktime.h>
+#include <linux/tracepoint.h>
+#include <linux/string.h>
+#include <asm/sections.h>
+
+DECLARE_EVENT_CLASS(preemptirq_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",
+		  (void *)((unsigned long)(_stext) + __entry->caller_offs),
+		  (void *)((unsigned long)(_stext) + __entry->parent_offs))
+);
+
+DEFINE_EVENT(preemptirq_template, irq_disable,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+
+DEFINE_EVENT(preemptirq_template, irq_enable,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+
+DEFINE_EVENT(preemptirq_template, preempt_disable,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+
+DEFINE_EVENT(preemptirq_template, preempt_enable,
+	     TP_PROTO(unsigned long ip, unsigned long parent_ip),
+	     TP_ARGS(ip, parent_ip));
+
+#endif /* _TRACE_PREEMPTIRQ_H */
+
+#include <trace/define_trace.h>
+
+#else /* !CONFIG_PREEMPTIRQ_EVENTS */
+
+#define trace_irq_enable(...)
+#define trace_irq_disable(...)
+#define trace_preempt_enable(...)
+#define trace_preempt_disable(...)
+#define trace_irq_enable_rcuidle(...)
+#define trace_irq_disable_rcuidle(...)
+#define trace_preempt_enable_rcuidle(...)
+#define trace_preempt_disable_rcuidle(...)
+
+#endif
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 434c840e2d82..420666152de8 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -160,6 +160,15 @@ config FUNCTION_GRAPH_TRACER
 	  address on the current task structure into a stack of calls.
 
 
+config PREEMPTIRQ_EVENTS
+	bool "Enable trace events for preempt and irq disable/enable"
+	select TRACE_IRQFLAGS
+	default n
+	help
+	  Enable tracing of disable and enable events for preemption and irqs.
+	  For tracing preempt disable/enable events, CONFIG_DEBUG_PREEMPT must
+	  be enabled.
+
 config IRQSOFF_TRACER
 	bool "Interrupts-off Latency Tracer"
 	default n
diff --git a/kernel/trace/Makefile b/kernel/trace/Makefile
index 90f2701d92a7..9f62eee61f14 100644
--- a/kernel/trace/Makefile
+++ b/kernel/trace/Makefile
@@ -34,6 +34,7 @@ obj-$(CONFIG_TRACING) += trace_printk.o
 obj-$(CONFIG_TRACING_MAP) += tracing_map.o
 obj-$(CONFIG_CONTEXT_SWITCH_TRACER) += trace_sched_switch.o
 obj-$(CONFIG_FUNCTION_TRACER) += trace_functions.o
+obj-$(CONFIG_PREEMPTIRQ_EVENTS) += trace_irqsoff.o
 obj-$(CONFIG_IRQSOFF_TRACER) += trace_irqsoff.o
 obj-$(CONFIG_PREEMPT_TRACER) += trace_irqsoff.o
 obj-$(CONFIG_SCHED_TRACER) += trace_sched_wakeup.o
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 0e3033c00474..515ac851841a 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -16,6 +16,9 @@
 
 #include "trace.h"
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/preemptirq.h>
+
 #if defined(CONFIG_IRQSOFF_TRACER) || defined(CONFIG_PREEMPT_TRACER)
 static struct trace_array		*irqsoff_trace __read_mostly;
 static int				tracer_enabled __read_mostly;
@@ -776,27 +779,60 @@ static inline void tracer_preempt_on(unsigned long a0, unsigned long a1) { }
 static inline void tracer_preempt_off(unsigned long a0, unsigned long a1) { }
 #endif
 
+/*
+ * trace_hardirqs_off can be called even when IRQs are already off. It is
+ * pointless and inconsistent with trace_preempt_enable and
+ * trace_preempt_disable to trace this, lets prevent double counting it with a
+ * per-cpu variable. Also reuse the per-cpu variable for other trace_hardirqs_*
+ * functions since we already define it.
+ */
+static DEFINE_PER_CPU(int, tracing_irq_cpu);
+
 #if defined(CONFIG_TRACE_IRQFLAGS) && !defined(CONFIG_PROVE_LOCKING)
 void trace_hardirqs_on(void)
 {
+	if (!this_cpu_read(tracing_irq_cpu))
+		return;
+
+	trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
 	tracer_hardirqs_on();
+
+	this_cpu_write(tracing_irq_cpu, 0);
 }
 EXPORT_SYMBOL(trace_hardirqs_on);
 
 void trace_hardirqs_off(void)
 {
+	if (this_cpu_read(tracing_irq_cpu))
+		return;
+
+	this_cpu_write(tracing_irq_cpu, 1);
+
+	trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
 	tracer_hardirqs_off();
 }
 EXPORT_SYMBOL(trace_hardirqs_off);
 
 __visible void trace_hardirqs_on_caller(unsigned long caller_addr)
 {
+	if (!this_cpu_read(tracing_irq_cpu))
+		return;
+
+	trace_irq_enable_rcuidle(CALLER_ADDR0, caller_addr);
 	tracer_hardirqs_on_caller(caller_addr);
+
+	this_cpu_write(tracing_irq_cpu, 0);
 }
 EXPORT_SYMBOL(trace_hardirqs_on_caller);
 
 __visible void trace_hardirqs_off_caller(unsigned long caller_addr)
 {
+	if (this_cpu_read(tracing_irq_cpu))
+		return;
+
+	this_cpu_write(tracing_irq_cpu, 1);
+
+	trace_irq_disable_rcuidle(CALLER_ADDR0, caller_addr);
 	tracer_hardirqs_off_caller(caller_addr);
 }
 EXPORT_SYMBOL(trace_hardirqs_off_caller);
@@ -818,14 +854,17 @@ inline void print_irqtrace_events(struct task_struct *curr)
 }
 #endif
 
-#ifdef CONFIG_PREEMPT_TRACER
+#if defined(CONFIG_PREEMPT_TRACER) || \
+	(defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPTIRQ_EVENTS))
 void trace_preempt_on(unsigned long a0, unsigned long a1)
 {
+	trace_preempt_enable_rcuidle(a0, a1);
 	tracer_preempt_on(a0, a1);
 }
 
 void trace_preempt_off(unsigned long a0, unsigned long a1)
 {
+	trace_preempt_disable_rcuidle(a0, a1);
 	tracer_preempt_off(a0, a1);
 }
 #endif
-- 
2.14.2.822.g60be5d43e6-goog

Back to linux.kernel | Previous | Next — Previous in thread | Find similar | Unroll thread


Thread

[PATCH v7 1/2] tracing: Prepare to add preempt and irq trace events Joel Fernandes <joelaf@google.com> - 2017-09-29 23:30 +0200
  [PATCH v7 2/2] tracing: Add support for preempt and irq enable/disable events Joel Fernandes <joelaf@google.com> - 2017-09-29 23:30 +0200

csiph-web