[v3] time: alarmtimer: Add the trcepoints for alarmtimer

Message ID	27d8c8be532b025a1e68d710ff539b8923c9d4cb.1471839665.git.baolin.wang@linaro.org
State	Superseded
Headers	show Delivered-To: patch@linaro.org Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; From: Baolin Wang <baolin.wang@linaro.org> To: rostedt@goodmis.org, mingo@redhat.com, john.stultz@linaro.org, tglx@linutronix.de Cc: baolin.wang@linaro.org, broonie@kernel.org, linux-kernel@vger.kernel.org Subject: [PATCH v3] time: alarmtimer: Add the trcepoints for alarmtimer Date: Mon, 22 Aug 2016 12:23:14 +0800 Message-Id: <27d8c8be532b025a1e68d710ff539b8923c9d4cb.1471839665.git.baolin.wang@linaro.org> Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk

Message ID

27d8c8be532b025a1e68d710ff539b8923c9d4cb.1471839665.git.baolin.wang@linaro.org

State

Superseded

Headers

Received-SPF: pass (google.com: best guess record for domain of
	linux-kernel-owner@vger.kernel.org designates 209.132.180.67
	as permitted sender) client-ip=209.132.180.67; 
From: Baolin Wang <baolin.wang@linaro.org>
To: rostedt@goodmis.org, mingo@redhat.com, john.stultz@linaro.org,
	tglx@linutronix.de
Cc: baolin.wang@linaro.org, broonie@kernel.org, linux-kernel@vger.kernel.org
Subject: [PATCH v3] time: alarmtimer: Add the trcepoints for alarmtimer
Date: Mon, 22 Aug 2016 12:23:14 +0800
Message-Id: <27d8c8be532b025a1e68d710ff539b8923c9d4cb.1471839665.git.baolin.wang@linaro.org>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

Commit Message

(Exiting) Baolin Wang Aug. 22, 2016, 4:23 a.m. UTC

For system debugging, we usually want to know who sets one alarm timer, the
time of the timer, when the timer started and fired and so on. Thus adding
tracepoints can help us trace the alarmtimer information.

For example, when we debug the system supend/resume, if the system is always
resumed by RTC alarm, we can find out which process set the alarm timer to
resume system by below trace log:

......
Binder:2976_6-3473  [005] d..2  1076.587732: alarmtimer_start: process:Binder:2976_6
alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

Binder:2976_7-3480  [002] d..2  1076.592707: alarmtimer_cancel: process:Binder:2976_7
alarmtimer type:ALARM_BOOTTIME expires:1325463060000000000 time: 2012-1-2 0:11:0

Binder:2976_7-3480  [002] d..2  1076.592731: alarmtimer_start: process:Binder:2976_7
alarmtimer type:ALARM_BOOTTIME expires:1325378040000000000 time: 2012-1-1 0:34:0

system_server-2976  [003] d..2  1076.605587: alarmtimer_cancel: process:system_server
alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

system_server-2976  [003] d..2  1076.605608: alarmtimer_start: process:system_server
alarmtimer type:ALARM_BOOTTIME expires:1234155000000 time: 1970-1-1 0:20:35

system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend: alarmtimer type:ALARM_BOOTTIME
expires time: 2012-1-1 0:34:0
......

From the trace log, we can find out the 'Binder:2976_7' process set one alarm
timer which resumes the system.

Signed-off-by: Baolin Wang <baolin.wang@linaro.org>

---
Changes since v2:
 - Add TRACE_DEFINE_ENUM() macros.
 - Change the time variables type to save space in the ring buffer.
 - Add trace_alarmtimer_suspend_enabled() in case of tracing is not enabled.

Changes since v1:
 - Fix the kbuild error.
 - Modify the changelog with adding trace log.
---
 include/trace/events/alarmtimer.h |  137 +++++++++++++++++++++++++++++++++++++
 kernel/time/alarmtimer.c          |   23 ++++++-
 2 files changed, 157 insertions(+), 3 deletions(-)
 create mode 100644 include/trace/events/alarmtimer.h

