[PATCH] timekeeping: Add tracepoints for xtime changes - v2

[PATCH] timekeeping: Add tracepoints for xtime changes - v2

[David Ahern]

One component of tracking perf_clock timestamps to time-of-day is
updates to xtime by a user or ntpd. To that end this patch adds
tracepoints to the timekeeping code as suggested by Thomas:
https://lkml.org/lkml/2011/3/2/186

v2: use timekeeping_get_ns to retrieve nsec component

Signed-off-by: David Ahern <dsahern@gmail.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: John Stultz <johnstul@us.ibm.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
---
 include/trace/events/timekeeping.h |   51 ++++++++++++++++++++++++++++++++++++
 kernel/time/timekeeping.c          |   11 ++++++++
 2 files changed, 62 insertions(+)
 create mode 100644 include/trace/events/timekeeping.h

diff --git a/include/trace/events/timekeeping.h b/include/trace/events/timekeeping.h
new file mode 100644
index 0000000..ff7a631
--- /dev/null
+++ b/include/trace/events/timekeeping.h
@@ -0,0 +1,51 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM timekeeping
+
+#if !defined(_TRACE_TIMEKEEP_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_TIMEKEEP_H
+
+#include <linux/tracepoint.h>
+#include <linux/time.h>
+
+DECLARE_EVENT_CLASS(xtime_template,
+
+	TP_PROTO(u64 sec, u64 nsec),
+
+	TP_ARGS(sec, nsec),
+
+	TP_STRUCT__entry(
+		__field( u64,	sec)
+		__field( u64,	nsec)
+	),
+
+	TP_fast_assign(
+		__entry->sec  = sec;
+		__entry->nsec = nsec;
+	),
+
+	TP_printk("sec=%Lu nsec=%Lu", __entry->sec, __entry->nsec)
+);
+
+DEFINE_EVENT(xtime_template, do_settimeofday,
+	TP_PROTO(u64 sec, u64 nsec),
+	TP_ARGS(sec, nsec));
+
+DEFINE_EVENT(xtime_template, timekeeping_inject_offset,
+	TP_PROTO(u64 sec, u64 nsec),
+	TP_ARGS(sec, nsec));
+
+DEFINE_EVENT(xtime_template, timekeeping_inject_sleeptime,
+	TP_PROTO(u64 sec, u64 nsec),
+	TP_ARGS(sec, nsec));
+
+DEFINE_EVENT(xtime_template, timekeeping_resume,
+	TP_PROTO(u64 sec, u64 nsec),
+	TP_ARGS(sec, nsec));
+
+DEFINE_EVENT(xtime_template, change_clocksource,
+	TP_PROTO(u64 sec, u64 nsec),
+	TP_ARGS(sec, nsec));
+#endif /*  _TRACE_TIMEKEEP_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
index 9a0bc98..0ce45ec 100644
--- a/kernel/time/timekeeping.c
+++ b/kernel/time/timekeeping.c
@@ -23,6 +23,8 @@
 #include <linux/stop_machine.h>
 #include <linux/pvclock_gtod.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/timekeeping.h>
 
 static struct timekeeper timekeeper;
 
@@ -462,6 +464,8 @@ int do_settimeofday(const struct timespec *tv)
 
 	timekeeping_update(tk, true);
 
+	trace_do_settimeofday(tk->xtime_sec, timekeeping_get_ns(tk));
+
 	write_sequnlock_irqrestore(&tk->lock, flags);
 
 	/* signal hrtimers about time change */
@@ -504,6 +508,8 @@ int timekeeping_inject_offset(struct timespec *ts)
 error: /* even if we error out, we forwarded the time, so call update */
 	timekeeping_update(tk, true);
 
+	trace_timekeeping_inject_offset(tk->xtime_sec, timekeeping_get_ns(tk));
+
 	write_sequnlock_irqrestore(&tk->lock, flags);
 
 	/* signal hrtimers about time change */
@@ -536,6 +542,7 @@ static int change_clocksource(void *data)
 			old->disable(old);
 	}
 	timekeeping_update(tk, true);
+	trace_change_clocksource(tk->xtime_sec, timekeeping_get_ns(tk));
 
 	write_sequnlock_irqrestore(&tk->lock, flags);
 
@@ -772,6 +779,9 @@ void timekeeping_inject_sleeptime(struct timespec *delta)
 
 	timekeeping_update(tk, true);
 
+	trace_timekeeping_inject_sleeptime(tk->xtime_sec,
+					   timekeeping_get_ns(tk));
+
 	write_sequnlock_irqrestore(&tk->lock, flags);
 
 	/* signal hrtimers about time change */
@@ -807,6 +817,7 @@ static void timekeeping_resume(void)
 	tk->ntp_error = 0;
 	timekeeping_suspended = 0;
 	timekeeping_update(tk, false);
+	trace_timekeeping_resume(tk->xtime_sec, timekeeping_get_ns(tk));
 	write_sequnlock_irqrestore(&tk->lock, flags);
 
 	touch_softlockup_watchdog();
-- 
1.7.10.1

