[tip:timers/core] alarmtimer: Add tracepoints for alarm timers

From: tip-bot for Baolin Wang
Date: Thu Dec 01 2016 - 08:52:30 EST


Commit-ID: 4a057549d6044c2dea47e80f8369a76225ec9d90
Gitweb: http://git.kernel.org/tip/4a057549d6044c2dea47e80f8369a76225ec9d90
Author: Baolin Wang <baolin.wang@xxxxxxxxxx>
AuthorDate: Mon, 28 Nov 2016 14:35:21 -0800
Committer: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
CommitDate: Thu, 1 Dec 2016 14:45:08 +0100

alarmtimer: Add tracepoints for alarm timers

Alarm timers are one of the mechanisms to wake up a system from suspend,
but there exist no tracepoints to analyse which process/thread armed an
alarmtimer.

Add tracepoints for start/cancel/expire of individual alarm timers and one
for tracing the suspend time decision when to resume the system.

The following trace excerpt illustrates the new mechanism:

Binder:3292_2-3304 [000] d..2 149.981123: alarmtimer_cancel:
alarmtimer:ffffffc1319a7800 type:REALTIME
expires:1325463120000000000 now:1325376810370370245

Binder:3292_2-3304 [000] d..2 149.981136: alarmtimer_start:
alarmtimer:ffffffc1319a7800 type:REALTIME
expires:1325376840000000000 now:1325376810370384591

Binder:3292_9-3953 [000] d..2 150.212991: alarmtimer_cancel:
alarmtimer:ffffffc1319a5a00 type:BOOTTIME
expires:179552000000 now:150154008122

Binder:3292_9-3953 [000] d..2 150.213006: alarmtimer_start:
alarmtimer:ffffffc1319a5a00 type:BOOTTIME
expires:179551000000 now:150154025622

system_server-3000 [002] ...1 162.701940: alarmtimer_suspend:
alarmtimer type:REALTIME expires:1325376840000000000

The wakeup time which is selected at suspend time allows to map it back to
the task arming the timer: Binder:3292_2.

[ tglx: Store alarm timer expiry time instead of some useless RTC relative
information, add proper type information for wakeups which are
handled via the clock_nanosleep/freezer and massage the changelog. ]

Signed-off-by: Baolin Wang <baolin.wang@xxxxxxxxxx>
Signed-off-by: John Stultz <john.stultz@xxxxxxxxxx>
Acked-by: Steven Rostedt <rostedt@xxxxxxxxxxx>
Cc: Prarit Bhargava <prarit@xxxxxxxxxx>
Cc: Richard Cochran <richardcochran@xxxxxxxxx>
Link: http://lkml.kernel.org/r/1480372524-15181-5-git-send-email-john.stultz@xxxxxxxxxx
Signed-off-by: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
---
include/linux/alarmtimer.h | 5 ++
include/trace/events/alarmtimer.h | 96 +++++++++++++++++++++++++++++++++++++++
kernel/time/alarmtimer.c | 53 +++++++++++++++++----
3 files changed, 144 insertions(+), 10 deletions(-)

diff --git a/include/linux/alarmtimer.h b/include/linux/alarmtimer.h
index 9d80312..c70aac1 100644
--- a/include/linux/alarmtimer.h
+++ b/include/linux/alarmtimer.h
@@ -10,7 +10,12 @@ enum alarmtimer_type {
ALARM_REALTIME,
ALARM_BOOTTIME,

+ /* Supported types end here */
ALARM_NUMTYPE,
+
+ /* Used for tracing information. No usable types. */
+ ALARM_REALTIME_FREEZER,
+ ALARM_BOOTTIME_FREEZER,
};