-- 
1.7.9.5

Comments

(Exiting) Baolin Wang Aug. 30, 2016, 11:50 a.m. UTC | #1

Hi,

On 22 August 2016 at 12:23, Baolin Wang <baolin.wang@linaro.org> wrote:
> For system debugging, we usually want to know who sets one alarm timer, the

> time of the timer, when the timer started and fired and so on. Thus adding

> tracepoints can help us trace the alarmtimer information.

>

> For example, when we debug the system supend/resume, if the system is always

> resumed by RTC alarm, we can find out which process set the alarm timer to

> resume system by below trace log:

>

> ......

> Binder:2976_6-3473  [005] d..2  1076.587732: alarmtimer_start: process:Binder:2976_6

> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>

> Binder:2976_7-3480  [002] d..2  1076.592707: alarmtimer_cancel: process:Binder:2976_7

> alarmtimer type:ALARM_BOOTTIME expires:1325463060000000000 time: 2012-1-2 0:11:0

>

> Binder:2976_7-3480  [002] d..2  1076.592731: alarmtimer_start: process:Binder:2976_7

> alarmtimer type:ALARM_BOOTTIME expires:1325378040000000000 time: 2012-1-1 0:34:0

>

> system_server-2976  [003] d..2  1076.605587: alarmtimer_cancel: process:system_server

> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>

> system_server-2976  [003] d..2  1076.605608: alarmtimer_start: process:system_server

> alarmtimer type:ALARM_BOOTTIME expires:1234155000000 time: 1970-1-1 0:20:35

>

> system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend: alarmtimer type:ALARM_BOOTTIME

> expires time: 2012-1-1 0:34:0

> ......

>

> From the trace log, we can find out the 'Binder:2976_7' process set one alarm

> timer which resumes the system.


Do you have any comments about this patch? Thanks.

>

> Signed-off-by: Baolin Wang <baolin.wang@linaro.org>

> ---

> Changes since v2:

>  - Add TRACE_DEFINE_ENUM() macros.

>  - Change the time variables type to save space in the ring buffer.

>  - Add trace_alarmtimer_suspend_enabled() in case of tracing is not enabled.

>

> Changes since v1:

>  - Fix the kbuild error.

>  - Modify the changelog with adding trace log.

> ---

>  include/trace/events/alarmtimer.h |  137 +++++++++++++++++++++++++++++++++++++

>  kernel/time/alarmtimer.c          |   23 ++++++-

>  2 files changed, 157 insertions(+), 3 deletions(-)

>  create mode 100644 include/trace/events/alarmtimer.h

>

> diff --git a/include/trace/events/alarmtimer.h b/include/trace/events/alarmtimer.h

> new file mode 100644

> index 0000000..6a34bc9

> --- /dev/null

> +++ b/include/trace/events/alarmtimer.h

> @@ -0,0 +1,137 @@

> +#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);

> +

> +#define show_alarm_type(type)  __print_flags(type, " | ",      \

> +       { 1 << ALARM_REALTIME, "ALARM_REALTIME" },              \

> +       { 1 << ALARM_BOOTTIME, "ALARM_BOOTTIME" })

> +

> +DECLARE_EVENT_CLASS(alarm_setting,

> +

> +       TP_PROTO(struct rtc_time *rtc_time, int flag),

> +

> +       TP_ARGS(rtc_time, flag),

> +

> +       TP_STRUCT__entry(

> +               __field(unsigned char, second)

> +               __field(unsigned char, minute)

> +               __field(unsigned char, hour)

> +               __field(unsigned char, day)

> +               __field(unsigned char, mon)

> +               __field(unsigned short, year)

> +               __field(unsigned char, alarm_type)

> +       ),

> +

> +       TP_fast_assign(

> +               __entry->second = rtc_time->tm_sec;

> +               __entry->minute = rtc_time->tm_min;

> +               __entry->hour = rtc_time->tm_hour;

> +               __entry->day = rtc_time->tm_mday;

> +               __entry->mon = rtc_time->tm_mon;

> +               __entry->year = rtc_time->tm_year;

> +               __entry->alarm_type = flag;

> +       ),

> +

> +       TP_printk("alarmtimer type:%s expires time: %hu-%u-%u %u:%u:%u",

> +                 show_alarm_type((1 << __entry->alarm_type)),

> +                 __entry->year + 1900,

> +                 __entry->mon + 1,

> +                 __entry->day,

> +                 __entry->hour,

> +                 __entry->minute,

> +                 __entry->second

> +       )

> +);

