From: Binoy Jayan <binoy.jayan@linaro.org>
To: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>,
Daniel Wagner <daniel.wagner@bmw-carit.de>,
Arnd Bergmann <arnd@arndb.de>,
linux-kernel@vger.kernel.org,
Masami <masami.hiramatsu@linaro.org>,
Binoy Jayan <binoy.jayan@linaro.org>
Subject: [PATCH v4 3/3] tracing: Histogram for missed timer offsets
Date: Tue, 30 Aug 2016 15:58:44 +0530 [thread overview]
Message-ID: <1472552924-22297-4-git-send-email-binoy.jayan@linaro.org> (raw)
In-Reply-To: <1472552924-22297-1-git-send-email-binoy.jayan@linaro.org>
Latencies of missed timer offsets. Generate a histogram of missed
timer offsets in microseconds. This will be a based along with irq
and preemption latencies to calculate the effective process wakeup
latencies.
The following filter(s) may be used
'hist:key=common_pid.execname'
'hist:key=common_pid.execname:val=toffset,hitcount'
Signed-off-by: Binoy Jayan <binoy.jayan@linaro.org>
---
include/linux/hrtimer.h | 3 +++
include/trace/events/latency.h | 29 +++++++++++++++++++++++++++++
kernel/time/hrtimer.c | 40 ++++++++++++++++++++++++++++++++++++++++
3 files changed, 72 insertions(+)
diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h
index 5e00f80..e09de14 100644
--- a/include/linux/hrtimer.h
+++ b/include/linux/hrtimer.h
@@ -104,6 +104,9 @@ struct hrtimer {
struct hrtimer_clock_base *base;
u8 state;
u8 is_rel;
+#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER)
+ ktime_t praecox;
+#endif
#ifdef CONFIG_TIMER_STATS
int start_pid;
void *start_site;
diff --git a/include/trace/events/latency.h b/include/trace/events/latency.h
index e89be12..7fca7cd 100644
--- a/include/trace/events/latency.h
+++ b/include/trace/events/latency.h
@@ -29,6 +29,35 @@ DEFINE_EVENT(latency_template, latency_preempt,
TP_PROTO(int ltype, cycles_t latency),
TP_ARGS(ltype, latency));
+TRACE_EVENT(latency_hrtimer_interrupt,
+
+ TP_PROTO(long long toffset, struct task_struct *curr,
+ struct task_struct *task),
+
+ TP_ARGS(toffset, curr, task),
+
+ TP_STRUCT__entry(
+ __field(long long, toffset)
+ __array(char, ccomm, TASK_COMM_LEN)
+ __field(int, cprio)
+ __array(char, tcomm, TASK_COMM_LEN)
+ __field(int, tprio)
+ ),
+
+ TP_fast_assign(
+ __entry->toffset = toffset;
+ memcpy(__entry->ccomm, curr->comm, TASK_COMM_LEN);
+ __entry->cprio = curr->prio;
+ memcpy(__entry->tcomm, task != NULL ? task->comm : "<none>",
+ task != NULL ? TASK_COMM_LEN : 7);
+ __entry->tprio = task != NULL ? task->prio : -1;
+ ),
+
+ TP_printk("toffset=%lld curr=%s[%d] thread=%s[%d]",
+ __entry->toffset, __entry->ccomm, __entry->cprio,
+ __entry->tcomm, __entry->tprio)
+);
+
#endif /* _TRACE_HIST_H */
/* This part must be outside protection */
diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c
index 9ba7c82..f3e1d92 100644
--- a/kernel/time/hrtimer.c
+++ b/kernel/time/hrtimer.c
@@ -53,9 +53,12 @@
#include <asm/uaccess.h>
#include <trace/events/timer.h>
+#include <trace/events/latency.h>
#include "tick-internal.h"
+static enum hrtimer_restart hrtimer_wakeup(struct hrtimer *timer);
+
/*
* The timer bases:
*
@@ -960,6 +963,39 @@ static inline ktime_t hrtimer_update_lowres(struct hrtimer *timer, ktime_t tim,
return tim;
}
+static inline void trace_latency_hrtimer_mark_ts(struct hrtimer *timer,
+ struct hrtimer_clock_base *new_base,
+ ktime_t tim)
+{
+#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER)
+ if (trace_latency_hrtimer_interrupt_enabled()) {
+ ktime_t now = new_base->get_time();
+
+ if (ktime_to_ns(tim) < ktime_to_ns(now))
+ timer->praecox = now;
+ else
+ timer->praecox = ktime_set(0, 0);
+ }
+#endif
+}
+
+static inline void trace_latency_missed_hrtimer(struct hrtimer *timer,
+ ktime_t basenow)
+{
+#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER)
+ if (trace_latency_hrtimer_interrupt_enabled())
+ trace_latency_hrtimer_interrupt(
+ ktime_to_ns(ktime_sub(ktime_to_ns(timer->praecox) ?
+ timer->praecox : hrtimer_get_expires(timer),
+ basenow)),
+ current,
+ timer->function == hrtimer_wakeup ?
+ container_of(timer, struct hrtimer_sleeper,
+ timer)->task : NULL);
+#endif
+
+}
+
/**
* hrtimer_start_range_ns - (re)start an hrtimer on the current CPU
* @timer: the timer to be added
@@ -992,6 +1028,8 @@ void hrtimer_start_range_ns(struct hrtimer *timer, ktime_t tim,
timer_stats_hrtimer_set_start_info(timer);
+ trace_latency_hrtimer_mark_ts(timer, new_base, tim);
+
leftmost = enqueue_hrtimer(timer, new_base);
if (!leftmost)
goto unlock;
@@ -1284,6 +1322,8 @@ static void __hrtimer_run_queues(struct hrtimer_cpu_base *cpu_base, ktime_t now)
timer = container_of(node, struct hrtimer, node);
+ trace_latency_missed_hrtimer(timer, basenow);
+
/*
* The immediate goal for using the softexpires is
* minimizing wakeups, not running timers at the
--
The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project
next prev parent reply other threads:[~2016-08-30 10:29 UTC|newest]
Thread overview: 16+ messages / expand[flat|nested] mbox.gz Atom feed top
2016-08-30 10:28 [PATCH v4 0/3] *** Latency histograms - IRQSOFF,PREEMPTOFF *** Binoy Jayan
2016-08-30 10:28 ` [PATCH v4 1/3] tracing: Deference pointers without RCU checks Binoy Jayan
2016-08-30 10:28 ` [PATCH v4 2/3] tracing: Add trace_irqsoff tracepoints Binoy Jayan
2016-08-30 11:30 ` Daniel Wagner
2016-08-30 11:49 ` Binoy Jayan
2016-08-30 14:08 ` Steven Rostedt
2016-08-31 11:39 ` Binoy Jayan
2016-08-30 10:28 ` Binoy Jayan [this message]
2016-08-30 10:50 ` [PATCH v4 3/3] tracing: Histogram for missed timer offsets Masami Hiramatsu
2016-09-02 12:41 ` Binoy Jayan
2016-09-02 15:54 ` Masami Hiramatsu
2016-08-30 14:15 ` Steven Rostedt
2016-08-31 11:34 ` Binoy Jayan
2016-08-31 12:42 ` Steven Rostedt
2016-08-30 11:39 ` [PATCH v4 0/3] *** Latency histograms - IRQSOFF,PREEMPTOFF *** Daniel Wagner
2016-08-30 12:02 ` Masami Hiramatsu
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=1472552924-22297-4-git-send-email-binoy.jayan@linaro.org \
--to=binoy.jayan@linaro.org \
--cc=arnd@arndb.de \
--cc=daniel.wagner@bmw-carit.de \
--cc=linux-kernel@vger.kernel.org \
--cc=masami.hiramatsu@linaro.org \
--cc=mingo@redhat.com \
--cc=rostedt@goodmis.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).