enum alarmtimer_restart {
diff --git a/include/trace/events/alarmtimer.h b/include/trace/events/alarmtimer.h
new file mode 100644
index 0000000..a1c108c
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,96 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM alarmtimer
+
+#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_ALARMTIMER_H
+
+#include <linux/alarmtimer.h>
+#include <linux/rtc.h>
+#include <linux/tracepoint.h>
+
+TRACE_DEFINE_ENUM(ALARM_REALTIME);
+TRACE_DEFINE_ENUM(ALARM_BOOTTIME);
+TRACE_DEFINE_ENUM(ALARM_REALTIME_FREEZER);
+TRACE_DEFINE_ENUM(ALARM_BOOTTIME_FREEZER);
+
+#define show_alarm_type(type) __print_flags(type, " | ", \
+ { 1 << ALARM_REALTIME, "REALTIME" }, \
+ { 1 << ALARM_BOOTTIME, "BOOTTIME" }, \
+ { 1 << ALARM_REALTIME_FREEZER, "REALTIME Freezer" }, \
+ { 1 << ALARM_BOOTTIME_FREEZER, "BOOTTIME Freezer" })
+
+TRACE_EVENT(alarmtimer_suspend,
+
+ TP_PROTO(ktime_t expires, int flag),
+
+ TP_ARGS(expires, flag),
+
+ TP_STRUCT__entry(
+ __field(s64, expires)
+ __field(unsigned char, alarm_type)
+ ),
+
+ TP_fast_assign(
+ __entry->expires = expires.tv64;
+ __entry->alarm_type = flag;
+ ),
+
+ TP_printk("alarmtimer type:%s expires:%llu",
+ show_alarm_type((1 << __entry->alarm_type)),
+ __entry->expires
+ )
+);
+
+DECLARE_EVENT_CLASS(alarm_class,
+
+ TP_PROTO(struct alarm *alarm, ktime_t now),
+
+ TP_ARGS(alarm, now),
+
+ TP_STRUCT__entry(
+ __field(void *, alarm)
+ __field(unsigned char, alarm_type)
+ __field(s64, expires)
+ __field(s64, now)
+ ),
+
+ TP_fast_assign(
+ __entry->alarm = alarm;
+ __entry->alarm_type = alarm->type;
+ __entry->expires = alarm->node.expires.tv64;
+ __entry->now = now.tv64;
+ ),
+
+ TP_printk("alarmtimer:%p type:%s expires:%llu now:%llu",
+ __entry->alarm,
+ show_alarm_type((1 << __entry->alarm_type)),
+ __entry->expires,
+ __entry->now
+ )
+);
+
+DEFINE_EVENT(alarm_class, alarmtimer_fired,
+
+ TP_PROTO(struct alarm *alarm, ktime_t now),
+
+ TP_ARGS(alarm, now)
+);
+
+DEFINE_EVENT(alarm_class, alarmtimer_start,
+
+ TP_PROTO(struct alarm *alarm, ktime_t now),
+
+ TP_ARGS(alarm, now)
+);
+
+DEFINE_EVENT(alarm_class, alarmtimer_cancel,
+
+ TP_PROTO(struct alarm *alarm, ktime_t now),
+
+ TP_ARGS(alarm, now)
+);
+
+#endif /* _TRACE_ALARMTIMER_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
index a15caa3..9b08ca3 100644
--- a/kernel/time/alarmtimer.c
+++ b/kernel/time/alarmtimer.c
@@ -26,6 +26,9 @@
#include <linux/workqueue.h>
#include <linux/freezer.h>

+#define CREATE_TRACE_POINTS
+#include <trace/events/alarmtimer.h>
+
/**
* struct alarm_base - Alarm timer bases
* @lock: Lock for syncrhonized access to the base
@@ -40,7 +43,9 @@ static struct alarm_base {
clockid_t base_clockid;
} alarm_bases[ALARM_NUMTYPE];

-/* freezer delta & lock used to handle clock_nanosleep triggered wakeups */
+/* freezer information to handle clock_nanosleep triggered wakeups */
+static enum alarmtimer_type freezer_alarmtype;
+static ktime_t freezer_expires;
static ktime_t freezer_delta;
static DEFINE_SPINLOCK(freezer_delta_lock);

