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

[Baolin Wang]

On 18 October 2016 at 03:03, Steven Rostedt  wrote:
> On Tue, 11 Oct 2016 18:48:16 +0800
> Baolin Wang  wrote:
>
>> ---
>> Changes since v2:
>>  - Save time as s64 type.
>>  - Remove 'process_name' parameter and add 'now' parameter.
>>  - Rename the trace event name.
>>  - Remove restart trace event.
>>  - Other optimization.
>> ---
>>  include/trace/events/alarmtimer.h |   92 
>> +
>>  kernel/time/alarmtimer.c  |   16 ++-
>>  2 files changed, 106 insertions(+), 2 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 000..4c92a3e
>> --- /dev/null
>> +++ b/include/trace/events/alarmtimer.h
>> @@ -0,0 +1,92 @@
>> +#undef TRACE_SYSTEM
>> +#define TRACE_SYSTEM alarmtimer
>> +
>> +#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
>> +#define _TRACE_ALARMTIMER_H
>> +
>> +#include 
>> +#include 
>> +#include 
>> +
>> +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" })
>
> Why have the "ALARM_" prefix in the string? We already know that these
> are "alarm" tracepoints. They just make the lines longer than they need
> to be.
>
> Other than that, from a tracing point of view, this looks fine to me.

Thanks Steven. I will remove the prefix and add your ACK in next version.

-- 
Baolin.wang
Best Regards

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

[Baolin Wang]

On 18 October 2016 at 03:03, Steven Rostedt  wrote:
> On Tue, 11 Oct 2016 18:48:16 +0800
> Baolin Wang  wrote:
>
>> ---
>> Changes since v2:
>>  - Save time as s64 type.
>>  - Remove 'process_name' parameter and add 'now' parameter.
>>  - Rename the trace event name.
>>  - Remove restart trace event.
>>  - Other optimization.
>> ---
>>  include/trace/events/alarmtimer.h |   92 
>> +
>>  kernel/time/alarmtimer.c  |   16 ++-
>>  2 files changed, 106 insertions(+), 2 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 000..4c92a3e
>> --- /dev/null
>> +++ b/include/trace/events/alarmtimer.h
>> @@ -0,0 +1,92 @@
>> +#undef TRACE_SYSTEM
>> +#define TRACE_SYSTEM alarmtimer
>> +
>> +#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
>> +#define _TRACE_ALARMTIMER_H
>> +
>> +#include 
>> +#include 
>> +#include 
>> +
>> +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" })
>
> Why have the "ALARM_" prefix in the string? We already know that these
> are "alarm" tracepoints. They just make the lines longer than they need
> to be.
>
> Other than that, from a tracing point of view, this looks fine to me.

Thanks Steven. I will remove the prefix and add your ACK in next version.

-- 
Baolin.wang
Best Regards

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

[Steven Rostedt]

On Tue, 11 Oct 2016 18:48:16 +0800
Baolin Wang  wrote:

> For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
> alarmtimer:ffc1319a7800 type:ALARM_REALTIME
> expires:13254631200 now:1325376810370370245
> 
> Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
> alarmtimer:ffc1319a7800 type:ALARM_REALTIME
> expires:13253768400 now:1325376810370384591
> 
> Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
> alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
> expires:17955200 now:150154008122
> 
> Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
> alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
> expires:17955100 now:150154025622
> 
> ..
> 
> system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend:
> alarmtimer type:ALARM_BOOTTIME expires: 1325376839802714584
> 
> ..
> 
> >From the trace log, we can find out the 'Binder:3292_2' process  
> set one alarm timer which resumes the system.
> 
> Signed-off-by: Baolin Wang 
> ---
> Changes since v2:
>  - Save time as s64 type.
>  - Remove 'process_name' parameter and add 'now' parameter.
>  - Rename the trace event name.
>  - Remove restart trace event.
>  - Other optimization.
> ---
>  include/trace/events/alarmtimer.h |   92 
> +
>  kernel/time/alarmtimer.c  |   16 ++-
>  2 files changed, 106 insertions(+), 2 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 000..4c92a3e
> --- /dev/null
> +++ b/include/trace/events/alarmtimer.h
> @@ -0,0 +1,92 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM alarmtimer
> +
> +#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_ALARMTIMER_H
> +
> +#include 
> +#include 
> +#include 
> +
> +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" })

