xref: /linux/include/trace/events/timer.h (revision da1d9caf95def6f0320819cf941c9fd1069ba9e1)
1 /* SPDX-License-Identifier: GPL-2.0 */
2 #undef TRACE_SYSTEM
3 #define TRACE_SYSTEM timer
4 
5 #if !defined(_TRACE_TIMER_H) || defined(TRACE_HEADER_MULTI_READ)
6 #define _TRACE_TIMER_H
7 
8 #include <linux/tracepoint.h>
9 #include <linux/hrtimer.h>
10 #include <linux/timer.h>
11 
12 DECLARE_EVENT_CLASS(timer_class,
13 
14 	TP_PROTO(struct timer_list *timer),
15 
16 	TP_ARGS(timer),
17 
18 	TP_STRUCT__entry(
19 		__field( void *,	timer	)
20 	),
21 
22 	TP_fast_assign(
23 		__entry->timer	= timer;
24 	),
25 
26 	TP_printk("timer=%p", __entry->timer)
27 );
28 
29 /**
30  * timer_init - called when the timer is initialized
31  * @timer:	pointer to struct timer_list
32  */
33 DEFINE_EVENT(timer_class, timer_init,
34 
35 	TP_PROTO(struct timer_list *timer),
36 
37 	TP_ARGS(timer)
38 );
39 
40 #define decode_timer_flags(flags)			\
41 	__print_flags(flags, "|",			\
42 		{  TIMER_MIGRATING,	"M" },		\
43 		{  TIMER_DEFERRABLE,	"D" },		\
44 		{  TIMER_PINNED,	"P" },		\
45 		{  TIMER_IRQSAFE,	"I" })
46 
47 /**
48  * timer_start - called when the timer is started
49  * @timer:	pointer to struct timer_list
50  * @expires:	the timers expiry time
51  * @flags:	the timers flags
52  */
53 TRACE_EVENT(timer_start,
54 
55 	TP_PROTO(struct timer_list *timer,
56 		unsigned long expires,
57 		unsigned int flags),
58 
59 	TP_ARGS(timer, expires, flags),
60 
61 	TP_STRUCT__entry(
62 		__field( void *,	timer		)
63 		__field( void *,	function	)
64 		__field( unsigned long,	expires		)
65 		__field( unsigned long,	now		)
66 		__field( unsigned int,	flags		)
67 	),
68 
69 	TP_fast_assign(
70 		__entry->timer		= timer;
71 		__entry->function	= timer->function;
72 		__entry->expires	= expires;
73 		__entry->now		= jiffies;
74 		__entry->flags		= flags;
75 	),
76 
77 	TP_printk("timer=%p function=%ps expires=%lu [timeout=%ld] cpu=%u idx=%u flags=%s",
78 		  __entry->timer, __entry->function, __entry->expires,
79 		  (long)__entry->expires - __entry->now,
80 		  __entry->flags & TIMER_CPUMASK,
81 		  __entry->flags >> TIMER_ARRAYSHIFT,
82 		  decode_timer_flags(__entry->flags & TIMER_TRACE_FLAGMASK))
83 );
84 
85 /**
86  * timer_expire_entry - called immediately before the timer callback
87  * @timer:	pointer to struct timer_list
88  * @baseclk:	value of timer_base::clk when timer expires
89  *
90  * Allows to determine the timer latency.
91  */
92 TRACE_EVENT(timer_expire_entry,
93 
94 	TP_PROTO(struct timer_list *timer, unsigned long baseclk),
95 
96 	TP_ARGS(timer, baseclk),
97 
98 	TP_STRUCT__entry(
99 		__field( void *,	timer	)
100 		__field( unsigned long,	now	)
101 		__field( void *,	function)
102 		__field( unsigned long,	baseclk	)
103 	),
104 
105 	TP_fast_assign(
106 		__entry->timer		= timer;
107 		__entry->now		= jiffies;
108 		__entry->function	= timer->function;
109 		__entry->baseclk	= baseclk;
110 	),
111 
112 	TP_printk("timer=%p function=%ps now=%lu baseclk=%lu",
113 		  __entry->timer, __entry->function, __entry->now,
114 		  __entry->baseclk)
115 );
116 
117 /**
118  * timer_expire_exit - called immediately after the timer callback returns
119  * @timer:	pointer to struct timer_list
120  *
121  * When used in combination with the timer_expire_entry tracepoint we can
122  * determine the runtime of the timer callback function.
123  *
124  * NOTE: Do NOT dereference timer in TP_fast_assign. The pointer might
125  * be invalid. We solely track the pointer.
126  */
127 DEFINE_EVENT(timer_class, timer_expire_exit,
128 
129 	TP_PROTO(struct timer_list *timer),
130 
131 	TP_ARGS(timer)
132 );
133 
134 /**
135  * timer_cancel - called when the timer is canceled
136  * @timer:	pointer to struct timer_list
137  */
138 DEFINE_EVENT(timer_class, timer_cancel,
139 
140 	TP_PROTO(struct timer_list *timer),
141 
142 	TP_ARGS(timer)
143 );
144 
145 #define decode_clockid(type)						\
146 	__print_symbolic(type,						\
147 		{ CLOCK_REALTIME,	"CLOCK_REALTIME"	},	\
148 		{ CLOCK_MONOTONIC,	"CLOCK_MONOTONIC"	},	\
149 		{ CLOCK_BOOTTIME,	"CLOCK_BOOTTIME"	},	\
150 		{ CLOCK_TAI,		"CLOCK_TAI"		})
151 
152 #define decode_hrtimer_mode(mode)					\
153 	__print_symbolic(mode,						\
154 		{ HRTIMER_MODE_ABS,		"ABS"		},	\
155 		{ HRTIMER_MODE_REL,		"REL"		},	\
156 		{ HRTIMER_MODE_ABS_PINNED,	"ABS|PINNED"	},	\
157 		{ HRTIMER_MODE_REL_PINNED,	"REL|PINNED"	},	\
158 		{ HRTIMER_MODE_ABS_SOFT,	"ABS|SOFT"	},	\
159 		{ HRTIMER_MODE_REL_SOFT,	"REL|SOFT"	},	\
160 		{ HRTIMER_MODE_ABS_PINNED_SOFT,	"ABS|PINNED|SOFT" },	\
161 		{ HRTIMER_MODE_REL_PINNED_SOFT,	"REL|PINNED|SOFT" })
162 
163 /**
164  * hrtimer_init - called when the hrtimer is initialized
165  * @hrtimer:	pointer to struct hrtimer
166  * @clockid:	the hrtimers clock
167  * @mode:	the hrtimers mode
168  */
169 TRACE_EVENT(hrtimer_init,
170 
171 	TP_PROTO(struct hrtimer *hrtimer, clockid_t clockid,
172 		 enum hrtimer_mode mode),
173 
174 	TP_ARGS(hrtimer, clockid, mode),
175 
176 	TP_STRUCT__entry(
177 		__field( void *,		hrtimer		)
178 		__field( clockid_t,		clockid		)
179 		__field( enum hrtimer_mode,	mode		)
180 	),
181 
182 	TP_fast_assign(
183 		__entry->hrtimer	= hrtimer;
184 		__entry->clockid	= clockid;
185 		__entry->mode		= mode;
186 	),
187 
188 	TP_printk("hrtimer=%p clockid=%s mode=%s", __entry->hrtimer,
189 		  decode_clockid(__entry->clockid),
190 		  decode_hrtimer_mode(__entry->mode))
191 );
192 
193 /**
194  * hrtimer_start - called when the hrtimer is started
195  * @hrtimer:	pointer to struct hrtimer
196  * @mode:	the hrtimers mode
197  */
198 TRACE_EVENT(hrtimer_start,
199 
200 	TP_PROTO(struct hrtimer *hrtimer, enum hrtimer_mode mode),
201 
202 	TP_ARGS(hrtimer, mode),
203 
204 	TP_STRUCT__entry(
205 		__field( void *,	hrtimer		)
206 		__field( void *,	function	)
207 		__field( s64,		expires		)
208 		__field( s64,		softexpires	)
209 		__field( enum hrtimer_mode,	mode	)
210 	),
211 
212 	TP_fast_assign(
213 		__entry->hrtimer	= hrtimer;
214 		__entry->function	= hrtimer->function;
215 		__entry->expires	= hrtimer_get_expires(hrtimer);
216 		__entry->softexpires	= hrtimer_get_softexpires(hrtimer);
217 		__entry->mode		= mode;
218 	),
219 
220 	TP_printk("hrtimer=%p function=%ps expires=%llu softexpires=%llu "
221 		  "mode=%s", __entry->hrtimer, __entry->function,
222 		  (unsigned long long) __entry->expires,
223 		  (unsigned long long) __entry->softexpires,
224 		  decode_hrtimer_mode(__entry->mode))
225 );
226 
227 /**
228  * hrtimer_expire_entry - called immediately before the hrtimer callback
229  * @hrtimer:	pointer to struct hrtimer
230  * @now:	pointer to variable which contains current time of the
231  *		timers base.
232  *
233  * Allows to determine the timer latency.
234  */
235 TRACE_EVENT(hrtimer_expire_entry,
236 
237 	TP_PROTO(struct hrtimer *hrtimer, ktime_t *now),
238 
239 	TP_ARGS(hrtimer, now),
240 
241 	TP_STRUCT__entry(
242 		__field( void *,	hrtimer	)
243 		__field( s64,		now	)
244 		__field( void *,	function)
245 	),
246 
247 	TP_fast_assign(
248 		__entry->hrtimer	= hrtimer;
249 		__entry->now		= *now;
250 		__entry->function	= hrtimer->function;
251 	),
252 
253 	TP_printk("hrtimer=%p function=%ps now=%llu",
254 		  __entry->hrtimer, __entry->function,
255 		  (unsigned long long) __entry->now)
256 );
257 
258 DECLARE_EVENT_CLASS(hrtimer_class,
259 
260 	TP_PROTO(struct hrtimer *hrtimer),
261 
262 	TP_ARGS(hrtimer),
263 
264 	TP_STRUCT__entry(
265 		__field( void *,	hrtimer	)
266 	),
267 
268 	TP_fast_assign(
269 		__entry->hrtimer	= hrtimer;
270 	),
271 
272 	TP_printk("hrtimer=%p", __entry->hrtimer)
273 );
274 
275 /**
276  * hrtimer_expire_exit - called immediately after the hrtimer callback returns
277  * @hrtimer:	pointer to struct hrtimer
278  *
279  * When used in combination with the hrtimer_expire_entry tracepoint we can
280  * determine the runtime of the callback function.
281  */
282 DEFINE_EVENT(hrtimer_class, hrtimer_expire_exit,
283 
284 	TP_PROTO(struct hrtimer *hrtimer),
285 
286 	TP_ARGS(hrtimer)
287 );
288 
289 /**
290  * hrtimer_cancel - called when the hrtimer is canceled
291  * @hrtimer:	pointer to struct hrtimer
292  */
293 DEFINE_EVENT(hrtimer_class, hrtimer_cancel,
294 
295 	TP_PROTO(struct hrtimer *hrtimer),
296 
297 	TP_ARGS(hrtimer)
298 );
299 
300 /**
301  * itimer_state - called when itimer is started or canceled
302  * @which:	name of the interval timer
303  * @value:	the itimers value, itimer is canceled if value->it_value is
304  *		zero, otherwise it is started
305  * @expires:	the itimers expiry time
306  */
307 TRACE_EVENT(itimer_state,
308 
309 	TP_PROTO(int which, const struct itimerspec64 *const value,
310 		 unsigned long long expires),
311 
312 	TP_ARGS(which, value, expires),
313 
314 	TP_STRUCT__entry(
315 		__field(	int,			which		)
316 		__field(	unsigned long long,	expires		)
317 		__field(	long,			value_sec	)
318 		__field(	long,			value_nsec	)
319 		__field(	long,			interval_sec	)
320 		__field(	long,			interval_nsec	)
321 	),
322 
323 	TP_fast_assign(
324 		__entry->which		= which;
325 		__entry->expires	= expires;
326 		__entry->value_sec	= value->it_value.tv_sec;
327 		__entry->value_nsec	= value->it_value.tv_nsec;
328 		__entry->interval_sec	= value->it_interval.tv_sec;
329 		__entry->interval_nsec	= value->it_interval.tv_nsec;
330 	),
331 
332 	TP_printk("which=%d expires=%llu it_value=%ld.%06ld it_interval=%ld.%06ld",
333 		  __entry->which, __entry->expires,
334 		  __entry->value_sec, __entry->value_nsec / NSEC_PER_USEC,
335 		  __entry->interval_sec, __entry->interval_nsec / NSEC_PER_USEC)
336 );
337 
338 /**
339  * itimer_expire - called when itimer expires
340  * @which:	type of the interval timer
341  * @pid:	pid of the process which owns the timer
342  * @now:	current time, used to calculate the latency of itimer
343  */
344 TRACE_EVENT(itimer_expire,
345 
346 	TP_PROTO(int which, struct pid *pid, unsigned long long now),
347 
348 	TP_ARGS(which, pid, now),
349 
350 	TP_STRUCT__entry(
351 		__field( int ,			which	)
352 		__field( pid_t,			pid	)
353 		__field( unsigned long long,	now	)
354 	),
355 
356 	TP_fast_assign(
357 		__entry->which	= which;
358 		__entry->now	= now;
359 		__entry->pid	= pid_nr(pid);
360 	),
361 
362 	TP_printk("which=%d pid=%d now=%llu", __entry->which,
363 		  (int) __entry->pid, __entry->now)
364 );
365 
366 #ifdef CONFIG_NO_HZ_COMMON
367 
368 #define TICK_DEP_NAMES					\
369 		tick_dep_mask_name(NONE)		\
370 		tick_dep_name(POSIX_TIMER)		\
371 		tick_dep_name(PERF_EVENTS)		\
372 		tick_dep_name(SCHED)			\
373 		tick_dep_name(CLOCK_UNSTABLE)		\
374 		tick_dep_name_end(RCU)
375 
376 #undef tick_dep_name
377 #undef tick_dep_mask_name
378 #undef tick_dep_name_end
379 
380 /* The MASK will convert to their bits and they need to be processed too */
381 #define tick_dep_name(sdep) TRACE_DEFINE_ENUM(TICK_DEP_BIT_##sdep); \
382 	TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
383 #define tick_dep_name_end(sdep)  TRACE_DEFINE_ENUM(TICK_DEP_BIT_##sdep); \
384 	TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
385 /* NONE only has a mask defined for it */
386 #define tick_dep_mask_name(sdep) TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
387 
388 TICK_DEP_NAMES
389 
390 #undef tick_dep_name
391 #undef tick_dep_mask_name
392 #undef tick_dep_name_end
393 
394 #define tick_dep_name(sdep) { TICK_DEP_MASK_##sdep, #sdep },
395 #define tick_dep_mask_name(sdep) { TICK_DEP_MASK_##sdep, #sdep },
396 #define tick_dep_name_end(sdep) { TICK_DEP_MASK_##sdep, #sdep }
397 
398 #define show_tick_dep_name(val)				\
399 	__print_symbolic(val, TICK_DEP_NAMES)
400 
401 TRACE_EVENT(tick_stop,
402 
403 	TP_PROTO(int success, int dependency),
404 
405 	TP_ARGS(success, dependency),
406 
407 	TP_STRUCT__entry(
408 		__field( int ,		success	)
409 		__field( int ,		dependency )
410 	),
411 
412 	TP_fast_assign(
413 		__entry->success	= success;
414 		__entry->dependency	= dependency;
415 	),
416 
417 	TP_printk("success=%d dependency=%s",  __entry->success, \
418 			show_tick_dep_name(__entry->dependency))
419 );
420 #endif
421 
422 #endif /*  _TRACE_TIMER_H */
423 
424 /* This part must be outside protection */
425 #include <trace/define_trace.h>
426