1 /* 2 * 3 * Function graph tracer. 4 * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com> 5 * Mostly borrowed from function tracer which 6 * is Copyright (c) Steven Rostedt <srostedt@redhat.com> 7 * 8 */ 9 #include <linux/debugfs.h> 10 #include <linux/uaccess.h> 11 #include <linux/ftrace.h> 12 #include <linux/fs.h> 13 14 #include "trace.h" 15 #include "trace_output.h" 16 17 struct fgraph_data { 18 pid_t last_pid; 19 int depth; 20 }; 21 22 #define TRACE_GRAPH_INDENT 2 23 24 /* Flag options */ 25 #define TRACE_GRAPH_PRINT_OVERRUN 0x1 26 #define TRACE_GRAPH_PRINT_CPU 0x2 27 #define TRACE_GRAPH_PRINT_OVERHEAD 0x4 28 #define TRACE_GRAPH_PRINT_PROC 0x8 29 #define TRACE_GRAPH_PRINT_DURATION 0x10 30 #define TRACE_GRAPH_PRINT_ABS_TIME 0X20 31 32 static struct tracer_opt trace_opts[] = { 33 /* Display overruns? (for self-debug purpose) */ 34 { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) }, 35 /* Display CPU ? */ 36 { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) }, 37 /* Display Overhead ? */ 38 { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) }, 39 /* Display proc name/pid */ 40 { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) }, 41 /* Display duration of execution */ 42 { TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) }, 43 /* Display absolute time of an entry */ 44 { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) }, 45 { } /* Empty entry */ 46 }; 47 48 static struct tracer_flags tracer_flags = { 49 /* Don't display overruns and proc by default */ 50 .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD | 51 TRACE_GRAPH_PRINT_DURATION, 52 .opts = trace_opts 53 }; 54 55 static struct trace_array *graph_array; 56 57 58 /* Add a function return address to the trace stack on thread info.*/ 59 int 60 ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth, 61 unsigned long frame_pointer) 62 { 63 unsigned long long calltime; 64 int index; 65 66 if (!current->ret_stack) 67 return -EBUSY; 68 69 /* 70 * We must make sure the ret_stack is tested before we read 71 * anything else. 72 */ 73 smp_rmb(); 74 75 /* The return trace stack is full */ 76 if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) { 77 atomic_inc(¤t->trace_overrun); 78 return -EBUSY; 79 } 80 81 calltime = trace_clock_local(); 82 83 index = ++current->curr_ret_stack; 84 barrier(); 85 current->ret_stack[index].ret = ret; 86 current->ret_stack[index].func = func; 87 current->ret_stack[index].calltime = calltime; 88 current->ret_stack[index].subtime = 0; 89 current->ret_stack[index].fp = frame_pointer; 90 *depth = index; 91 92 return 0; 93 } 94 95 /* Retrieve a function return address to the trace stack on thread info.*/ 96 static void 97 ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret, 98 unsigned long frame_pointer) 99 { 100 int index; 101 102 index = current->curr_ret_stack; 103 104 if (unlikely(index < 0)) { 105 ftrace_graph_stop(); 106 WARN_ON(1); 107 /* Might as well panic, otherwise we have no where to go */ 108 *ret = (unsigned long)panic; 109 return; 110 } 111 112 #ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST 113 /* 114 * The arch may choose to record the frame pointer used 115 * and check it here to make sure that it is what we expect it 116 * to be. If gcc does not set the place holder of the return 117 * address in the frame pointer, and does a copy instead, then 118 * the function graph trace will fail. This test detects this 119 * case. 120 * 121 * Currently, x86_32 with optimize for size (-Os) makes the latest 122 * gcc do the above. 123 */ 124 if (unlikely(current->ret_stack[index].fp != frame_pointer)) { 125 ftrace_graph_stop(); 126 WARN(1, "Bad frame pointer: expected %lx, received %lx\n" 127 " from func %ps return to %lx\n", 128 current->ret_stack[index].fp, 129 frame_pointer, 130 (void *)current->ret_stack[index].func, 131 current->ret_stack[index].ret); 132 *ret = (unsigned long)panic; 133 return; 134 } 135 #endif 136 137 *ret = current->ret_stack[index].ret; 138 trace->func = current->ret_stack[index].func; 139 trace->calltime = current->ret_stack[index].calltime; 140 trace->overrun = atomic_read(¤t->trace_overrun); 141 trace->depth = index; 142 } 143 144 /* 145 * Send the trace to the ring-buffer. 146 * @return the original return address. 147 */ 148 unsigned long ftrace_return_to_handler(unsigned long frame_pointer) 149 { 150 struct ftrace_graph_ret trace; 151 unsigned long ret; 152 153 ftrace_pop_return_trace(&trace, &ret, frame_pointer); 154 trace.rettime = trace_clock_local(); 155 ftrace_graph_return(&trace); 156 barrier(); 157 current->curr_ret_stack--; 158 159 if (unlikely(!ret)) { 160 ftrace_graph_stop(); 161 WARN_ON(1); 162 /* Might as well panic. What else to do? */ 163 ret = (unsigned long)panic; 164 } 165 166 return ret; 167 } 168 169 static int __trace_graph_entry(struct trace_array *tr, 170 struct ftrace_graph_ent *trace, 171 unsigned long flags, 172 int pc) 173 { 174 struct ftrace_event_call *call = &event_funcgraph_entry; 175 struct ring_buffer_event *event; 176 struct ring_buffer *buffer = tr->buffer; 177 struct ftrace_graph_ent_entry *entry; 178 179 if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled)))) 180 return 0; 181 182 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, 183 sizeof(*entry), flags, pc); 184 if (!event) 185 return 0; 186 entry = ring_buffer_event_data(event); 187 entry->graph_ent = *trace; 188 if (!filter_current_check_discard(buffer, call, entry, event)) 189 ring_buffer_unlock_commit(buffer, event); 190 191 return 1; 192 } 193 194 int trace_graph_entry(struct ftrace_graph_ent *trace) 195 { 196 struct trace_array *tr = graph_array; 197 struct trace_array_cpu *data; 198 unsigned long flags; 199 long disabled; 200 int ret; 201 int cpu; 202 int pc; 203 204 if (unlikely(!tr)) 205 return 0; 206 207 if (!ftrace_trace_task(current)) 208 return 0; 209 210 if (!ftrace_graph_addr(trace->func)) 211 return 0; 212 213 local_irq_save(flags); 214 cpu = raw_smp_processor_id(); 215 data = tr->data[cpu]; 216 disabled = atomic_inc_return(&data->disabled); 217 if (likely(disabled == 1)) { 218 pc = preempt_count(); 219 ret = __trace_graph_entry(tr, trace, flags, pc); 220 } else { 221 ret = 0; 222 } 223 /* Only do the atomic if it is not already set */ 224 if (!test_tsk_trace_graph(current)) 225 set_tsk_trace_graph(current); 226 227 atomic_dec(&data->disabled); 228 local_irq_restore(flags); 229 230 return ret; 231 } 232 233 static void __trace_graph_return(struct trace_array *tr, 234 struct ftrace_graph_ret *trace, 235 unsigned long flags, 236 int pc) 237 { 238 struct ftrace_event_call *call = &event_funcgraph_exit; 239 struct ring_buffer_event *event; 240 struct ring_buffer *buffer = tr->buffer; 241 struct ftrace_graph_ret_entry *entry; 242 243 if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled)))) 244 return; 245 246 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET, 247 sizeof(*entry), flags, pc); 248 if (!event) 249 return; 250 entry = ring_buffer_event_data(event); 251 entry->ret = *trace; 252 if (!filter_current_check_discard(buffer, call, entry, event)) 253 ring_buffer_unlock_commit(buffer, event); 254 } 255 256 void trace_graph_return(struct ftrace_graph_ret *trace) 257 { 258 struct trace_array *tr = graph_array; 259 struct trace_array_cpu *data; 260 unsigned long flags; 261 long disabled; 262 int cpu; 263 int pc; 264 265 local_irq_save(flags); 266 cpu = raw_smp_processor_id(); 267 data = tr->data[cpu]; 268 disabled = atomic_inc_return(&data->disabled); 269 if (likely(disabled == 1)) { 270 pc = preempt_count(); 271 __trace_graph_return(tr, trace, flags, pc); 272 } 273 if (!trace->depth) 274 clear_tsk_trace_graph(current); 275 atomic_dec(&data->disabled); 276 local_irq_restore(flags); 277 } 278 279 static int graph_trace_init(struct trace_array *tr) 280 { 281 int ret; 282 283 graph_array = tr; 284 ret = register_ftrace_graph(&trace_graph_return, 285 &trace_graph_entry); 286 if (ret) 287 return ret; 288 tracing_start_cmdline_record(); 289 290 return 0; 291 } 292 293 void set_graph_array(struct trace_array *tr) 294 { 295 graph_array = tr; 296 } 297 298 static void graph_trace_reset(struct trace_array *tr) 299 { 300 tracing_stop_cmdline_record(); 301 unregister_ftrace_graph(); 302 } 303 304 static int max_bytes_for_cpu; 305 306 static enum print_line_t 307 print_graph_cpu(struct trace_seq *s, int cpu) 308 { 309 int ret; 310 311 /* 312 * Start with a space character - to make it stand out 313 * to the right a bit when trace output is pasted into 314 * email: 315 */ 316 ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu); 317 if (!ret) 318 return TRACE_TYPE_PARTIAL_LINE; 319 320 return TRACE_TYPE_HANDLED; 321 } 322 323 #define TRACE_GRAPH_PROCINFO_LENGTH 14 324 325 static enum print_line_t 326 print_graph_proc(struct trace_seq *s, pid_t pid) 327 { 328 char comm[TASK_COMM_LEN]; 329 /* sign + log10(MAX_INT) + '\0' */ 330 char pid_str[11]; 331 int spaces = 0; 332 int ret; 333 int len; 334 int i; 335 336 trace_find_cmdline(pid, comm); 337 comm[7] = '\0'; 338 sprintf(pid_str, "%d", pid); 339 340 /* 1 stands for the "-" character */ 341 len = strlen(comm) + strlen(pid_str) + 1; 342 343 if (len < TRACE_GRAPH_PROCINFO_LENGTH) 344 spaces = TRACE_GRAPH_PROCINFO_LENGTH - len; 345 346 /* First spaces to align center */ 347 for (i = 0; i < spaces / 2; i++) { 348 ret = trace_seq_printf(s, " "); 349 if (!ret) 350 return TRACE_TYPE_PARTIAL_LINE; 351 } 352 353 ret = trace_seq_printf(s, "%s-%s", comm, pid_str); 354 if (!ret) 355 return TRACE_TYPE_PARTIAL_LINE; 356 357 /* Last spaces to align center */ 358 for (i = 0; i < spaces - (spaces / 2); i++) { 359 ret = trace_seq_printf(s, " "); 360 if (!ret) 361 return TRACE_TYPE_PARTIAL_LINE; 362 } 363 return TRACE_TYPE_HANDLED; 364 } 365 366 367 static enum print_line_t 368 print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry) 369 { 370 if (!trace_seq_putc(s, ' ')) 371 return 0; 372 373 return trace_print_lat_fmt(s, entry); 374 } 375 376 /* If the pid changed since the last trace, output this event */ 377 static enum print_line_t 378 verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data) 379 { 380 pid_t prev_pid; 381 pid_t *last_pid; 382 int ret; 383 384 if (!data) 385 return TRACE_TYPE_HANDLED; 386 387 last_pid = &(per_cpu_ptr(data, cpu)->last_pid); 388 389 if (*last_pid == pid) 390 return TRACE_TYPE_HANDLED; 391 392 prev_pid = *last_pid; 393 *last_pid = pid; 394 395 if (prev_pid == -1) 396 return TRACE_TYPE_HANDLED; 397 /* 398 * Context-switch trace line: 399 400 ------------------------------------------ 401 | 1) migration/0--1 => sshd-1755 402 ------------------------------------------ 403 404 */ 405 ret = trace_seq_printf(s, 406 " ------------------------------------------\n"); 407 if (!ret) 408 return TRACE_TYPE_PARTIAL_LINE; 409 410 ret = print_graph_cpu(s, cpu); 411 if (ret == TRACE_TYPE_PARTIAL_LINE) 412 return TRACE_TYPE_PARTIAL_LINE; 413 414 ret = print_graph_proc(s, prev_pid); 415 if (ret == TRACE_TYPE_PARTIAL_LINE) 416 return TRACE_TYPE_PARTIAL_LINE; 417 418 ret = trace_seq_printf(s, " => "); 419 if (!ret) 420 return TRACE_TYPE_PARTIAL_LINE; 421 422 ret = print_graph_proc(s, pid); 423 if (ret == TRACE_TYPE_PARTIAL_LINE) 424 return TRACE_TYPE_PARTIAL_LINE; 425 426 ret = trace_seq_printf(s, 427 "\n ------------------------------------------\n\n"); 428 if (!ret) 429 return TRACE_TYPE_PARTIAL_LINE; 430 431 return TRACE_TYPE_HANDLED; 432 } 433 434 static struct ftrace_graph_ret_entry * 435 get_return_for_leaf(struct trace_iterator *iter, 436 struct ftrace_graph_ent_entry *curr) 437 { 438 struct ring_buffer_iter *ring_iter; 439 struct ring_buffer_event *event; 440 struct ftrace_graph_ret_entry *next; 441 442 ring_iter = iter->buffer_iter[iter->cpu]; 443 444 /* First peek to compare current entry and the next one */ 445 if (ring_iter) 446 event = ring_buffer_iter_peek(ring_iter, NULL); 447 else { 448 /* We need to consume the current entry to see the next one */ 449 ring_buffer_consume(iter->tr->buffer, iter->cpu, NULL); 450 event = ring_buffer_peek(iter->tr->buffer, iter->cpu, 451 NULL); 452 } 453 454 if (!event) 455 return NULL; 456 457 next = ring_buffer_event_data(event); 458 459 if (next->ent.type != TRACE_GRAPH_RET) 460 return NULL; 461 462 if (curr->ent.pid != next->ent.pid || 463 curr->graph_ent.func != next->ret.func) 464 return NULL; 465 466 /* this is a leaf, now advance the iterator */ 467 if (ring_iter) 468 ring_buffer_read(ring_iter, NULL); 469 470 return next; 471 } 472 473 /* Signal a overhead of time execution to the output */ 474 static int 475 print_graph_overhead(unsigned long long duration, struct trace_seq *s) 476 { 477 /* If duration disappear, we don't need anything */ 478 if (!(tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)) 479 return 1; 480 481 /* Non nested entry or return */ 482 if (duration == -1) 483 return trace_seq_printf(s, " "); 484 485 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) { 486 /* Duration exceeded 100 msecs */ 487 if (duration > 100000ULL) 488 return trace_seq_printf(s, "! "); 489 490 /* Duration exceeded 10 msecs */ 491 if (duration > 10000ULL) 492 return trace_seq_printf(s, "+ "); 493 } 494 495 return trace_seq_printf(s, " "); 496 } 497 498 static int print_graph_abs_time(u64 t, struct trace_seq *s) 499 { 500 unsigned long usecs_rem; 501 502 usecs_rem = do_div(t, NSEC_PER_SEC); 503 usecs_rem /= 1000; 504 505 return trace_seq_printf(s, "%5lu.%06lu | ", 506 (unsigned long)t, usecs_rem); 507 } 508 509 static enum print_line_t 510 print_graph_irq(struct trace_iterator *iter, unsigned long addr, 511 enum trace_type type, int cpu, pid_t pid) 512 { 513 int ret; 514 struct trace_seq *s = &iter->seq; 515 516 if (addr < (unsigned long)__irqentry_text_start || 517 addr >= (unsigned long)__irqentry_text_end) 518 return TRACE_TYPE_UNHANDLED; 519 520 /* Absolute time */ 521 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) { 522 ret = print_graph_abs_time(iter->ts, s); 523 if (!ret) 524 return TRACE_TYPE_PARTIAL_LINE; 525 } 526 527 /* Cpu */ 528 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) { 529 ret = print_graph_cpu(s, cpu); 530 if (ret == TRACE_TYPE_PARTIAL_LINE) 531 return TRACE_TYPE_PARTIAL_LINE; 532 } 533 534 /* Proc */ 535 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) { 536 ret = print_graph_proc(s, pid); 537 if (ret == TRACE_TYPE_PARTIAL_LINE) 538 return TRACE_TYPE_PARTIAL_LINE; 539 ret = trace_seq_printf(s, " | "); 540 if (!ret) 541 return TRACE_TYPE_PARTIAL_LINE; 542 } 543 544 /* No overhead */ 545 ret = print_graph_overhead(-1, s); 546 if (!ret) 547 return TRACE_TYPE_PARTIAL_LINE; 548 549 if (type == TRACE_GRAPH_ENT) 550 ret = trace_seq_printf(s, "==========>"); 551 else 552 ret = trace_seq_printf(s, "<=========="); 553 554 if (!ret) 555 return TRACE_TYPE_PARTIAL_LINE; 556 557 /* Don't close the duration column if haven't one */ 558 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) 559 trace_seq_printf(s, " |"); 560 ret = trace_seq_printf(s, "\n"); 561 562 if (!ret) 563 return TRACE_TYPE_PARTIAL_LINE; 564 return TRACE_TYPE_HANDLED; 565 } 566 567 enum print_line_t 568 trace_print_graph_duration(unsigned long long duration, struct trace_seq *s) 569 { 570 unsigned long nsecs_rem = do_div(duration, 1000); 571 /* log10(ULONG_MAX) + '\0' */ 572 char msecs_str[21]; 573 char nsecs_str[5]; 574 int ret, len; 575 int i; 576 577 sprintf(msecs_str, "%lu", (unsigned long) duration); 578 579 /* Print msecs */ 580 ret = trace_seq_printf(s, "%s", msecs_str); 581 if (!ret) 582 return TRACE_TYPE_PARTIAL_LINE; 583 584 len = strlen(msecs_str); 585 586 /* Print nsecs (we don't want to exceed 7 numbers) */ 587 if (len < 7) { 588 snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem); 589 ret = trace_seq_printf(s, ".%s", nsecs_str); 590 if (!ret) 591 return TRACE_TYPE_PARTIAL_LINE; 592 len += strlen(nsecs_str); 593 } 594 595 ret = trace_seq_printf(s, " us "); 596 if (!ret) 597 return TRACE_TYPE_PARTIAL_LINE; 598 599 /* Print remaining spaces to fit the row's width */ 600 for (i = len; i < 7; i++) { 601 ret = trace_seq_printf(s, " "); 602 if (!ret) 603 return TRACE_TYPE_PARTIAL_LINE; 604 } 605 return TRACE_TYPE_HANDLED; 606 } 607 608 static enum print_line_t 609 print_graph_duration(unsigned long long duration, struct trace_seq *s) 610 { 611 int ret; 612 613 ret = trace_print_graph_duration(duration, s); 614 if (ret != TRACE_TYPE_HANDLED) 615 return ret; 616 617 ret = trace_seq_printf(s, "| "); 618 if (!ret) 619 return TRACE_TYPE_PARTIAL_LINE; 620 621 return TRACE_TYPE_HANDLED; 622 } 623 624 /* Case of a leaf function on its call entry */ 625 static enum print_line_t 626 print_graph_entry_leaf(struct trace_iterator *iter, 627 struct ftrace_graph_ent_entry *entry, 628 struct ftrace_graph_ret_entry *ret_entry, struct trace_seq *s) 629 { 630 struct fgraph_data *data = iter->private; 631 struct ftrace_graph_ret *graph_ret; 632 struct ftrace_graph_ent *call; 633 unsigned long long duration; 634 int ret; 635 int i; 636 637 graph_ret = &ret_entry->ret; 638 call = &entry->graph_ent; 639 duration = graph_ret->rettime - graph_ret->calltime; 640 641 if (data) { 642 int cpu = iter->cpu; 643 int *depth = &(per_cpu_ptr(data, cpu)->depth); 644 645 /* 646 * Comments display at + 1 to depth. Since 647 * this is a leaf function, keep the comments 648 * equal to this depth. 649 */ 650 *depth = call->depth - 1; 651 } 652 653 /* Overhead */ 654 ret = print_graph_overhead(duration, s); 655 if (!ret) 656 return TRACE_TYPE_PARTIAL_LINE; 657 658 /* Duration */ 659 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) { 660 ret = print_graph_duration(duration, s); 661 if (ret == TRACE_TYPE_PARTIAL_LINE) 662 return TRACE_TYPE_PARTIAL_LINE; 663 } 664 665 /* Function */ 666 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) { 667 ret = trace_seq_printf(s, " "); 668 if (!ret) 669 return TRACE_TYPE_PARTIAL_LINE; 670 } 671 672 ret = trace_seq_printf(s, "%ps();\n", (void *)call->func); 673 if (!ret) 674 return TRACE_TYPE_PARTIAL_LINE; 675 676 return TRACE_TYPE_HANDLED; 677 } 678 679 static enum print_line_t 680 print_graph_entry_nested(struct trace_iterator *iter, 681 struct ftrace_graph_ent_entry *entry, 682 struct trace_seq *s, int cpu) 683 { 684 struct ftrace_graph_ent *call = &entry->graph_ent; 685 struct fgraph_data *data = iter->private; 686 int ret; 687 int i; 688 689 if (data) { 690 int cpu = iter->cpu; 691 int *depth = &(per_cpu_ptr(data, cpu)->depth); 692 693 *depth = call->depth; 694 } 695 696 /* No overhead */ 697 ret = print_graph_overhead(-1, s); 698 if (!ret) 699 return TRACE_TYPE_PARTIAL_LINE; 700 701 /* No time */ 702 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) { 703 ret = trace_seq_printf(s, " | "); 704 if (!ret) 705 return TRACE_TYPE_PARTIAL_LINE; 706 } 707 708 /* Function */ 709 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) { 710 ret = trace_seq_printf(s, " "); 711 if (!ret) 712 return TRACE_TYPE_PARTIAL_LINE; 713 } 714 715 ret = trace_seq_printf(s, "%ps() {\n", (void *)call->func); 716 if (!ret) 717 return TRACE_TYPE_PARTIAL_LINE; 718 719 /* 720 * we already consumed the current entry to check the next one 721 * and see if this is a leaf. 722 */ 723 return TRACE_TYPE_NO_CONSUME; 724 } 725 726 static enum print_line_t 727 print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s, 728 int type, unsigned long addr) 729 { 730 struct fgraph_data *data = iter->private; 731 struct trace_entry *ent = iter->ent; 732 int cpu = iter->cpu; 733 int ret; 734 735 /* Pid */ 736 if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE) 737 return TRACE_TYPE_PARTIAL_LINE; 738 739 if (type) { 740 /* Interrupt */ 741 ret = print_graph_irq(iter, addr, type, cpu, ent->pid); 742 if (ret == TRACE_TYPE_PARTIAL_LINE) 743 return TRACE_TYPE_PARTIAL_LINE; 744 } 745 746 /* Absolute time */ 747 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) { 748 ret = print_graph_abs_time(iter->ts, s); 749 if (!ret) 750 return TRACE_TYPE_PARTIAL_LINE; 751 } 752 753 /* Cpu */ 754 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) { 755 ret = print_graph_cpu(s, cpu); 756 if (ret == TRACE_TYPE_PARTIAL_LINE) 757 return TRACE_TYPE_PARTIAL_LINE; 758 } 759 760 /* Proc */ 761 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) { 762 ret = print_graph_proc(s, ent->pid); 763 if (ret == TRACE_TYPE_PARTIAL_LINE) 764 return TRACE_TYPE_PARTIAL_LINE; 765 766 ret = trace_seq_printf(s, " | "); 767 if (!ret) 768 return TRACE_TYPE_PARTIAL_LINE; 769 } 770 771 /* Latency format */ 772 if (trace_flags & TRACE_ITER_LATENCY_FMT) { 773 ret = print_graph_lat_fmt(s, ent); 774 if (ret == TRACE_TYPE_PARTIAL_LINE) 775 return TRACE_TYPE_PARTIAL_LINE; 776 } 777 778 return 0; 779 } 780 781 static enum print_line_t 782 print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s, 783 struct trace_iterator *iter) 784 { 785 int cpu = iter->cpu; 786 struct ftrace_graph_ent *call = &field->graph_ent; 787 struct ftrace_graph_ret_entry *leaf_ret; 788 789 if (print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func)) 790 return TRACE_TYPE_PARTIAL_LINE; 791 792 leaf_ret = get_return_for_leaf(iter, field); 793 if (leaf_ret) 794 return print_graph_entry_leaf(iter, field, leaf_ret, s); 795 else 796 return print_graph_entry_nested(iter, field, s, cpu); 797 798 } 799 800 static enum print_line_t 801 print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s, 802 struct trace_entry *ent, struct trace_iterator *iter) 803 { 804 unsigned long long duration = trace->rettime - trace->calltime; 805 struct fgraph_data *data = iter->private; 806 pid_t pid = ent->pid; 807 int cpu = iter->cpu; 808 int ret; 809 int i; 810 811 if (data) { 812 int cpu = iter->cpu; 813 int *depth = &(per_cpu_ptr(data, cpu)->depth); 814 815 /* 816 * Comments display at + 1 to depth. This is the 817 * return from a function, we now want the comments 818 * to display at the same level of the bracket. 819 */ 820 *depth = trace->depth - 1; 821 } 822 823 if (print_graph_prologue(iter, s, 0, 0)) 824 return TRACE_TYPE_PARTIAL_LINE; 825 826 /* Overhead */ 827 ret = print_graph_overhead(duration, s); 828 if (!ret) 829 return TRACE_TYPE_PARTIAL_LINE; 830 831 /* Duration */ 832 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) { 833 ret = print_graph_duration(duration, s); 834 if (ret == TRACE_TYPE_PARTIAL_LINE) 835 return TRACE_TYPE_PARTIAL_LINE; 836 } 837 838 /* Closing brace */ 839 for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) { 840 ret = trace_seq_printf(s, " "); 841 if (!ret) 842 return TRACE_TYPE_PARTIAL_LINE; 843 } 844 845 ret = trace_seq_printf(s, "}\n"); 846 if (!ret) 847 return TRACE_TYPE_PARTIAL_LINE; 848 849 /* Overrun */ 850 if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) { 851 ret = trace_seq_printf(s, " (Overruns: %lu)\n", 852 trace->overrun); 853 if (!ret) 854 return TRACE_TYPE_PARTIAL_LINE; 855 } 856 857 ret = print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, cpu, pid); 858 if (ret == TRACE_TYPE_PARTIAL_LINE) 859 return TRACE_TYPE_PARTIAL_LINE; 860 861 return TRACE_TYPE_HANDLED; 862 } 863 864 static enum print_line_t 865 print_graph_comment(struct trace_seq *s, struct trace_entry *ent, 866 struct trace_iterator *iter) 867 { 868 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK); 869 struct fgraph_data *data = iter->private; 870 struct trace_event *event; 871 int depth = 0; 872 int ret; 873 int i; 874 875 if (data) 876 depth = per_cpu_ptr(data, iter->cpu)->depth; 877 878 if (print_graph_prologue(iter, s, 0, 0)) 879 return TRACE_TYPE_PARTIAL_LINE; 880 881 /* No overhead */ 882 ret = print_graph_overhead(-1, s); 883 if (!ret) 884 return TRACE_TYPE_PARTIAL_LINE; 885 886 /* No time */ 887 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) { 888 ret = trace_seq_printf(s, " | "); 889 if (!ret) 890 return TRACE_TYPE_PARTIAL_LINE; 891 } 892 893 /* Indentation */ 894 if (depth > 0) 895 for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) { 896 ret = trace_seq_printf(s, " "); 897 if (!ret) 898 return TRACE_TYPE_PARTIAL_LINE; 899 } 900 901 /* The comment */ 902 ret = trace_seq_printf(s, "/* "); 903 if (!ret) 904 return TRACE_TYPE_PARTIAL_LINE; 905 906 switch (iter->ent->type) { 907 case TRACE_BPRINT: 908 ret = trace_print_bprintk_msg_only(iter); 909 if (ret != TRACE_TYPE_HANDLED) 910 return ret; 911 break; 912 case TRACE_PRINT: 913 ret = trace_print_printk_msg_only(iter); 914 if (ret != TRACE_TYPE_HANDLED) 915 return ret; 916 break; 917 default: 918 event = ftrace_find_event(ent->type); 919 if (!event) 920 return TRACE_TYPE_UNHANDLED; 921 922 ret = event->trace(iter, sym_flags); 923 if (ret != TRACE_TYPE_HANDLED) 924 return ret; 925 } 926 927 /* Strip ending newline */ 928 if (s->buffer[s->len - 1] == '\n') { 929 s->buffer[s->len - 1] = '\0'; 930 s->len--; 931 } 932 933 ret = trace_seq_printf(s, " */\n"); 934 if (!ret) 935 return TRACE_TYPE_PARTIAL_LINE; 936 937 return TRACE_TYPE_HANDLED; 938 } 939 940 941 enum print_line_t 942 print_graph_function(struct trace_iterator *iter) 943 { 944 struct trace_entry *entry = iter->ent; 945 struct trace_seq *s = &iter->seq; 946 947 switch (entry->type) { 948 case TRACE_GRAPH_ENT: { 949 /* 950 * print_graph_entry() may consume the current event, 951 * thus @field may become invalid, so we need to save it. 952 * sizeof(struct ftrace_graph_ent_entry) is very small, 953 * it can be safely saved at the stack. 954 */ 955 struct ftrace_graph_ent_entry *field, saved; 956 trace_assign_type(field, entry); 957 saved = *field; 958 return print_graph_entry(&saved, s, iter); 959 } 960 case TRACE_GRAPH_RET: { 961 struct ftrace_graph_ret_entry *field; 962 trace_assign_type(field, entry); 963 return print_graph_return(&field->ret, s, entry, iter); 964 } 965 default: 966 return print_graph_comment(s, entry, iter); 967 } 968 969 return TRACE_TYPE_HANDLED; 970 } 971 972 static void print_lat_header(struct seq_file *s) 973 { 974 static const char spaces[] = " " /* 16 spaces */ 975 " " /* 4 spaces */ 976 " "; /* 17 spaces */ 977 int size = 0; 978 979 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) 980 size += 16; 981 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) 982 size += 4; 983 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) 984 size += 17; 985 986 seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces); 987 seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces); 988 seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces); 989 seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces); 990 seq_printf(s, "#%.*s||| / _-=> lock-depth \n", size, spaces); 991 seq_printf(s, "#%.*s|||| / \n", size, spaces); 992 } 993 994 static void print_graph_headers(struct seq_file *s) 995 { 996 int lat = trace_flags & TRACE_ITER_LATENCY_FMT; 997 998 if (lat) 999 print_lat_header(s); 1000 1001 /* 1st line */ 1002 seq_printf(s, "#"); 1003 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) 1004 seq_printf(s, " TIME "); 1005 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) 1006 seq_printf(s, " CPU"); 1007 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) 1008 seq_printf(s, " TASK/PID "); 1009 if (lat) 1010 seq_printf(s, "|||||"); 1011 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) 1012 seq_printf(s, " DURATION "); 1013 seq_printf(s, " FUNCTION CALLS\n"); 1014 1015 /* 2nd line */ 1016 seq_printf(s, "#"); 1017 if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) 1018 seq_printf(s, " | "); 1019 if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) 1020 seq_printf(s, " | "); 1021 if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) 1022 seq_printf(s, " | | "); 1023 if (lat) 1024 seq_printf(s, "|||||"); 1025 if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) 1026 seq_printf(s, " | | "); 1027 seq_printf(s, " | | | |\n"); 1028 } 1029 1030 static void graph_trace_open(struct trace_iterator *iter) 1031 { 1032 /* pid and depth on the last trace processed */ 1033 struct fgraph_data *data = alloc_percpu(struct fgraph_data); 1034 int cpu; 1035 1036 if (!data) 1037 pr_warning("function graph tracer: not enough memory\n"); 1038 else 1039 for_each_possible_cpu(cpu) { 1040 pid_t *pid = &(per_cpu_ptr(data, cpu)->last_pid); 1041 int *depth = &(per_cpu_ptr(data, cpu)->depth); 1042 *pid = -1; 1043 *depth = 0; 1044 } 1045 1046 iter->private = data; 1047 } 1048 1049 static void graph_trace_close(struct trace_iterator *iter) 1050 { 1051 free_percpu(iter->private); 1052 } 1053 1054 static struct tracer graph_trace __read_mostly = { 1055 .name = "function_graph", 1056 .open = graph_trace_open, 1057 .close = graph_trace_close, 1058 .wait_pipe = poll_wait_pipe, 1059 .init = graph_trace_init, 1060 .reset = graph_trace_reset, 1061 .print_line = print_graph_function, 1062 .print_header = print_graph_headers, 1063 .flags = &tracer_flags, 1064 #ifdef CONFIG_FTRACE_SELFTEST 1065 .selftest = trace_selftest_startup_function_graph, 1066 #endif 1067 }; 1068 1069 static __init int init_graph_trace(void) 1070 { 1071 max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); 1072 1073 return register_tracer(&graph_trace); 1074 } 1075 1076 device_initcall(init_graph_trace); 1077