> +

> +DEFINE_EVENT(alarm_setting, alarmtimer_suspend,

> +

> +       TP_PROTO(struct rtc_time *time, int flag),

> +

> +       TP_ARGS(time, flag)

> +);

> +

> +DECLARE_EVENT_CLASS(alarm_processing,

> +

> +       TP_PROTO(struct alarm *alarm, char *process_name),

> +

> +       TP_ARGS(alarm, process_name),

> +

> +       TP_STRUCT__entry(

> +               __field(unsigned long long, expires)

> +               __field(unsigned char, second)

> +               __field(unsigned char, minute)

> +               __field(unsigned char, hour)

> +               __field(unsigned char, day)

> +               __field(unsigned char, mon)

> +               __field(unsigned short, year)

> +               __field(unsigned char, alarm_type)

> +               __string(name, process_name)

> +       ),

> +

> +       TP_fast_assign(

> +               __entry->expires = alarm->node.expires.tv64;

> +               __entry->second = rtc_ktime_to_tm(alarm->node.expires).tm_sec;

> +               __entry->minute = rtc_ktime_to_tm(alarm->node.expires).tm_min;

> +               __entry->hour = rtc_ktime_to_tm(alarm->node.expires).tm_hour;

> +               __entry->day = rtc_ktime_to_tm(alarm->node.expires).tm_mday;

> +               __entry->mon = rtc_ktime_to_tm(alarm->node.expires).tm_mon;

> +               __entry->year = rtc_ktime_to_tm(alarm->node.expires).tm_year;

> +               __entry->alarm_type = alarm->type;

> +               __assign_str(name, process_name);

> +       ),

> +

> +       TP_printk("process:%s alarmtimer type:%s expires:%llu "

> +                 "time: %hu-%u-%u %u:%u:%u",

> +                 __get_str(name),

> +                 show_alarm_type((1 << __entry->alarm_type)),

> +                 __entry->expires,

> +                 __entry->year + 1900,

> +                 __entry->mon + 1,

> +                 __entry->day,

> +                 __entry->hour,

> +                 __entry->minute,

> +                 __entry->second

> +       )

> +);

> +

> +DEFINE_EVENT(alarm_processing, alarmtimer_fired,

> +

> +       TP_PROTO(struct alarm *alarm, char *process_name),

> +

> +       TP_ARGS(alarm, process_name)

> +);

> +

> +DEFINE_EVENT(alarm_processing, alarmtimer_start,

> +

> +       TP_PROTO(struct alarm *alarm, char *process_name),

> +

> +       TP_ARGS(alarm, process_name)

> +);

> +

> +DEFINE_EVENT(alarm_processing, alarmtimer_restart,

> +

> +       TP_PROTO(struct alarm *alarm, char *process_name),

> +

> +       TP_ARGS(alarm, process_name)

> +);

> +

> +DEFINE_EVENT(alarm_processing, alarmtimer_cancel,

> +

> +       TP_PROTO(struct alarm *alarm, char *process_name),

> +

> +       TP_ARGS(alarm, process_name)

> +);

> +

> +#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 c3aad68..7cd15eb 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

> @@ -194,6 +197,7 @@ static enum hrtimer_restart alarmtimer_fired(struct hrtimer *timer)

>         }

>         spin_unlock_irqrestore(&base->lock, flags);

>

