1 /* 2 * trace task wakeup timings 3 * 4 * Copyright (C) 2007-2008 Steven Rostedt <srostedt@redhat.com> 5 * Copyright (C) 2008 Ingo Molnar <mingo@redhat.com> 6 * 7 * Based on code from the latency_tracer, that is: 8 * 9 * Copyright (C) 2004-2006 Ingo Molnar 10 * Copyright (C) 2004 Nadia Yvette Chambers 11 */ 12 #include <linux/module.h> 13 #include <linux/fs.h> 14 #include <linux/debugfs.h> 15 #include <linux/kallsyms.h> 16 #include <linux/uaccess.h> 17 #include <linux/ftrace.h> 18 #include <linux/sched/rt.h> 19 #include <linux/sched/deadline.h> 20 #include <trace/events/sched.h> 21 #include "trace.h" 22 23 static struct trace_array *wakeup_trace; 24 static int __read_mostly tracer_enabled; 25 26 static struct task_struct *wakeup_task; 27 static int wakeup_cpu; 28 static int wakeup_current_cpu; 29 static unsigned wakeup_prio = -1; 30 static int wakeup_rt; 31 static int wakeup_dl; 32 static int tracing_dl = 0; 33 34 static arch_spinlock_t wakeup_lock = 35 (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED; 36 37 static void wakeup_reset(struct trace_array *tr); 38 static void __wakeup_reset(struct trace_array *tr); 39 static int wakeup_graph_entry(struct ftrace_graph_ent *trace); 40 static void wakeup_graph_return(struct ftrace_graph_ret *trace); 41 42 static int save_flags; 43 static bool function_enabled; 44 45 #define TRACE_DISPLAY_GRAPH 1 46 47 static struct tracer_opt trace_opts[] = { 48 #ifdef CONFIG_FUNCTION_GRAPH_TRACER 49 /* display latency trace as call graph */ 50 { TRACER_OPT(display-graph, TRACE_DISPLAY_GRAPH) }, 51 #endif 52 { } /* Empty entry */ 53 }; 54 55 static struct tracer_flags tracer_flags = { 56 .val = 0, 57 .opts = trace_opts, 58 }; 59 60 #define is_graph() (tracer_flags.val & TRACE_DISPLAY_GRAPH) 61 62 #ifdef CONFIG_FUNCTION_TRACER 63 64 /* 65 * Prologue for the wakeup function tracers. 66 * 67 * Returns 1 if it is OK to continue, and preemption 68 * is disabled and data->disabled is incremented. 69 * 0 if the trace is to be ignored, and preemption 70 * is not disabled and data->disabled is 71 * kept the same. 72 * 73 * Note, this function is also used outside this ifdef but 74 * inside the #ifdef of the function graph tracer below. 75 * This is OK, since the function graph tracer is 76 * dependent on the function tracer. 77 */ 78 static int 79 func_prolog_preempt_disable(struct trace_array *tr, 80 struct trace_array_cpu **data, 81 int *pc) 82 { 83 long disabled; 84 int cpu; 85 86 if (likely(!wakeup_task)) 87 return 0; 88 89 *pc = preempt_count(); 90 preempt_disable_notrace(); 91 92 cpu = raw_smp_processor_id(); 93 if (cpu != wakeup_current_cpu) 94 goto out_enable; 95 96 *data = per_cpu_ptr(tr->trace_buffer.data, cpu); 97 disabled = atomic_inc_return(&(*data)->disabled); 98 if (unlikely(disabled != 1)) 99 goto out; 100 101 return 1; 102 103 out: 104 atomic_dec(&(*data)->disabled); 105 106 out_enable: 107 preempt_enable_notrace(); 108 return 0; 109 } 110 111 /* 112 * wakeup uses its own tracer function to keep the overhead down: 113 */ 114 static void 115 wakeup_tracer_call(unsigned long ip, unsigned long parent_ip, 116 struct ftrace_ops *op, struct pt_regs *pt_regs) 117 { 118 struct trace_array *tr = wakeup_trace; 119 struct trace_array_cpu *data; 120 unsigned long flags; 121 int pc; 122 123 if (!func_prolog_preempt_disable(tr, &data, &pc)) 124 return; 125 126 local_irq_save(flags); 127 trace_function(tr, ip, parent_ip, flags, pc); 128 local_irq_restore(flags); 129 130 atomic_dec(&data->disabled); 131 preempt_enable_notrace(); 132 } 133 134 static struct ftrace_ops trace_ops __read_mostly = 135 { 136 .func = wakeup_tracer_call, 137 .flags = FTRACE_OPS_FL_GLOBAL | FTRACE_OPS_FL_RECURSION_SAFE, 138 }; 139 #endif /* CONFIG_FUNCTION_TRACER */ 140 141 static int register_wakeup_function(int graph, int set) 142 { 143 int ret; 144 145 /* 'set' is set if TRACE_ITER_FUNCTION is about to be set */ 146 if (function_enabled || (!set && !(trace_flags & TRACE_ITER_FUNCTION))) 147 return 0; 148 149 if (graph) 150 ret = register_ftrace_graph(&wakeup_graph_return, 151 &wakeup_graph_entry); 152 else 153 ret = register_ftrace_function(&trace_ops); 154 155 if (!ret) 156 function_enabled = true; 157 158 return ret; 159 } 160 161 static void unregister_wakeup_function(int graph) 162 { 163 if (!function_enabled) 164 return; 165 166 if (graph) 167 unregister_ftrace_graph(); 168 else 169 unregister_ftrace_function(&trace_ops); 170 171 function_enabled = false; 172 } 173 174 static void wakeup_function_set(int set) 175 { 176 if (set) 177 register_wakeup_function(is_graph(), 1); 178 else 179 unregister_wakeup_function(is_graph()); 180 } 181 182 static int wakeup_flag_changed(struct tracer *tracer, u32 mask, int set) 183 { 184 if (mask & TRACE_ITER_FUNCTION) 185 wakeup_function_set(set); 186 187 return trace_keep_overwrite(tracer, mask, set); 188 } 189 190 static int start_func_tracer(int graph) 191 { 192 int ret; 193 194 ret = register_wakeup_function(graph, 0); 195 196 if (!ret && tracing_is_enabled()) 197 tracer_enabled = 1; 198 else 199 tracer_enabled = 0; 200 201 return ret; 202 } 203 204 static void stop_func_tracer(int graph) 205 { 206 tracer_enabled = 0; 207 208 unregister_wakeup_function(graph); 209 } 210 211 #ifdef CONFIG_FUNCTION_GRAPH_TRACER 212 static int wakeup_set_flag(u32 old_flags, u32 bit, int set) 213 { 214 215 if (!(bit & TRACE_DISPLAY_GRAPH)) 216 return -EINVAL; 217 218 if (!(is_graph() ^ set)) 219 return 0; 220 221 stop_func_tracer(!set); 222 223 wakeup_reset(wakeup_trace); 224 tracing_max_latency = 0; 225 226 return start_func_tracer(set); 227 } 228 229 static int wakeup_graph_entry(struct ftrace_graph_ent *trace) 230 { 231 struct trace_array *tr = wakeup_trace; 232 struct trace_array_cpu *data; 233 unsigned long flags; 234 int pc, ret = 0; 235 236 if (!func_prolog_preempt_disable(tr, &data, &pc)) 237 return 0; 238 239 local_save_flags(flags); 240 ret = __trace_graph_entry(tr, trace, flags, pc); 241 atomic_dec(&data->disabled); 242 preempt_enable_notrace(); 243 244 return ret; 245 } 246 247 static void wakeup_graph_return(struct ftrace_graph_ret *trace) 248 { 249 struct trace_array *tr = wakeup_trace; 250 struct trace_array_cpu *data; 251 unsigned long flags; 252 int pc; 253 254 if (!func_prolog_preempt_disable(tr, &data, &pc)) 255 return; 256 257 local_save_flags(flags); 258 __trace_graph_return(tr, trace, flags, pc); 259 atomic_dec(&data->disabled); 260 261 preempt_enable_notrace(); 262 return; 263 } 264 265 static void wakeup_trace_open(struct trace_iterator *iter) 266 { 267 if (is_graph()) 268 graph_trace_open(iter); 269 } 270 271 static void wakeup_trace_close(struct trace_iterator *iter) 272 { 273 if (iter->private) 274 graph_trace_close(iter); 275 } 276 277 #define GRAPH_TRACER_FLAGS (TRACE_GRAPH_PRINT_PROC | \ 278 TRACE_GRAPH_PRINT_ABS_TIME | \ 279 TRACE_GRAPH_PRINT_DURATION) 280 281 static enum print_line_t wakeup_print_line(struct trace_iterator *iter) 282 { 283 /* 284 * In graph mode call the graph tracer output function, 285 * otherwise go with the TRACE_FN event handler 286 */ 287 if (is_graph()) 288 return print_graph_function_flags(iter, GRAPH_TRACER_FLAGS); 289 290 return TRACE_TYPE_UNHANDLED; 291 } 292 293 static void wakeup_print_header(struct seq_file *s) 294 { 295 if (is_graph()) 296 print_graph_headers_flags(s, GRAPH_TRACER_FLAGS); 297 else 298 trace_default_header(s); 299 } 300 301 static void 302 __trace_function(struct trace_array *tr, 303 unsigned long ip, unsigned long parent_ip, 304 unsigned long flags, int pc) 305 { 306 if (is_graph()) 307 trace_graph_function(tr, ip, parent_ip, flags, pc); 308 else 309 trace_function(tr, ip, parent_ip, flags, pc); 310 } 311 #else 312 #define __trace_function trace_function 313 314 static int wakeup_set_flag(u32 old_flags, u32 bit, int set) 315 { 316 return -EINVAL; 317 } 318 319 static int wakeup_graph_entry(struct ftrace_graph_ent *trace) 320 { 321 return -1; 322 } 323 324 static enum print_line_t wakeup_print_line(struct trace_iterator *iter) 325 { 326 return TRACE_TYPE_UNHANDLED; 327 } 328 329 static void wakeup_graph_return(struct ftrace_graph_ret *trace) { } 330 static void wakeup_trace_open(struct trace_iterator *iter) { } 331 static void wakeup_trace_close(struct trace_iterator *iter) { } 332 333 #ifdef CONFIG_FUNCTION_TRACER 334 static void wakeup_print_header(struct seq_file *s) 335 { 336 trace_default_header(s); 337 } 338 #else 339 static void wakeup_print_header(struct seq_file *s) 340 { 341 trace_latency_header(s); 342 } 343 #endif /* CONFIG_FUNCTION_TRACER */ 344 #endif /* CONFIG_FUNCTION_GRAPH_TRACER */ 345 346 /* 347 * Should this new latency be reported/recorded? 348 */ 349 static int report_latency(cycle_t delta) 350 { 351 if (tracing_thresh) { 352 if (delta < tracing_thresh) 353 return 0; 354 } else { 355 if (delta <= tracing_max_latency) 356 return 0; 357 } 358 return 1; 359 } 360 361 static void 362 probe_wakeup_migrate_task(void *ignore, struct task_struct *task, int cpu) 363 { 364 if (task != wakeup_task) 365 return; 366 367 wakeup_current_cpu = cpu; 368 } 369 370 static void notrace 371 probe_wakeup_sched_switch(void *ignore, 372 struct task_struct *prev, struct task_struct *next) 373 { 374 struct trace_array_cpu *data; 375 cycle_t T0, T1, delta; 376 unsigned long flags; 377 long disabled; 378 int cpu; 379 int pc; 380 381 tracing_record_cmdline(prev); 382 383 if (unlikely(!tracer_enabled)) 384 return; 385 386 /* 387 * When we start a new trace, we set wakeup_task to NULL 388 * and then set tracer_enabled = 1. We want to make sure 389 * that another CPU does not see the tracer_enabled = 1 390 * and the wakeup_task with an older task, that might 391 * actually be the same as next. 392 */ 393 smp_rmb(); 394 395 if (next != wakeup_task) 396 return; 397 398 pc = preempt_count(); 399 400 /* disable local data, not wakeup_cpu data */ 401 cpu = raw_smp_processor_id(); 402 disabled = atomic_inc_return(&per_cpu_ptr(wakeup_trace->trace_buffer.data, cpu)->disabled); 403 if (likely(disabled != 1)) 404 goto out; 405 406 local_irq_save(flags); 407 arch_spin_lock(&wakeup_lock); 408 409 /* We could race with grabbing wakeup_lock */ 410 if (unlikely(!tracer_enabled || next != wakeup_task)) 411 goto out_unlock; 412 413 /* The task we are waiting for is waking up */ 414 data = per_cpu_ptr(wakeup_trace->trace_buffer.data, wakeup_cpu); 415 416 __trace_function(wakeup_trace, CALLER_ADDR0, CALLER_ADDR1, flags, pc); 417 tracing_sched_switch_trace(wakeup_trace, prev, next, flags, pc); 418 419 T0 = data->preempt_timestamp; 420 T1 = ftrace_now(cpu); 421 delta = T1-T0; 422 423 if (!report_latency(delta)) 424 goto out_unlock; 425 426 if (likely(!is_tracing_stopped())) { 427 tracing_max_latency = delta; 428 update_max_tr(wakeup_trace, wakeup_task, wakeup_cpu); 429 } 430 431 out_unlock: 432 __wakeup_reset(wakeup_trace); 433 arch_spin_unlock(&wakeup_lock); 434 local_irq_restore(flags); 435 out: 436 atomic_dec(&per_cpu_ptr(wakeup_trace->trace_buffer.data, cpu)->disabled); 437 } 438 439 static void __wakeup_reset(struct trace_array *tr) 440 { 441 wakeup_cpu = -1; 442 wakeup_prio = -1; 443 tracing_dl = 0; 444 445 if (wakeup_task) 446 put_task_struct(wakeup_task); 447 448 wakeup_task = NULL; 449 } 450 451 static void wakeup_reset(struct trace_array *tr) 452 { 453 unsigned long flags; 454 455 tracing_reset_online_cpus(&tr->trace_buffer); 456 457 local_irq_save(flags); 458 arch_spin_lock(&wakeup_lock); 459 __wakeup_reset(tr); 460 arch_spin_unlock(&wakeup_lock); 461 local_irq_restore(flags); 462 } 463 464 static void 465 probe_wakeup(void *ignore, struct task_struct *p, int success) 466 { 467 struct trace_array_cpu *data; 468 int cpu = smp_processor_id(); 469 unsigned long flags; 470 long disabled; 471 int pc; 472 473 if (likely(!tracer_enabled)) 474 return; 475 476 tracing_record_cmdline(p); 477 tracing_record_cmdline(current); 478 479 /* 480 * Semantic is like this: 481 * - wakeup tracer handles all tasks in the system, independently 482 * from their scheduling class; 483 * - wakeup_rt tracer handles tasks belonging to sched_dl and 484 * sched_rt class; 485 * - wakeup_dl handles tasks belonging to sched_dl class only. 486 */ 487 if (tracing_dl || (wakeup_dl && !dl_task(p)) || 488 (wakeup_rt && !dl_task(p) && !rt_task(p)) || 489 (!dl_task(p) && (p->prio >= wakeup_prio || p->prio >= current->prio))) 490 return; 491 492 pc = preempt_count(); 493 disabled = atomic_inc_return(&per_cpu_ptr(wakeup_trace->trace_buffer.data, cpu)->disabled); 494 if (unlikely(disabled != 1)) 495 goto out; 496 497 /* interrupts should be off from try_to_wake_up */ 498 arch_spin_lock(&wakeup_lock); 499 500 /* check for races. */ 501 if (!tracer_enabled || tracing_dl || 502 (!dl_task(p) && p->prio >= wakeup_prio)) 503 goto out_locked; 504 505 /* reset the trace */ 506 __wakeup_reset(wakeup_trace); 507 508 wakeup_cpu = task_cpu(p); 509 wakeup_current_cpu = wakeup_cpu; 510 wakeup_prio = p->prio; 511 512 /* 513 * Once you start tracing a -deadline task, don't bother tracing 514 * another task until the first one wakes up. 515 */ 516 if (dl_task(p)) 517 tracing_dl = 1; 518 else 519 tracing_dl = 0; 520 521 wakeup_task = p; 522 get_task_struct(wakeup_task); 523 524 local_save_flags(flags); 525 526 data = per_cpu_ptr(wakeup_trace->trace_buffer.data, wakeup_cpu); 527 data->preempt_timestamp = ftrace_now(cpu); 528 tracing_sched_wakeup_trace(wakeup_trace, p, current, flags, pc); 529 530 /* 531 * We must be careful in using CALLER_ADDR2. But since wake_up 532 * is not called by an assembly function (where as schedule is) 533 * it should be safe to use it here. 534 */ 535 __trace_function(wakeup_trace, CALLER_ADDR1, CALLER_ADDR2, flags, pc); 536 537 out_locked: 538 arch_spin_unlock(&wakeup_lock); 539 out: 540 atomic_dec(&per_cpu_ptr(wakeup_trace->trace_buffer.data, cpu)->disabled); 541 } 542 543 static void start_wakeup_tracer(struct trace_array *tr) 544 { 545 int ret; 546 547 ret = register_trace_sched_wakeup(probe_wakeup, NULL); 548 if (ret) { 549 pr_info("wakeup trace: Couldn't activate tracepoint" 550 " probe to kernel_sched_wakeup\n"); 551 return; 552 } 553 554 ret = register_trace_sched_wakeup_new(probe_wakeup, NULL); 555 if (ret) { 556 pr_info("wakeup trace: Couldn't activate tracepoint" 557 " probe to kernel_sched_wakeup_new\n"); 558 goto fail_deprobe; 559 } 560 561 ret = register_trace_sched_switch(probe_wakeup_sched_switch, NULL); 562 if (ret) { 563 pr_info("sched trace: Couldn't activate tracepoint" 564 " probe to kernel_sched_switch\n"); 565 goto fail_deprobe_wake_new; 566 } 567 568 ret = register_trace_sched_migrate_task(probe_wakeup_migrate_task, NULL); 569 if (ret) { 570 pr_info("wakeup trace: Couldn't activate tracepoint" 571 " probe to kernel_sched_migrate_task\n"); 572 return; 573 } 574 575 wakeup_reset(tr); 576 577 /* 578 * Don't let the tracer_enabled = 1 show up before 579 * the wakeup_task is reset. This may be overkill since 580 * wakeup_reset does a spin_unlock after setting the 581 * wakeup_task to NULL, but I want to be safe. 582 * This is a slow path anyway. 583 */ 584 smp_wmb(); 585 586 if (start_func_tracer(is_graph())) 587 printk(KERN_ERR "failed to start wakeup tracer\n"); 588 589 return; 590 fail_deprobe_wake_new: 591 unregister_trace_sched_wakeup_new(probe_wakeup, NULL); 592 fail_deprobe: 593 unregister_trace_sched_wakeup(probe_wakeup, NULL); 594 } 595 596 static void stop_wakeup_tracer(struct trace_array *tr) 597 { 598 tracer_enabled = 0; 599 stop_func_tracer(is_graph()); 600 unregister_trace_sched_switch(probe_wakeup_sched_switch, NULL); 601 unregister_trace_sched_wakeup_new(probe_wakeup, NULL); 602 unregister_trace_sched_wakeup(probe_wakeup, NULL); 603 unregister_trace_sched_migrate_task(probe_wakeup_migrate_task, NULL); 604 } 605 606 static int __wakeup_tracer_init(struct trace_array *tr) 607 { 608 save_flags = trace_flags; 609 610 /* non overwrite screws up the latency tracers */ 611 set_tracer_flag(tr, TRACE_ITER_OVERWRITE, 1); 612 set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, 1); 613 614 tracing_max_latency = 0; 615 wakeup_trace = tr; 616 start_wakeup_tracer(tr); 617 return 0; 618 } 619 620 static int wakeup_tracer_init(struct trace_array *tr) 621 { 622 wakeup_dl = 0; 623 wakeup_rt = 0; 624 return __wakeup_tracer_init(tr); 625 } 626 627 static int wakeup_rt_tracer_init(struct trace_array *tr) 628 { 629 wakeup_dl = 0; 630 wakeup_rt = 1; 631 return __wakeup_tracer_init(tr); 632 } 633 634 static int wakeup_dl_tracer_init(struct trace_array *tr) 635 { 636 wakeup_dl = 1; 637 wakeup_rt = 0; 638 return __wakeup_tracer_init(tr); 639 } 640 641 static void wakeup_tracer_reset(struct trace_array *tr) 642 { 643 int lat_flag = save_flags & TRACE_ITER_LATENCY_FMT; 644 int overwrite_flag = save_flags & TRACE_ITER_OVERWRITE; 645 646 stop_wakeup_tracer(tr); 647 /* make sure we put back any tasks we are tracing */ 648 wakeup_reset(tr); 649 650 set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, lat_flag); 651 set_tracer_flag(tr, TRACE_ITER_OVERWRITE, overwrite_flag); 652 } 653 654 static void wakeup_tracer_start(struct trace_array *tr) 655 { 656 wakeup_reset(tr); 657 tracer_enabled = 1; 658 } 659 660 static void wakeup_tracer_stop(struct trace_array *tr) 661 { 662 tracer_enabled = 0; 663 } 664 665 static struct tracer wakeup_tracer __read_mostly = 666 { 667 .name = "wakeup", 668 .init = wakeup_tracer_init, 669 .reset = wakeup_tracer_reset, 670 .start = wakeup_tracer_start, 671 .stop = wakeup_tracer_stop, 672 .print_max = true, 673 .print_header = wakeup_print_header, 674 .print_line = wakeup_print_line, 675 .flags = &tracer_flags, 676 .set_flag = wakeup_set_flag, 677 .flag_changed = wakeup_flag_changed, 678 #ifdef CONFIG_FTRACE_SELFTEST 679 .selftest = trace_selftest_startup_wakeup, 680 #endif 681 .open = wakeup_trace_open, 682 .close = wakeup_trace_close, 683 .use_max_tr = true, 684 }; 685 686 static struct tracer wakeup_rt_tracer __read_mostly = 687 { 688 .name = "wakeup_rt", 689 .init = wakeup_rt_tracer_init, 690 .reset = wakeup_tracer_reset, 691 .start = wakeup_tracer_start, 692 .stop = wakeup_tracer_stop, 693 .wait_pipe = poll_wait_pipe, 694 .print_max = true, 695 .print_header = wakeup_print_header, 696 .print_line = wakeup_print_line, 697 .flags = &tracer_flags, 698 .set_flag = wakeup_set_flag, 699 .flag_changed = wakeup_flag_changed, 700 #ifdef CONFIG_FTRACE_SELFTEST 701 .selftest = trace_selftest_startup_wakeup, 702 #endif 703 .open = wakeup_trace_open, 704 .close = wakeup_trace_close, 705 .use_max_tr = true, 706 }; 707 708 static struct tracer wakeup_dl_tracer __read_mostly = 709 { 710 .name = "wakeup_dl", 711 .init = wakeup_dl_tracer_init, 712 .reset = wakeup_tracer_reset, 713 .start = wakeup_tracer_start, 714 .stop = wakeup_tracer_stop, 715 .wait_pipe = poll_wait_pipe, 716 .print_max = true, 717 .print_header = wakeup_print_header, 718 .print_line = wakeup_print_line, 719 .flags = &tracer_flags, 720 .set_flag = wakeup_set_flag, 721 .flag_changed = wakeup_flag_changed, 722 #ifdef CONFIG_FTRACE_SELFTEST 723 .selftest = trace_selftest_startup_wakeup, 724 #endif 725 .open = wakeup_trace_open, 726 .close = wakeup_trace_close, 727 .use_max_tr = true, 728 }; 729 730 __init static int init_wakeup_tracer(void) 731 { 732 int ret; 733 734 ret = register_tracer(&wakeup_tracer); 735 if (ret) 736 return ret; 737 738 ret = register_tracer(&wakeup_rt_tracer); 739 if (ret) 740 return ret; 741 742 ret = register_tracer(&wakeup_dl_tracer); 743 if (ret) 744 return ret; 745 746 return 0; 747 } 748 core_initcall(init_wakeup_tracer); 749