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