> +       trace_alarmtimer_fired(alarm, NULL);

>         return ret;

>

>  }

> @@ -218,11 +222,11 @@ EXPORT_SYMBOL_GPL(alarm_expires_remaining);

>   */

>  static int alarmtimer_suspend(struct device *dev)

>  {

> -       struct rtc_time tm;

> +       struct rtc_time tm, tm_set;

>         ktime_t min, now;

>         unsigned long flags;

>         struct rtc_device *rtc;

> -       int i;

> +       int i, type = 0;

>         int ret;

>

>         spin_lock_irqsave(&freezer_delta_lock, flags);

> @@ -247,8 +251,10 @@ 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)) {

>                         min = delta;

> +                       type = i;

> +               }

>         }

>         if (min.tv64 == 0)

>                 return 0;

> @@ -264,6 +270,11 @@ static int alarmtimer_suspend(struct device *dev)

>         now = rtc_tm_to_ktime(tm);

>         now = ktime_add(now, min);

>

> +       if (trace_alarmtimer_suspend_enabled()) {

> +               tm_set = rtc_ktime_to_tm(now);

> +               trace_alarmtimer_suspend(&tm_set, type);

> +       }

> +

>         /* Set alarm, if in the past reject suspend briefly to handle */

>         ret = rtc_timer_start(rtc, &rtctimer, now, ktime_set(0, 0));

>         if (ret < 0)

> @@ -342,6 +353,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, current->comm);

>  }

>  EXPORT_SYMBOL_GPL(alarm_start);

>

> @@ -369,6 +382,8 @@ void alarm_restart(struct alarm *alarm)

>         hrtimer_restart(&alarm->timer);

>         alarmtimer_enqueue(base, alarm);

>         spin_unlock_irqrestore(&base->lock, flags);

> +

> +       trace_alarmtimer_restart(alarm, current->comm);

>  }

>  EXPORT_SYMBOL_GPL(alarm_restart);

>

> @@ -390,6 +405,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, current->comm);

>         return ret;

>  }

>  EXPORT_SYMBOL_GPL(alarm_try_to_cancel);

> --

> 1.7.9.5

>




-- 
Baolin.wang
Best Regards

John Stultz Aug. 30, 2016, 6:58 p.m. UTC | #2

On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang <baolin.wang@linaro.org> wrote:
> Hi,

>

> On 22 August 2016 at 12:23, Baolin Wang <baolin.wang@linaro.org> wrote:

>> For system debugging, we usually want to know who sets one alarm timer, the

>> time of the timer, when the timer started and fired and so on. Thus adding

>> tracepoints can help us trace the alarmtimer information.

>>

>> For example, when we debug the system supend/resume, if the system is always

>> resumed by RTC alarm, we can find out which process set the alarm timer to

>> resume system by below trace log:

>>

>> ......

>> Binder:2976_6-3473  [005] d..2  1076.587732: alarmtimer_start: process:Binder:2976_6

>> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>>

>> Binder:2976_7-3480  [002] d..2  1076.592707: alarmtimer_cancel: process:Binder:2976_7

>> alarmtimer type:ALARM_BOOTTIME expires:1325463060000000000 time: 2012-1-2 0:11:0

>>

>> Binder:2976_7-3480  [002] d..2  1076.592731: alarmtimer_start: process:Binder:2976_7

>> alarmtimer type:ALARM_BOOTTIME expires:1325378040000000000 time: 2012-1-1 0:34:0

>>

>> system_server-2976  [003] d..2  1076.605587: alarmtimer_cancel: process:system_server

>> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>>

>> system_server-2976  [003] d..2  1076.605608: alarmtimer_start: process:system_server

>> alarmtimer type:ALARM_BOOTTIME expires:1234155000000 time: 1970-1-1 0:20:35

>>

>> system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend: alarmtimer type:ALARM_BOOTTIME

>> expires time: 2012-1-1 0:34:0

>> ......

>>

>> From the trace log, we can find out the 'Binder:2976_7' process set one alarm