Why have the "ALARM_" prefix in the string? We already know that these
are "alarm" tracepoints. They just make the lines longer than they need
to be.

Other than that, from a tracing point of view, this looks fine to me.

Acked-by: Steven Rostedt 

-- Steve


> +
> +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 
> diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
> index c3aad68..4e10dad 100644
> --- a/kernel/time/alarmtimer.c
> +++ 

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

[Steven Rostedt]

On Tue, 11 Oct 2016 18:48:16 +0800
Baolin Wang  wrote:

> For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
> alarmtimer:ffc1319a7800 type:ALARM_REALTIME
> expires:13254631200 now:1325376810370370245
> 
> Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
> alarmtimer:ffc1319a7800 type:ALARM_REALTIME
> expires:13253768400 now:1325376810370384591
> 
> Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
> alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
> expires:17955200 now:150154008122
> 
> Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
> alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
> expires:17955100 now:150154025622
> 
> ..
> 
> system_server-3000  [002] ...1  1087.737565: alarmtimer_suspend:
> alarmtimer type:ALARM_BOOTTIME expires: 1325376839802714584
> 
> ..
> 
> >From the trace log, we can find out the 'Binder:3292_2' process  
> set one alarm timer which resumes the system.
> 
> Signed-off-by: Baolin Wang 
> ---
> Changes since v2:
>  - Save time as s64 type.
>  - Remove 'process_name' parameter and add 'now' parameter.
>  - Rename the trace event name.
>  - Remove restart trace event.
>  - Other optimization.
> ---
>  include/trace/events/alarmtimer.h |   92 
> +
>  kernel/time/alarmtimer.c  |   16 ++-
>  2 files changed, 106 insertions(+), 2 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 000..4c92a3e
> --- /dev/null
> +++ b/include/trace/events/alarmtimer.h
> @@ -0,0 +1,92 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM alarmtimer
> +
> +#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_ALARMTIMER_H
> +
> +#include 
> +#include 
> +#include 
> +
> +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" })

Why have the "ALARM_" prefix in the string? We already know that these
are "alarm" tracepoints. They just make the lines longer than they need
to be.

Other than that, from a tracing point of view, this looks fine to me.

Acked-by: Steven Rostedt 

-- Steve


> +
> +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 
> diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
> index c3aad68..4e10dad 100644
> --- a/kernel/time/alarmtimer.c
> +++ b/kernel/time/alarmtimer.c
> @@ -26,6 +26,9 @@
>  #include 
>  #include 
>  

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

[Baolin Wang]

For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13254631200 now:1325376810370370245

Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13253768400 now:1325376810370384591

Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955200 now:150154008122

Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955100 now:150154025622

..

system_server-3000  [002] ...1  162.701940: alarmtimer_suspend:
alarmtimer type:ALARM_REALTIME expires:1325376839802714584

..

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

Signed-off-by: Baolin Wang 
---
Changes since v2:
 - Save time as s64 type.
 - Remove 'process_name' parameter and add 'now' parameter.
 - Rename the trace event name.
 - Remove restart trace event.
 - Other optimization.
---
 include/trace/events/alarmtimer.h |   92 +
 kernel/time/alarmtimer.c  |   16 ++-
 2 files changed, 106 insertions(+), 2 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 000..4c92a3e
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,92 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM alarmtimer
+
+#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_ALARMTIMER_H
+
+#include 
+#include 
+#include 
+
+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" })
+
+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 
diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
index c3aad68..4e10dad 100644
--- a/kernel/time/alarmtimer.c
+++ b/kernel/time/alarmtimer.c
@@ -26,6 +26,9 @@
 #include 
 #include 
 