Re: [PATCH] timekeeping: Add tracepoints for xtime changes - v2

[David Ahern]

ping... any comments or opinions on the tracepoints?

On 3/19/13 10:27 AM, David Ahern wrote:
> One component of tracking perf_clock timestamps to time-of-day is
> updates to xtime by a user or ntpd. To that end this patch adds
> tracepoints to the timekeeping code as suggested by Thomas:
> https://lkml.org/lkml/2011/3/2/186
>
> v2: use timekeeping_get_ns to retrieve nsec component
>
> Signed-off-by: David Ahern <dsahern@gmail.com>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: John Stultz <johnstul@us.ibm.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> ---
>   include/trace/events/timekeeping.h |   51 ++++++++++++++++++++++++++++++++++++
>   kernel/time/timekeeping.c          |   11 ++++++++
>   2 files changed, 62 insertions(+)
>   create mode 100644 include/trace/events/timekeeping.h
>
> diff --git a/include/trace/events/timekeeping.h b/include/trace/events/timekeeping.h
> new file mode 100644
> index 0000000..ff7a631
> --- /dev/null
> +++ b/include/trace/events/timekeeping.h
> @@ -0,0 +1,51 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM timekeeping
> +
> +#if !defined(_TRACE_TIMEKEEP_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_TIMEKEEP_H
> +
> +#include <linux/tracepoint.h>
> +#include <linux/time.h>
> +
> +DECLARE_EVENT_CLASS(xtime_template,
> +
> +	TP_PROTO(u64 sec, u64 nsec),
> +
> +	TP_ARGS(sec, nsec),
> +
> +	TP_STRUCT__entry(
> +		__field( u64,	sec)
> +		__field( u64,	nsec)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->sec  = sec;
> +		__entry->nsec = nsec;
> +	),
> +
> +	TP_printk("sec=%Lu nsec=%Lu", __entry->sec, __entry->nsec)
> +);
> +
> +DEFINE_EVENT(xtime_template, do_settimeofday,
> +	TP_PROTO(u64 sec, u64 nsec),
> +	TP_ARGS(sec, nsec));
> +
> +DEFINE_EVENT(xtime_template, timekeeping_inject_offset,
> +	TP_PROTO(u64 sec, u64 nsec),
> +	TP_ARGS(sec, nsec));
> +
> +DEFINE_EVENT(xtime_template, timekeeping_inject_sleeptime,
> +	TP_PROTO(u64 sec, u64 nsec),
> +	TP_ARGS(sec, nsec));
> +
> +DEFINE_EVENT(xtime_template, timekeeping_resume,
> +	TP_PROTO(u64 sec, u64 nsec),
> +	TP_ARGS(sec, nsec));
> +
> +DEFINE_EVENT(xtime_template, change_clocksource,
> +	TP_PROTO(u64 sec, u64 nsec),
> +	TP_ARGS(sec, nsec));
> +#endif /*  _TRACE_TIMEKEEP_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> index 9a0bc98..0ce45ec 100644
> --- a/kernel/time/timekeeping.c
> +++ b/kernel/time/timekeeping.c
> @@ -23,6 +23,8 @@
>   #include <linux/stop_machine.h>
>   #include <linux/pvclock_gtod.h>
>
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/timekeeping.h>
>
>   static struct timekeeper timekeeper;
>
> @@ -462,6 +464,8 @@ int do_settimeofday(const struct timespec *tv)
>
>   	timekeeping_update(tk, true);
>
> +	trace_do_settimeofday(tk->xtime_sec, timekeeping_get_ns(tk));
> +
>   	write_sequnlock_irqrestore(&tk->lock, flags);
>
>   	/* signal hrtimers about time change */
> @@ -504,6 +508,8 @@ int timekeeping_inject_offset(struct timespec *ts)
>   error: /* even if we error out, we forwarded the time, so call update */
>   	timekeeping_update(tk, true);
>
> +	trace_timekeeping_inject_offset(tk->xtime_sec, timekeeping_get_ns(tk));
> +
>   	write_sequnlock_irqrestore(&tk->lock, flags);
>
>   	/* signal hrtimers about time change */
> @@ -536,6 +542,7 @@ static int change_clocksource(void *data)
>   			old->disable(old);
>   	}
>   	timekeeping_update(tk, true);
> +	trace_change_clocksource(tk->xtime_sec, timekeeping_get_ns(tk));
>
>   	write_sequnlock_irqrestore(&tk->lock, flags);
>
> @@ -772,6 +779,9 @@ void timekeeping_inject_sleeptime(struct timespec *delta)
>
>   	timekeeping_update(tk, true);
>
> +	trace_timekeeping_inject_sleeptime(tk->xtime_sec,
> +					   timekeeping_get_ns(tk));
> +
>   	write_sequnlock_irqrestore(&tk->lock, flags);
>
>   	/* signal hrtimers about time change */
> @@ -807,6 +817,7 @@ static void timekeeping_resume(void)
>   	tk->ntp_error = 0;
>   	timekeeping_suspended = 0;
>   	timekeeping_update(tk, false);
> +	trace_timekeeping_resume(tk->xtime_sec, timekeeping_get_ns(tk));
>   	write_sequnlock_irqrestore(&tk->lock, flags);
>
>   	touch_softlockup_watchdog();
>