>> timer which resumes the system.

>

> Do you have any comments about this patch? Thanks.


No objection from me. I'll queue it for testing.

thanks
-john

(Exiting) Baolin Wang Aug. 31, 2016, 3:18 a.m. UTC | #3

Hi Steven,

On 30 August 2016 at 23:42, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Tue, 30 Aug 2016 19:50:20 +0800

> Baolin Wang <baolin.wang@linaro.org> wrote:

>

>> Hi,

>>

>> On 22 August 2016 at 12:23, Baolin Wang <baolin.wang@linaro.org> wrote:

>> > For system debugging, we usually want to know who sets one alarm timer, the

>> > time of the timer, when the timer started and fired and so on. Thus adding

>> > tracepoints can help us trace the alarmtimer information.

>> >

>> > For example, when we debug the system supend/resume, if the system is always

>> > resumed by RTC alarm, we can find out which process set the alarm timer to

>> > resume system by below trace log:

>> >

>> > ......

>> > Binder:2976_6-3473  [005] d..2  1076.587732: alarmtimer_start: process:Binder:2976_6

>> > alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>> >

>> > Binder:2976_7-3480  [002] d..2  1076.592707: alarmtimer_cancel: process:Binder:2976_7

>> > alarmtimer type:ALARM_BOOTTIME expires:1325463060000000000 time: 2012-1-2 0:11:0

>> >

>> > Binder:2976_7-3480  [002] d..2  1076.592731: alarmtimer_start: process:Binder:2976_7

>> > alarmtimer type:ALARM_BOOTTIME expires:1325378040000000000 time: 2012-1-1 0:34:0

>> >

>> > system_server-2976  [003] d..2  1076.605587: alarmtimer_cancel: process:system_server

>> > alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>> >

>> > system_server-2976  [003] d..2  1076.605608: alarmtimer_start: process:system_server

>> > alarmtimer type:ALARM_BOOTTIME expires:1234155000000 time: 1970-1-1 0:20:35

>> >

>> > system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend: alarmtimer type:ALARM_BOOTTIME

>> > expires time: 2012-1-1 0:34:0

>> > ......

>> >

>> > From the trace log, we can find out the 'Binder:2976_7' process set one alarm

>> > timer which resumes the system.

>>

>> Do you have any comments about this patch? Thanks.

>

> Looks fine to me.

>

> Acked-by: Steven Rostedt <rostedt@goodmis.org>

>

> Now you need to get the time maintainers to accept it.


Thanks.

-- 
Baolin.wang
Best Regards

(Exiting) Baolin Wang Aug. 31, 2016, 5:29 a.m. UTC | #4

On 31 August 2016 at 02:58, John Stultz <john.stultz@linaro.org> wrote:
> On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang <baolin.wang@linaro.org> wrote:

>> Hi,

>>

>> On 22 August 2016 at 12:23, Baolin Wang <baolin.wang@linaro.org> wrote:

>>> For system debugging, we usually want to know who sets one alarm timer, the

>>> time of the timer, when the timer started and fired and so on. Thus adding

>>> tracepoints can help us trace the alarmtimer information.

>>>

>>> For example, when we debug the system supend/resume, if the system is always

>>> resumed by RTC alarm, we can find out which process set the alarm timer to

>>> resume system by below trace log:

>>>

>>> ......

>>> Binder:2976_6-3473  [005] d..2  1076.587732: alarmtimer_start: process:Binder:2976_6

>>> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>>>

>>> Binder:2976_7-3480  [002] d..2  1076.592707: alarmtimer_cancel: process:Binder:2976_7

>>> alarmtimer type:ALARM_BOOTTIME expires:1325463060000000000 time: 2012-1-2 0:11:0

>>>

>>> Binder:2976_7-3480  [002] d..2  1076.592731: alarmtimer_start: process:Binder:2976_7

>>> alarmtimer type:ALARM_BOOTTIME expires:1325378040000000000 time: 2012-1-1 0:34:0