@@ -194,6 +199,7 @@ static enum hrtimer_restart alarmtimer_fired(struct hrtimer *timer)
}
spin_unlock_irqrestore(&base->lock, flags);

+ trace_alarmtimer_fired(alarm, base->gettime());
return ret;

}
@@ -218,15 +224,16 @@ EXPORT_SYMBOL_GPL(alarm_expires_remaining);
*/
static int alarmtimer_suspend(struct device *dev)
{
- struct rtc_time tm;
- ktime_t min, now;
- unsigned long flags;
+ ktime_t min, now, expires;
+ int i, ret, type;
struct rtc_device *rtc;
- int i;
- int ret;
+ unsigned long flags;
+ struct rtc_time tm;

spin_lock_irqsave(&freezer_delta_lock, flags);
min = freezer_delta;
+ expires = freezer_expires;
+ type = freezer_alarmtype;
freezer_delta = ktime_set(0, 0);
spin_unlock_irqrestore(&freezer_delta_lock, flags);

@@ -247,8 +254,11 @@ static int alarmtimer_suspend(struct device *dev)
if (!next)
continue;
delta = ktime_sub(next->expires, base->gettime());
- if (!min.tv64 || (delta.tv64 < min.tv64))
+ if (!min.tv64 || (delta.tv64 < min.tv64)) {
+ expires = next->expires;
min = delta;
+ type = i;
+ }
}
if (min.tv64 == 0)
return 0;
@@ -258,6 +268,8 @@ static int alarmtimer_suspend(struct device *dev)
return -EBUSY;
}

+ trace_alarmtimer_suspend(expires, type);
+
/* Setup an rtc timer to fire that far in the future */
rtc_timer_cancel(rtc, &rtctimer);
rtc_read_time(rtc, &tm);
@@ -295,15 +307,32 @@ static int alarmtimer_resume(struct device *dev)

static void alarmtimer_freezerset(ktime_t absexp, enum alarmtimer_type type)
{
- ktime_t delta;
+ struct alarm_base *base;
unsigned long flags;
- struct alarm_base *base = &alarm_bases[type];
+ ktime_t delta;
+
+ switch(type) {
+ case ALARM_REALTIME:
+ base = &alarm_bases[ALARM_REALTIME];
+ type = ALARM_REALTIME_FREEZER;
+ break;
+ case ALARM_BOOTTIME:
+ base = &alarm_bases[ALARM_BOOTTIME];
+ type = ALARM_BOOTTIME_FREEZER;
+ break;
+ default:
+ WARN_ONCE(1, "Invalid alarm type: %d\n", type);
+ return;
+ }

delta = ktime_sub(absexp, base->gettime());

spin_lock_irqsave(&freezer_delta_lock, flags);
- if (!freezer_delta.tv64 || (delta.tv64 < freezer_delta.tv64))
+ if (!freezer_delta.tv64 || (delta.tv64 < freezer_delta.tv64)) {
freezer_delta = delta;
+ freezer_expires = absexp;
+ freezer_alarmtype = type;
+ }
spin_unlock_irqrestore(&freezer_delta_lock, flags);
}

@@ -342,6 +371,8 @@ void alarm_start(struct alarm *alarm, ktime_t start)
alarmtimer_enqueue(base, alarm);
hrtimer_start(&alarm->timer, alarm->node.expires, HRTIMER_MODE_ABS);
spin_unlock_irqrestore(&base->lock, flags);
+
+ trace_alarmtimer_start(alarm, base->gettime());
}
EXPORT_SYMBOL_GPL(alarm_start);

@@ -390,6 +421,8 @@ int alarm_try_to_cancel(struct alarm *alarm)
if (ret >= 0)
alarmtimer_dequeue(base, alarm);
spin_unlock_irqrestore(&base->lock, flags);
+
+ trace_alarmtimer_cancel(alarm, base->gettime());
return ret;
}
EXPORT_SYMBOL_GPL(alarm_try_to_cancel);