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