| 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
| ||
|
Message-ID: <4A604F1E.9010402@cn.fujitsu.com>
Date: Fri, 17 Jul 2009 18:14:54 +0800
From: Xiao Guangrong <xiaoguangrong@...fujitsu.com>
To: Ingo Molnar <mingo@...e.hu>
CC: Thomas Gleixner <tglx@...utronix.de>,
Steven Rostedt <rostedt@...dmis.org>,
Frederic Weisbecker <fweisbec@...il.com>,
Zhaolei <zhaolei@...fujitsu.com>, kosaki.motohiro@...fujitsu.com,
Mathieu Desnoyers <mathieu.desnoyers@...ymtl.ca>,
Anton Blanchard <anton@...ba.org>,
LKML <linux-kernel@...r.kernel.org>
Subject: [PATCH v3 1/4] tracing/events: Add timer and high res timer tracepoints
From: Anton Blanchard <anton@...ba.org>
Add tracepoints for timer and high res timer execution. We add entry and
exit tracepoints so we can calculate timer latency.
Example ftrace output:
<idle>-0 [000] 264.040506: hrtimer_entry: func=.tick_sched_timer
<idle>-0 [000] 264.040508: hrtimer_exit: func=.tick_sched_timer restart=HRTIMER_RESTART
<idle>-0 [000] 264.040530: timer_entry: func=.e1000_watchdog
<idle>-0 [000] 264.040728: timer_exit: func=.e1000_watchdog
Here we can see e1000_watchdog is taking 0.2ms - it might make sense to
move this into a workqueue or kernel thread.
Changelog v1->v2:
1: Rebase this patch against latest tip tree by Xiao Guangrong.
2: Move TRACE_SYSTEM out of #if
Signed-off-by: Anton Blanchard <anton@...ba.org>
Acked-by: Thomas Gleixner <tglx@...utronix.de>
Signed-off-by: Xiao Guangrong <xiaoguangrong@...fujitsu.com>
---
include/trace/events/timer.h | 116 ++++++++++++++++++++++++++++++++++++++++++
kernel/hrtimer.c | 3 +
kernel/timer.c | 5 ++
3 files changed, 124 insertions(+), 0 deletions(-)
create mode 100644 include/trace/events/timer.h
diff --git a/include/trace/events/timer.h b/include/trace/events/timer.h
new file mode 100644
index 0000000..ff2754a
--- /dev/null
+++ b/include/trace/events/timer.h
@@ -0,0 +1,116 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM timer
+
+#if !defined(_TRACE_TIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_TIMER_H
+
+#include <linux/tracepoint.h>
+#include <linux/timer.h>
+#include <linux/hrtimer.h>
+
+/**
+ * timer_entry - called immediately before the timer callback
+ * @timer: pointer to struct timer_list
+ *
+ * When used in combination with the timer_exit tracepoint we can
+ * determine the timer latency.
+ **/
+TRACE_EVENT(timer_entry,
+
+ TP_PROTO(struct timer_list *timer),
+
+ TP_ARGS(timer),
+
+ TP_STRUCT__entry(
+ __field(void *, function)
+ ),
+
+ TP_fast_assign(
+ __entry->function = timer->function;
+ ),
+
+ TP_printk("func=%pf", __entry->function)
+);
+
+/**
+ * timer_exit - called immediately after the timer returns
+ * @timer: pointer to struct timer_list
+ *
+ * When used in combination with the timer_entry tracepoint we can
+ * determine the timer latency.
+ **/
+TRACE_EVENT(timer_exit,
+
+ TP_PROTO(struct timer_list *timer),
+
+ TP_ARGS(timer),
+
+ TP_STRUCT__entry(
+ __field(void *, function)
+ ),
+
+ TP_fast_assign(
+ __entry->function = timer->function;
+ ),
+
+ TP_printk("func=%pf", __entry->function)
+);
+
+/**
+ * hrtimer_entry - called immediately before the high res timer callback
+ * @timer: pointer to struct hrtimer
+ *
+ * When used in combination with the hrtimer_exit tracepoint we can
+ * determine the high res timer latency.
+ **/
+TRACE_EVENT(hrtimer_entry,
+
+ TP_PROTO(struct hrtimer *timer),
+
+ TP_ARGS(timer),
+
+ TP_STRUCT__entry(
+ __field(void *, function)
+ ),
+
+ TP_fast_assign(
+ __entry->function = timer->function;
+ ),
+
+ TP_printk("func=%pf", __entry->function)
+);
+
+/**
+ * hrtimer_exit - called immediately after the high res timer returns
+ * @timer: pointer to struct hrtimer
+ * @restart: high res timer return value
+ *
+ * High res timer will restart if @restart is set to HRTIMER_RESTART.
+ * When used in combination with the hrtimer_entry tracepoint we can
+ * determine the high res timer latency.
+ **/
+TRACE_EVENT(hrtimer_exit,
+
+ TP_PROTO(struct hrtimer *timer, int restart),
+
+ TP_ARGS(timer, restart),
+
+ TP_STRUCT__entry(
+ __field(void *, function)
+ __field(int, restart)
+ ),
+
+ TP_fast_assign(
+ __entry->function = timer->function;
+ __entry->restart = restart;
+ ),
+
+ TP_printk("func=%pf restart=%s", __entry->function,
+ (__entry->restart == HRTIMER_RESTART) ?
+ "HRTIMER_RESTART" : "HRTIMER_NORESTART")
+);
+
+#endif /* _TRACE_TIMER_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
index ab5eb70..33317e4 100644
--- a/kernel/hrtimer.c
+++ b/kernel/hrtimer.c
@@ -47,6 +47,7 @@
#include <linux/timer.h>
#include <asm/uaccess.h>
+#include <trace/events/timer.h>
/*
* The timer bases:
@@ -1161,7 +1162,9 @@ static void __run_hrtimer(struct hrtimer *timer)
* the timer base.
*/
spin_unlock(&cpu_base->lock);
+ trace_hrtimer_entry(timer);
restart = fn(timer);
+ trace_hrtimer_exit(timer, restart);
spin_lock(&cpu_base->lock);
/*
diff --git a/kernel/timer.c b/kernel/timer.c
index 0b36b9e..9385ad5 100644
--- a/kernel/timer.c
+++ b/kernel/timer.c
@@ -46,6 +46,9 @@
#include <asm/timex.h>
#include <asm/io.h>
+#define CREATE_TRACE_POINTS
+#include <trace/events/timer.h>
+
u64 jiffies_64 __cacheline_aligned_in_smp = INITIAL_JIFFIES;
EXPORT_SYMBOL(jiffies_64);
@@ -984,7 +987,9 @@ static inline void __run_timers(struct tvec_base *base)
*/
lock_map_acquire(&lockdep_map);
+ trace_timer_entry(timer);
fn(data);
+ trace_timer_exit(timer);
lock_map_release(&lockdep_map);
--
1.6.1.2
--
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