Re: [PATCH] timekeeping: Add tracepoints for xtime changes - v2

[David Ahern]

On 4/1/13 12:55 PM, John Stultz wrote:
>
> Sorry I missed this, I no longer receive emails at that address.

Noted. I'll update the address on future versions (and dropped the IBM 
one from this thread).

>     diff --git a/include/trace/events/timekeeping.h
>     b/include/trace/events/timekeeping.h
>     new file mode 100644
>     index 0000000..ff7a631
>     --- /dev/null
>     +++ b/include/trace/events/timekeeping.h
>     @@ -0,0 +1,51 @@
>     +#undef TRACE_SYSTEM
>     +#define TRACE_SYSTEM timekeeping
>     +
>     +#if !defined(_TRACE_TIMEKEEP_H) || defined(TRACE_HEADER_MULTI_READ)
>     +#define _TRACE_TIMEKEEP_H
>     +
>     +#include <linux/tracepoint.h>
>     +#include <linux/time.h>
>     +
>     +DECLARE_EVENT_CLASS(xtime_template,

> So xtime is becoming more of a historical reference in the code. Should
> this maybe be timespec_template? Or timeupdate_template?

What I want is to track updates (user, ntpd, other) to the timespec 
returned for gettimeofday (or, per the comment in that function, 
getnstimeofday). The event will have the new value for that timekeeper 
and the perf_clock timestamp as well so I can update the correlation.

I'm fine with calling it timespec_template. No religion on the names, 
only the feature.

--8<--

> This all looks reasonable. Though do we need to be more explicit in what
> we're tracing here? ie: CLOCK_REALTIME timestamps?

The tracepoints don't care about the what and the tp names follow the 
convention of trace_<function_name> so you know where it is triggering.

>
> I'd someday eventually like to rework the timekeeping core to be mostly
> ktime_t based, building time in a more logical method up from
> CLOCK_MONOTONIC rather then using CLOCK_REALTIME as our base and
> subtracting time from that. I'm just worried about what sort of
> constraints these tracepoints may put on a larger rework in the future.

Understood. And my comment above is not going to help -- ie., telling 
perf specific tracepoints which include function names. Should I 
consolidate this into a single trace_tod_update() that gets invoked in 
various places? The locations can move without affecting perf. I just 
want the tod update; where it happens should not matter.

David

David

Re: [PATCH] timekeeping: Add tracepoints for xtime changes - v2

[John Stultz]

On 04/01/2013 02:58 PM, David Ahern wrote:
> On 4/1/13 12:55 PM, John Stultz wrote:
>
>> This all looks reasonable. Though do we need to be more explicit in what
>> we're tracing here? ie: CLOCK_REALTIME timestamps?
>
> The tracepoints don't care about the what and the tp names follow the 
> convention of trace_<function_name> so you know where it is triggering.
>
>>
>> I'd someday eventually like to rework the timekeeping core to be mostly
>> ktime_t based, building time in a more logical method up from
>> CLOCK_MONOTONIC rather then using CLOCK_REALTIME as our base and
>> subtracting time from that. I'm just worried about what sort of
>> constraints these tracepoints may put on a larger rework in the future.
>
> Understood. And my comment above is not going to help -- ie., telling 
> perf specific tracepoints which include function names. Should I 
> consolidate this into a single trace_tod_update() that gets invoked in 
> various places? The locations can move without affecting perf. I just 
> want the tod update; where it happens should not matter.
>

I guess what I'm getting at is: What ABI are we creating here?  Can 
these tracepoints come and go without any consequence? Or would changing 
them in the future cause application breakage?

I'm somewhat worried even trace_tod_update() is maybe too vague (again 
not that the name specifically is critical, but that the semantics we're 
specifying are clear). In other words, I think you're wanting a 
tracepoint at any time CLOCK_REALTIME is updated by anything other then 
the normal progression of time? Is that right?

You may want to also include the leapsecond modification in the tracing 
as well.

thanks
-john

Re: [PATCH] timekeeping: Add tracepoints for xtime changes - v2

[David Ahern]

On 4/1/13 4:16 PM, John Stultz wrote:
> I guess what I'm getting at is: What ABI are we creating here?  Can
> these tracepoints come and go without any consequence? Or would changing
> them in the future cause application breakage?
>
> I'm somewhat worried even trace_tod_update() is maybe too vague (again
> not that the name specifically is critical, but that the semantics we're
> specifying are clear). In other words, I think you're wanting a
> tracepoint at any time CLOCK_REALTIME is updated by anything other then
> the normal progression of time? Is that right?

yes. essentially everywhere timekeeping_update() is called except 
update_wall_time().

>
> You may want to also include the leapsecond modification in the tracing
> as well.

I thought those were covered as well. hmm... maybe not if it triggers in 
update_wall_time.

David