+#define CREATE_TRACE_POINTS
+#include 
+
 /**
  * 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(>lock, flags);
 
+   trace_alarmtimer_fired(alarm, base->gettime());
return ret;
 
 }
@@ -222,7 +226,7 @@ static int alarmtimer_suspend(struct device *dev)
ktime_t min, now;
unsigned long flags;
struct rtc_device 

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

[Baolin Wang]

For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13254631200 now:1325376810370370245

Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13253768400 now:1325376810370384591

Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955200 now:150154008122

Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955100 now:150154025622

..

system_server-3000  [002] ...1  162.701940: alarmtimer_suspend:
alarmtimer type:ALARM_REALTIME expires:1325376839802714584

..

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

Signed-off-by: Baolin Wang 
---
Changes since v2:
 - Save time as s64 type.
 - Remove 'process_name' parameter and add 'now' parameter.
 - Rename the trace event name.
 - Remove restart trace event.
 - Other optimization.
---
 include/trace/events/alarmtimer.h |   92 +
 kernel/time/alarmtimer.c  |   16 ++-
 2 files changed, 106 insertions(+), 2 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 000..4c92a3e
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,92 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM alarmtimer
+
+#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_ALARMTIMER_H
+
+#include 
+#include 
+#include 
+
+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" })
+
+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 
diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
index c3aad68..4e10dad 100644
--- a/kernel/time/alarmtimer.c
+++ b/kernel/time/alarmtimer.c
@@ -26,6 +26,9 @@
 #include 
 #include 
 
+#define CREATE_TRACE_POINTS
+#include 
+
 /**
  * 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(>lock, flags);
 
+   trace_alarmtimer_fired(alarm, base->gettime());
return ret;
 
 }
@@ -222,7 +226,7 @@ static int alarmtimer_suspend(struct device *dev)
ktime_t min, now;
unsigned long flags;
struct rtc_device *rtc;
-   int i;
+   

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

[Baolin Wang]

For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13254631200 now:1325376810370370245

Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13253768400 now:1325376810370384591

Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955200 now:150154008122

Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955100 now:150154025622

..

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

..

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

Signed-off-by: Baolin Wang 
---
Changes since v2:
 - Save time as s64 type.
 - Remove 'process_name' parameter and add 'now' parameter.
 - Rename the trace event name.
 - Remove restart trace event.
 - Other optimization.
---
 include/trace/events/alarmtimer.h |   92 +
 kernel/time/alarmtimer.c  |   16 ++-
 2 files changed, 106 insertions(+), 2 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 000..4c92a3e
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,92 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM alarmtimer
+
+#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_ALARMTIMER_H
+
+#include 
+#include 
+#include 
+
+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" })
+
+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 
diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
index c3aad68..4e10dad 100644
--- a/kernel/time/alarmtimer.c
+++ b/kernel/time/alarmtimer.c
@@ -26,6 +26,9 @@
 #include 
 #include 
 
+#define CREATE_TRACE_POINTS
+#include 
+
 /**
  * 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(>lock, flags);
 
+   trace_alarmtimer_fired(alarm, base->gettime());
return ret;
 
 }
@@ -222,7 +226,7 @@ static int alarmtimer_suspend(struct device *dev)
ktime_t min, now;
unsigned long flags;
struct rtc_device 

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

[Baolin Wang]

For system debugging, we sometimes 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:3292_2-3304  [000] d..2   149.981123: alarmtimer_cancel:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13254631200 now:1325376810370370245

Binder:3292_2-3304  [000] d..2   149.981136: alarmtimer_start:
alarmtimer:ffc1319a7800 type:ALARM_REALTIME
expires:13253768400 now:1325376810370384591

Binder:3292_9-3953  [000] d..2   150.212991: alarmtimer_cancel:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955200 now:150154008122

Binder:3292_9-3953  [000] d..2   150.213006: alarmtimer_start:
alarmtimer:ffc1319a5a00 type:ALARM_BOOTTIME
expires:17955100 now:150154025622

..

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

..

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

Signed-off-by: Baolin Wang 
---
Changes since v2:
 - Save time as s64 type.
 - Remove 'process_name' parameter and add 'now' parameter.
 - Rename the trace event name.
 - Remove restart trace event.
 - Other optimization.
---
 include/trace/events/alarmtimer.h |   92 +
 kernel/time/alarmtimer.c  |   16 ++-
 2 files changed, 106 insertions(+), 2 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 000..4c92a3e
--- /dev/null
+++ b/include/trace/events/alarmtimer.h
@@ -0,0 +1,92 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM alarmtimer
+
+#if !defined(_TRACE_ALARMTIMER_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_ALARMTIMER_H
+
+#include 
+#include 
+#include 
+
+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" })
+
+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 
diff --git a/kernel/time/alarmtimer.c b/kernel/time/alarmtimer.c
index c3aad68..4e10dad 100644
--- a/kernel/time/alarmtimer.c
+++ b/kernel/time/alarmtimer.c
@@ -26,6 +26,9 @@
 #include 
 #include 
 
+#define CREATE_TRACE_POINTS
+#include 
+
 /**
  * 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(>lock, flags);
 
+   trace_alarmtimer_fired(alarm, base->gettime());
return ret;
 
 }
@@ -222,7 +226,7 @@ static int alarmtimer_suspend(struct device *dev)
ktime_t min, now;
unsigned long flags;
struct rtc_device *rtc;
-   int i;
+ 

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

[Baolin Wang]

On 31 August 2016 at 02:58, John Stultz  wrote:
> On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang  wrote:
>> Hi,
>>
>> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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

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

[Baolin Wang]

On 31 August 2016 at 02:58, John Stultz  wrote:
> On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang  wrote:
>> Hi,
>>
>> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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

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

[Baolin Wang]

Hi Steven,

On 30 August 2016 at 23:42, Steven Rostedt  wrote:
> On Tue, 30 Aug 2016 19:50:20 +0800
> Baolin Wang  wrote:
>
>> Hi,
>>
>> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
>
> Now you need to get the time maintainers to accept it.

Thanks.

-- 
Baolin.wang
Best Regards

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

[Baolin Wang]

Hi Steven,

On 30 August 2016 at 23:42, Steven Rostedt  wrote:
> On Tue, 30 Aug 2016 19:50:20 +0800
> Baolin Wang  wrote:
>
>> Hi,
>>
>> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
>
> Now you need to get the time maintainers to accept it.

Thanks.

-- 
Baolin.wang
Best Regards

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

[John Stultz]

On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang  wrote:
> Hi,
>
> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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

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

[John Stultz]

On Tue, Aug 30, 2016 at 4:50 AM, Baolin Wang  wrote:
> Hi,
>
> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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

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

[Steven Rostedt]

On Tue, 30 Aug 2016 19:50:20 +0800
Baolin Wang  wrote:

> Hi,
> 
> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 

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

Thanks!

-- Steve

> 
> >
> > Signed-off-by: Baolin Wang 
> > ---

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

[Steven Rostedt]

On Tue, 30 Aug 2016 19:50:20 +0800
Baolin Wang  wrote:

> Hi,
> 
> On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 

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

Thanks!

-- Steve

> 
> >
> > Signed-off-by: Baolin Wang 
> > ---

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

[Baolin Wang]

Hi,

On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
> ---
> 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 000..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 
> +#include 
> +#include 
> +
> +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)
> +  

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

[Baolin Wang]

Hi,

On 22 August 2016 at 12:23, Baolin Wang  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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
> ---
> 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 000..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 
> +#include 
> +#include 
> +
> +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)
> + 

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

[Baolin Wang]

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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
---
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 000..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 
+#include 
+#include 
+
+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 = 

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

[Baolin Wang]

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:123415400 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:13254630600 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:13253780400 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:123415400 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:123415500 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 
---
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 000..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 
+#include 
+#include 
+
+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;
+