>>>

>>> system_server-2976  [003] d..2  1076.605587: alarmtimer_cancel: process:system_server

>>> alarmtimer type:ALARM_BOOTTIME expires:1234154000000 time: 1970-1-1 0:20:35

>>>

>>> system_server-2976  [003] d..2  1076.605608: alarmtimer_start: process:system_server

>>> alarmtimer type:ALARM_BOOTTIME expires:1234155000000 time: 1970-1-1 0:20:35

>>>

>>> system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend: alarmtimer type:ALARM_BOOTTIME

>>> expires time: 2012-1-1 0:34:0

>>> ......

>>>

>>> From the trace log, we can find out the 'Binder:2976_7' process set one alarm

>>> timer which resumes the system.

>>

>> Do you have any comments about this patch? Thanks.

>

> No objection from me. I'll queue it for testing.


Thanks, John.

>

> thanks

> -john




-- 
Baolin.wang
Best Regards

diff --git a/include/trace/events/alarmtimer.h b/include/trace/events/alarmtimer.h
new file mode 100644
index 0000000..6a34bc9
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,137 @@ 
+#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);
+
+#define show_alarm_type(type)	__print_flags(type, " | ",	\
+	{ 1 << ALARM_REALTIME, "ALARM_REALTIME" },		\
+	{ 1 << ALARM_BOOTTIME, "ALARM_BOOTTIME" })
+
+DECLARE_EVENT_CLASS(alarm_setting,
+
+	TP_PROTO(struct rtc_time *rtc_time, int flag),
+
+	TP_ARGS(rtc_time, flag),
+
+	TP_STRUCT__entry(
+		__field(unsigned char, second)
+		__field(unsigned char, minute)
+		__field(unsigned char, hour)
+		__field(unsigned char, day)
+		__field(unsigned char, mon)
+		__field(unsigned short, year)
+		__field(unsigned char, alarm_type)
+	),
+
+	TP_fast_assign(
+		__entry->second = rtc_time->tm_sec;
+		__entry->minute = rtc_time->tm_min;
+		__entry->hour = rtc_time->tm_hour;
+		__entry->day = rtc_time->tm_mday;
+		__entry->mon = rtc_time->tm_mon;
+		__entry->year = rtc_time->tm_year;
+		__entry->alarm_type = flag;
+	),
+
+	TP_printk("alarmtimer type:%s expires time: %hu-%u-%u %u:%u:%u",
+		  show_alarm_type((1 << __entry->alarm_type)),
+		  __entry->year + 1900,
+		  __entry->mon + 1,
+		  __entry->day,
+		  __entry->hour,
+		  __entry->minute,
+		  __entry->second
+	)
+);
+
+DEFINE_EVENT(alarm_setting, alarmtimer_suspend,
+
+	TP_PROTO(struct rtc_time *time, int flag),
+
+	TP_ARGS(time, flag)
+);
+
+DECLARE_EVENT_CLASS(alarm_processing,
+
+	TP_PROTO(struct alarm *alarm, char *process_name),
+
+	TP_ARGS(alarm, process_name),
+
+	TP_STRUCT__entry(
+		__field(unsigned long long, expires)
+		__field(unsigned char, second)
+		__field(unsigned char, minute)
+		__field(unsigned char, hour)
+		__field(unsigned char, day)
+		__field(unsigned char, mon)
+		__field(unsigned short, year)
+		__field(unsigned char, alarm_type)
+		__string(name, process_name)
+	),
+
+	TP_fast_assign(
+		__entry->expires = alarm->node.expires.tv64;
+		__entry->second = rtc_ktime_to_tm(alarm->node.expires).tm_sec;
+		__entry->minute = rtc_ktime_to_tm(alarm->node.expires).tm_min;
+		__entry->hour = rtc_ktime_to_tm(alarm->node.expires).tm_hour;
+		__entry->day = rtc_ktime_to_tm(alarm->node.expires).tm_mday;
+		__entry->mon = rtc_ktime_to_tm(alarm->node.expires).tm_mon;
+		__entry->year = rtc_ktime_to_tm(alarm->node.expires).tm_year;
+		__entry->alarm_type = alarm->type;
+		__assign_str(name, process_name);
+	),
+
+	TP_printk("process:%s alarmtimer type:%s expires:%llu "
+		  "time: %hu-%u-%u %u:%u:%u",
+		  __get_str(name),
+		  show_alarm_type((1 << __entry->alarm_type)),
+		  __entry->expires,
+		  __entry->year + 1900,
+		  __entry->mon + 1,
+		  __entry->day,
+		  __entry->hour,
+		  __entry->minute,
+		  __entry->second
+	)
+);
+
+DEFINE_EVENT(alarm_processing, alarmtimer_fired,
+
+	TP_PROTO(struct alarm *alarm, char *process_name),
+
+	TP_ARGS(alarm, process_name)
+);
+
+DEFINE_EVENT(alarm_processing, alarmtimer_start,
+
+	TP_PROTO(struct alarm *alarm, char *process_name),
+
+	TP_ARGS(alarm, process_name)
+);
+
+DEFINE_EVENT(alarm_processing, alarmtimer_restart,
+
+	TP_PROTO(struct alarm *alarm, char *process_name),
+
+	TP_ARGS(alarm, process_name)
+);
+
+DEFINE_EVENT(alarm_processing, alarmtimer_cancel,
+
+	TP_PROTO(struct alarm *alarm, char *process_name),
+
+	TP_ARGS(alarm, process_name)
+);
+
+#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 c3aad68..7cd15eb 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
@@ -194,6 +197,7 @@  static enum hrtimer_restart alarmtimer_fired(struct hrtimer *timer)
 	}
 	spin_unlock_irqrestore(&base->lock, flags);
 
