[PATCH] tracing: Add trace_irqsoff tracepoints

From: Daniel Wagner
Date: Wed Apr 29 2015 - 11:09:04 EST


In order to create latency histograms, we place a tracepoint at the end
of critical section.

Not for inclusion!

Not-Signed-off-by: Daniel Wagner <daniel.wagner@xxxxxxxxxxxx>
---
include/trace/events/latency.h | 41 +++++++++++++++++++++++++++++++++++++++++
kernel/trace/trace_irqsoff.c | 22 ++++++++++++++--------
2 files changed, 55 insertions(+), 8 deletions(-)
create mode 100644 include/trace/events/latency.h

diff --git a/include/trace/events/latency.h b/include/trace/events/latency.h
new file mode 100644
index 0000000..1ed8b13
--- /dev/null
+++ b/include/trace/events/latency.h
@@ -0,0 +1,41 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM latency
+
+#if !defined(_TRACE_LATENCY_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_LATENCY_H
+
+#include <linux/tracepoint.h>
+
+#define LATENCY_CS 1
+#define LATENCY_IRQ 2
+#define LATENCY_PREEMPT 3
+
+#define latency_source_sym \
+ {LATENCY_CS, "critical section" }, \
+ {LATENCY_IRQ, "irq"}, \
+ {LATENCY_PREEMPT, "preempt"}
+
+TRACE_EVENT(latency,
+ TP_PROTO(int source, cycles_t latency),
+
+ TP_ARGS(source, latency),
+
+ TP_STRUCT__entry(
+ __field(int, source)
+ __field(cycles_t, latency)
+ ),
+
+ TP_fast_assign(
+ __entry->source = source;
+ __entry->latency = latency;
+ ),
+
+ TP_printk("source=%s latency=%llu",
+ __print_symbolic(__entry->source, latency_source_sym),
+ __entry->latency)
+);
+
+#endif /* _TRACE_LATENCY_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 8523ea3..7a1d254 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -14,8 +14,13 @@
#include <linux/module.h>
#include <linux/ftrace.h>

+#include <trace/events/sched.h>
+
#include "trace.h"

+#define CREATE_TRACE_POINTS
+#include <trace/events/latency.h>
+
static struct trace_array *irqsoff_trace __read_mostly;
static int tracer_enabled __read_mostly;

@@ -311,7 +316,7 @@ static void
check_critical_timing(struct trace_array *tr,
struct trace_array_cpu *data,
unsigned long parent_ip,
- int cpu)
+ int cpu, int source)
{
cycle_t T0, T1, delta;
unsigned long flags;
@@ -325,6 +330,7 @@ check_critical_timing(struct trace_array *tr,

pc = preempt_count();

+ trace_latency(source, delta);
if (!report_latency(tr, delta))
goto out;

@@ -396,7 +402,7 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
}

static inline void
-stop_critical_timing(unsigned long ip, unsigned long parent_ip)
+stop_critical_timing(unsigned long ip, unsigned long parent_ip, int source)
{
int cpu;
struct trace_array *tr = irqsoff_trace;
@@ -423,7 +429,7 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip)

local_save_flags(flags);
__trace_function(tr, ip, parent_ip, flags, preempt_count());
- check_critical_timing(tr, data, parent_ip ? : ip, cpu);
+ check_critical_timing(tr, data, parent_ip ? : ip, cpu, source);
data->critical_start = 0;
atomic_dec(&data->disabled);
}
@@ -439,7 +445,7 @@ EXPORT_SYMBOL_GPL(start_critical_timings);
void stop_critical_timings(void)
{
if (preempt_trace() || irq_trace())
- stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
+ stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1, LATENCY_CS);
}
EXPORT_SYMBOL_GPL(stop_critical_timings);

@@ -448,7 +454,7 @@ EXPORT_SYMBOL_GPL(stop_critical_timings);
void time_hardirqs_on(unsigned long a0, unsigned long a1)
{
if (!preempt_trace() && irq_trace())
- stop_critical_timing(a0, a1);
+ stop_critical_timing(a0, a1, LATENCY_IRQ);
}

void time_hardirqs_off(unsigned long a0, unsigned long a1)
@@ -481,7 +487,7 @@ inline void print_irqtrace_events(struct task_struct *curr)
void trace_hardirqs_on(void)
{
if (!preempt_trace() && irq_trace())
- stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
+ stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1, LATENCY_IRQ);
}
EXPORT_SYMBOL(trace_hardirqs_on);

@@ -495,7 +501,7 @@ EXPORT_SYMBOL(trace_hardirqs_off);
__visible void trace_hardirqs_on_caller(unsigned long caller_addr)
{
if (!preempt_trace() && irq_trace())
- stop_critical_timing(CALLER_ADDR0, caller_addr);
+ stop_critical_timing(CALLER_ADDR0, caller_addr, LATENCY_IRQ);
}
EXPORT_SYMBOL(trace_hardirqs_on_caller);

@@ -513,7 +519,7 @@ EXPORT_SYMBOL(trace_hardirqs_off_caller);
void trace_preempt_on(unsigned long a0, unsigned long a1)
{
if (preempt_trace() && !irq_trace())
- stop_critical_timing(a0, a1);
+ stop_critical_timing(a0, a1, LATENCY_PREEMPT);
}

void trace_preempt_off(unsigned long a0, unsigned long a1)
--
2.1.0

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