+	trace_alarmtimer_fired(alarm, NULL);
 	return ret;
 
 }
@@ -218,11 +222,11 @@  EXPORT_SYMBOL_GPL(alarm_expires_remaining);
  */
 static int alarmtimer_suspend(struct device *dev)
 {
-	struct rtc_time tm;
+	struct rtc_time tm, tm_set;
 	ktime_t min, now;
 	unsigned long flags;
 	struct rtc_device *rtc;
-	int i;
+	int i, type = 0;
 	int ret;
 
 	spin_lock_irqsave(&freezer_delta_lock, flags);
@@ -247,8 +251,10 @@  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)) {
 			min = delta;
+			type = i;
+		}
 	}
 	if (min.tv64 == 0)
 		return 0;
@@ -264,6 +270,11 @@  static int alarmtimer_suspend(struct device *dev)
 	now = rtc_tm_to_ktime(tm);
 	now = ktime_add(now, min);
 
+	if (trace_alarmtimer_suspend_enabled()) {
+		tm_set = rtc_ktime_to_tm(now);
+		trace_alarmtimer_suspend(&tm_set, type);
+	}
+
 	/* Set alarm, if in the past reject suspend briefly to handle */
 	ret = rtc_timer_start(rtc, &rtctimer, now, ktime_set(0, 0));
 	if (ret < 0)
@@ -342,6 +353,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, current->comm);
 }
 EXPORT_SYMBOL_GPL(alarm_start);
 
@@ -369,6 +382,8 @@  void alarm_restart(struct alarm *alarm)
 	hrtimer_restart(&alarm->timer);
 	alarmtimer_enqueue(base, alarm);
 	spin_unlock_irqrestore(&base->lock, flags);
+
+	trace_alarmtimer_restart(alarm, current->comm);
 }
 EXPORT_SYMBOL_GPL(alarm_restart);
 
@@ -390,6 +405,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, current->comm);
 	return ret;
 }
 EXPORT_SYMBOL_GPL(alarm_try_to_cancel);

[v3] time: alarmtimer: Add the trcepoints for alarmtimer

Commit Message

Comments

Patch