1 // SPDX-License-Identifier: GPL-2.0 2 /* 3 * 4 * Function graph tracer. 5 * Copyright (c) 2008-2009 Frederic Weisbecker <[email protected]> 6 * Mostly borrowed from function tracer which 7 * is Copyright (c) Steven Rostedt <[email protected]> 8 * 9 */ 10 #include <linux/uaccess.h> 11 #include <linux/ftrace.h> 12 #include <linux/interrupt.h> 13 #include <linux/slab.h> 14 #include <linux/fs.h> 15 16 #include "trace.h" 17 #include "trace_output.h" 18 19 /* When set, irq functions will be ignored */ 20 static int ftrace_graph_skip_irqs; 21 22 struct fgraph_cpu_data { 23 pid_t last_pid; 24 int depth; 25 int depth_irq; 26 int ignore; 27 unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH]; 28 }; 29 30 struct fgraph_data { 31 struct fgraph_cpu_data __percpu *cpu_data; 32 33 /* Place to preserve last processed entry. */ 34 union { 35 struct ftrace_graph_ent_entry ent; 36 struct fgraph_retaddr_ent_entry rent; 37 } ent; 38 struct ftrace_graph_ret_entry ret; 39 int failed; 40 int cpu; 41 }; 42 43 #define TRACE_GRAPH_INDENT 2 44 45 unsigned int fgraph_max_depth; 46 47 static struct tracer_opt trace_opts[] = { 48 /* Display overruns? (for self-debug purpose) */ 49 { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) }, 50 /* Display CPU ? */ 51 { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) }, 52 /* Display Overhead ? */ 53 { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) }, 54 /* Display proc name/pid */ 55 { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) }, 56 /* Display duration of execution */ 57 { TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) }, 58 /* Display absolute time of an entry */ 59 { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) }, 60 /* Display interrupts */ 61 { TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) }, 62 /* Display function name after trailing } */ 63 { TRACER_OPT(funcgraph-tail, TRACE_GRAPH_PRINT_TAIL) }, 64 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL 65 /* Display function return value ? */ 66 { TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) }, 67 /* Display function return value in hexadecimal format ? */ 68 { TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) }, 69 #endif 70 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 71 /* Display function return address ? */ 72 { TRACER_OPT(funcgraph-retaddr, TRACE_GRAPH_PRINT_RETADDR) }, 73 #endif 74 #ifdef CONFIG_FUNCTION_TRACE_ARGS 75 /* Display function arguments ? */ 76 { TRACER_OPT(funcgraph-args, TRACE_GRAPH_ARGS) }, 77 #endif 78 /* Include sleep time (scheduled out) between entry and return */ 79 { TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) }, 80 81 #ifdef CONFIG_FUNCTION_PROFILER 82 /* Include time within nested functions */ 83 { TRACER_OPT(graph-time, TRACE_GRAPH_GRAPH_TIME) }, 84 #endif 85 86 { } /* Empty entry */ 87 }; 88 89 static struct tracer_flags tracer_flags = { 90 /* Don't display overruns, proc, or tail by default */ 91 .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD | 92 TRACE_GRAPH_PRINT_DURATION | TRACE_GRAPH_PRINT_IRQS | 93 TRACE_GRAPH_SLEEP_TIME | TRACE_GRAPH_GRAPH_TIME, 94 .opts = trace_opts 95 }; 96 97 static bool tracer_flags_is_set(u32 flags) 98 { 99 return (tracer_flags.val & flags) == flags; 100 } 101 102 /* 103 * DURATION column is being also used to display IRQ signs, 104 * following values are used by print_graph_irq and others 105 * to fill in space into DURATION column. 106 */ 107 enum { 108 FLAGS_FILL_FULL = 1 << TRACE_GRAPH_PRINT_FILL_SHIFT, 109 FLAGS_FILL_START = 2 << TRACE_GRAPH_PRINT_FILL_SHIFT, 110 FLAGS_FILL_END = 3 << TRACE_GRAPH_PRINT_FILL_SHIFT, 111 }; 112 113 static void 114 print_graph_duration(struct trace_array *tr, unsigned long long duration, 115 struct trace_seq *s, u32 flags); 116 117 static int __graph_entry(struct trace_array *tr, struct ftrace_graph_ent *trace, 118 unsigned int trace_ctx, struct ftrace_regs *fregs) 119 { 120 struct ring_buffer_event *event; 121 struct trace_buffer *buffer = tr->array_buffer.buffer; 122 struct ftrace_graph_ent_entry *entry; 123 int size; 124 125 /* If fregs is defined, add FTRACE_REGS_MAX_ARGS long size words */ 126 size = sizeof(*entry) + (FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long)); 127 128 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, size, trace_ctx); 129 if (!event) 130 return 0; 131 132 entry = ring_buffer_event_data(event); 133 entry->graph_ent = *trace; 134 135 #ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API 136 if (fregs) { 137 for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++) 138 entry->args[i] = ftrace_regs_get_argument(fregs, i); 139 } 140 #endif 141 142 trace_buffer_unlock_commit_nostack(buffer, event); 143 144 return 1; 145 } 146 147 int __trace_graph_entry(struct trace_array *tr, 148 struct ftrace_graph_ent *trace, 149 unsigned int trace_ctx) 150 { 151 return __graph_entry(tr, trace, trace_ctx, NULL); 152 } 153 154 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 155 int __trace_graph_retaddr_entry(struct trace_array *tr, 156 struct ftrace_graph_ent *trace, 157 unsigned int trace_ctx, 158 unsigned long retaddr) 159 { 160 struct ring_buffer_event *event; 161 struct trace_buffer *buffer = tr->array_buffer.buffer; 162 struct fgraph_retaddr_ent_entry *entry; 163 164 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RETADDR_ENT, 165 sizeof(*entry), trace_ctx); 166 if (!event) 167 return 0; 168 entry = ring_buffer_event_data(event); 169 entry->graph_ent.func = trace->func; 170 entry->graph_ent.depth = trace->depth; 171 entry->graph_ent.retaddr = retaddr; 172 trace_buffer_unlock_commit_nostack(buffer, event); 173 174 return 1; 175 } 176 #else 177 int __trace_graph_retaddr_entry(struct trace_array *tr, 178 struct ftrace_graph_ent *trace, 179 unsigned int trace_ctx, 180 unsigned long retaddr) 181 { 182 return 1; 183 } 184 #endif 185 186 static inline int ftrace_graph_ignore_irqs(void) 187 { 188 if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT)) 189 return 0; 190 191 return in_hardirq(); 192 } 193 194 struct fgraph_times { 195 unsigned long long calltime; 196 unsigned long long sleeptime; /* may be optional! */ 197 }; 198 199 static int graph_entry(struct ftrace_graph_ent *trace, 200 struct fgraph_ops *gops, 201 struct ftrace_regs *fregs) 202 { 203 unsigned long *task_var = fgraph_get_task_var(gops); 204 struct trace_array *tr = gops->private; 205 struct trace_array_cpu *data; 206 struct fgraph_times *ftimes; 207 unsigned int trace_ctx; 208 long disabled; 209 int ret = 0; 210 int cpu; 211 212 if (*task_var & TRACE_GRAPH_NOTRACE) 213 return 0; 214 215 /* 216 * Do not trace a function if it's filtered by set_graph_notrace. 217 * Make the index of ret stack negative to indicate that it should 218 * ignore further functions. But it needs its own ret stack entry 219 * to recover the original index in order to continue tracing after 220 * returning from the function. 221 */ 222 if (ftrace_graph_notrace_addr(trace->func)) { 223 *task_var |= TRACE_GRAPH_NOTRACE; 224 /* 225 * Need to return 1 to have the return called 226 * that will clear the NOTRACE bit. 227 */ 228 return 1; 229 } 230 231 if (!ftrace_trace_task(tr)) 232 return 0; 233 234 if (ftrace_graph_ignore_func(gops, trace)) 235 return 0; 236 237 if (ftrace_graph_ignore_irqs()) 238 return 0; 239 240 if (fgraph_sleep_time) { 241 /* Only need to record the calltime */ 242 ftimes = fgraph_reserve_data(gops->idx, sizeof(ftimes->calltime)); 243 } else { 244 ftimes = fgraph_reserve_data(gops->idx, sizeof(*ftimes)); 245 if (ftimes) 246 ftimes->sleeptime = current->ftrace_sleeptime; 247 } 248 if (!ftimes) 249 return 0; 250 251 ftimes->calltime = trace_clock_local(); 252 253 /* 254 * Stop here if tracing_threshold is set. We only write function return 255 * events to the ring buffer. 256 */ 257 if (tracing_thresh) 258 return 1; 259 260 preempt_disable_notrace(); 261 cpu = raw_smp_processor_id(); 262 data = per_cpu_ptr(tr->array_buffer.data, cpu); 263 disabled = atomic_read(&data->disabled); 264 if (likely(!disabled)) { 265 trace_ctx = tracing_gen_ctx(); 266 if (IS_ENABLED(CONFIG_FUNCTION_GRAPH_RETADDR) && 267 tracer_flags_is_set(TRACE_GRAPH_PRINT_RETADDR)) { 268 unsigned long retaddr = ftrace_graph_top_ret_addr(current); 269 ret = __trace_graph_retaddr_entry(tr, trace, trace_ctx, retaddr); 270 } else { 271 ret = __graph_entry(tr, trace, trace_ctx, fregs); 272 } 273 } 274 preempt_enable_notrace(); 275 276 return ret; 277 } 278 279 int trace_graph_entry(struct ftrace_graph_ent *trace, 280 struct fgraph_ops *gops, 281 struct ftrace_regs *fregs) 282 { 283 return graph_entry(trace, gops, NULL); 284 } 285 286 static int trace_graph_entry_args(struct ftrace_graph_ent *trace, 287 struct fgraph_ops *gops, 288 struct ftrace_regs *fregs) 289 { 290 return graph_entry(trace, gops, fregs); 291 } 292 293 static void 294 __trace_graph_function(struct trace_array *tr, 295 unsigned long ip, unsigned int trace_ctx) 296 { 297 u64 time = trace_clock_local(); 298 struct ftrace_graph_ent ent = { 299 .func = ip, 300 .depth = 0, 301 }; 302 struct ftrace_graph_ret ret = { 303 .func = ip, 304 .depth = 0, 305 }; 306 307 __trace_graph_entry(tr, &ent, trace_ctx); 308 __trace_graph_return(tr, &ret, trace_ctx, time, time); 309 } 310 311 void 312 trace_graph_function(struct trace_array *tr, 313 unsigned long ip, unsigned long parent_ip, 314 unsigned int trace_ctx) 315 { 316 __trace_graph_function(tr, ip, trace_ctx); 317 } 318 319 void __trace_graph_return(struct trace_array *tr, 320 struct ftrace_graph_ret *trace, 321 unsigned int trace_ctx, 322 u64 calltime, u64 rettime) 323 { 324 struct ring_buffer_event *event; 325 struct trace_buffer *buffer = tr->array_buffer.buffer; 326 struct ftrace_graph_ret_entry *entry; 327 328 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET, 329 sizeof(*entry), trace_ctx); 330 if (!event) 331 return; 332 entry = ring_buffer_event_data(event); 333 entry->ret = *trace; 334 entry->calltime = calltime; 335 entry->rettime = rettime; 336 trace_buffer_unlock_commit_nostack(buffer, event); 337 } 338 339 static void handle_nosleeptime(struct ftrace_graph_ret *trace, 340 struct fgraph_times *ftimes, 341 int size) 342 { 343 if (fgraph_sleep_time || size < sizeof(*ftimes)) 344 return; 345 346 ftimes->calltime += current->ftrace_sleeptime - ftimes->sleeptime; 347 } 348 349 void trace_graph_return(struct ftrace_graph_ret *trace, 350 struct fgraph_ops *gops, struct ftrace_regs *fregs) 351 { 352 unsigned long *task_var = fgraph_get_task_var(gops); 353 struct trace_array *tr = gops->private; 354 struct trace_array_cpu *data; 355 struct fgraph_times *ftimes; 356 unsigned int trace_ctx; 357 u64 calltime, rettime; 358 long disabled; 359 int size; 360 int cpu; 361 362 rettime = trace_clock_local(); 363 364 ftrace_graph_addr_finish(gops, trace); 365 366 if (*task_var & TRACE_GRAPH_NOTRACE) { 367 *task_var &= ~TRACE_GRAPH_NOTRACE; 368 return; 369 } 370 371 ftimes = fgraph_retrieve_data(gops->idx, &size); 372 if (!ftimes) 373 return; 374 375 handle_nosleeptime(trace, ftimes, size); 376 377 calltime = ftimes->calltime; 378 379 preempt_disable_notrace(); 380 cpu = raw_smp_processor_id(); 381 data = per_cpu_ptr(tr->array_buffer.data, cpu); 382 disabled = atomic_read(&data->disabled); 383 if (likely(!disabled)) { 384 trace_ctx = tracing_gen_ctx(); 385 __trace_graph_return(tr, trace, trace_ctx, calltime, rettime); 386 } 387 preempt_enable_notrace(); 388 } 389 390 static void trace_graph_thresh_return(struct ftrace_graph_ret *trace, 391 struct fgraph_ops *gops, 392 struct ftrace_regs *fregs) 393 { 394 struct fgraph_times *ftimes; 395 int size; 396 397 ftrace_graph_addr_finish(gops, trace); 398 399 if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) { 400 trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT); 401 return; 402 } 403 404 ftimes = fgraph_retrieve_data(gops->idx, &size); 405 if (!ftimes) 406 return; 407 408 handle_nosleeptime(trace, ftimes, size); 409 410 if (tracing_thresh && 411 (trace_clock_local() - ftimes->calltime < tracing_thresh)) 412 return; 413 else 414 trace_graph_return(trace, gops, fregs); 415 } 416 417 static struct fgraph_ops funcgraph_ops = { 418 .entryfunc = &trace_graph_entry, 419 .retfunc = &trace_graph_return, 420 }; 421 422 int allocate_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops) 423 { 424 struct fgraph_ops *gops; 425 426 gops = kzalloc(sizeof(*gops), GFP_KERNEL); 427 if (!gops) 428 return -ENOMEM; 429 430 gops->entryfunc = &trace_graph_entry; 431 gops->retfunc = &trace_graph_return; 432 433 tr->gops = gops; 434 gops->private = tr; 435 436 fgraph_init_ops(&gops->ops, ops); 437 438 return 0; 439 } 440 441 void free_fgraph_ops(struct trace_array *tr) 442 { 443 kfree(tr->gops); 444 } 445 446 __init void init_array_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops) 447 { 448 tr->gops = &funcgraph_ops; 449 funcgraph_ops.private = tr; 450 fgraph_init_ops(&tr->gops->ops, ops); 451 } 452 453 static int graph_trace_init(struct trace_array *tr) 454 { 455 int ret; 456 457 if (tracer_flags_is_set(TRACE_GRAPH_ARGS)) 458 tr->gops->entryfunc = trace_graph_entry_args; 459 else 460 tr->gops->entryfunc = trace_graph_entry; 461 462 if (tracing_thresh) 463 tr->gops->retfunc = trace_graph_thresh_return; 464 else 465 tr->gops->retfunc = trace_graph_return; 466 467 /* Make gops functions visible before we start tracing */ 468 smp_mb(); 469 470 ret = register_ftrace_graph(tr->gops); 471 if (ret) 472 return ret; 473 tracing_start_cmdline_record(); 474 475 return 0; 476 } 477 478 static int ftrace_graph_trace_args(struct trace_array *tr, int set) 479 { 480 trace_func_graph_ent_t entry; 481 482 if (set) 483 entry = trace_graph_entry_args; 484 else 485 entry = trace_graph_entry; 486 487 /* See if there's any changes */ 488 if (tr->gops->entryfunc == entry) 489 return 0; 490 491 unregister_ftrace_graph(tr->gops); 492 493 tr->gops->entryfunc = entry; 494 495 /* Make gops functions visible before we start tracing */ 496 smp_mb(); 497 return register_ftrace_graph(tr->gops); 498 } 499 500 static void graph_trace_reset(struct trace_array *tr) 501 { 502 tracing_stop_cmdline_record(); 503 unregister_ftrace_graph(tr->gops); 504 } 505 506 static int graph_trace_update_thresh(struct trace_array *tr) 507 { 508 graph_trace_reset(tr); 509 return graph_trace_init(tr); 510 } 511 512 static int max_bytes_for_cpu; 513 514 static void print_graph_cpu(struct trace_seq *s, int cpu) 515 { 516 /* 517 * Start with a space character - to make it stand out 518 * to the right a bit when trace output is pasted into 519 * email: 520 */ 521 trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu); 522 } 523 524 #define TRACE_GRAPH_PROCINFO_LENGTH 14 525 526 static void print_graph_proc(struct trace_seq *s, pid_t pid) 527 { 528 char comm[TASK_COMM_LEN]; 529 /* sign + log10(MAX_INT) + '\0' */ 530 char pid_str[11]; 531 int spaces = 0; 532 int len; 533 int i; 534 535 trace_find_cmdline(pid, comm); 536 comm[7] = '\0'; 537 sprintf(pid_str, "%d", pid); 538 539 /* 1 stands for the "-" character */ 540 len = strlen(comm) + strlen(pid_str) + 1; 541 542 if (len < TRACE_GRAPH_PROCINFO_LENGTH) 543 spaces = TRACE_GRAPH_PROCINFO_LENGTH - len; 544 545 /* First spaces to align center */ 546 for (i = 0; i < spaces / 2; i++) 547 trace_seq_putc(s, ' '); 548 549 trace_seq_printf(s, "%s-%s", comm, pid_str); 550 551 /* Last spaces to align center */ 552 for (i = 0; i < spaces - (spaces / 2); i++) 553 trace_seq_putc(s, ' '); 554 } 555 556 557 static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry) 558 { 559 trace_seq_putc(s, ' '); 560 trace_print_lat_fmt(s, entry); 561 trace_seq_puts(s, " | "); 562 } 563 564 /* If the pid changed since the last trace, output this event */ 565 static void 566 verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data) 567 { 568 pid_t prev_pid; 569 pid_t *last_pid; 570 571 if (!data) 572 return; 573 574 last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid); 575 576 if (*last_pid == pid) 577 return; 578 579 prev_pid = *last_pid; 580 *last_pid = pid; 581 582 if (prev_pid == -1) 583 return; 584 /* 585 * Context-switch trace line: 586 587 ------------------------------------------ 588 | 1) migration/0--1 => sshd-1755 589 ------------------------------------------ 590 591 */ 592 trace_seq_puts(s, " ------------------------------------------\n"); 593 print_graph_cpu(s, cpu); 594 print_graph_proc(s, prev_pid); 595 trace_seq_puts(s, " => "); 596 print_graph_proc(s, pid); 597 trace_seq_puts(s, "\n ------------------------------------------\n\n"); 598 } 599 600 static struct ftrace_graph_ret_entry * 601 get_return_for_leaf(struct trace_iterator *iter, 602 struct ftrace_graph_ent_entry *curr) 603 { 604 struct fgraph_data *data = iter->private; 605 struct ring_buffer_iter *ring_iter = NULL; 606 struct ring_buffer_event *event; 607 struct ftrace_graph_ret_entry *next; 608 609 /* 610 * If the previous output failed to write to the seq buffer, 611 * then we just reuse the data from before. 612 */ 613 if (data && data->failed) { 614 curr = &data->ent.ent; 615 next = &data->ret; 616 } else { 617 618 ring_iter = trace_buffer_iter(iter, iter->cpu); 619 620 /* First peek to compare current entry and the next one */ 621 if (ring_iter) 622 event = ring_buffer_iter_peek(ring_iter, NULL); 623 else { 624 /* 625 * We need to consume the current entry to see 626 * the next one. 627 */ 628 ring_buffer_consume(iter->array_buffer->buffer, iter->cpu, 629 NULL, NULL); 630 event = ring_buffer_peek(iter->array_buffer->buffer, iter->cpu, 631 NULL, NULL); 632 } 633 634 if (!event) 635 return NULL; 636 637 next = ring_buffer_event_data(event); 638 639 if (data) { 640 /* 641 * Save current and next entries for later reference 642 * if the output fails. 643 */ 644 if (unlikely(curr->ent.type == TRACE_GRAPH_RETADDR_ENT)) 645 data->ent.rent = *(struct fgraph_retaddr_ent_entry *)curr; 646 else 647 data->ent.ent = *curr; 648 /* 649 * If the next event is not a return type, then 650 * we only care about what type it is. Otherwise we can 651 * safely copy the entire event. 652 */ 653 if (next->ent.type == TRACE_GRAPH_RET) 654 data->ret = *next; 655 else 656 data->ret.ent.type = next->ent.type; 657 } 658 } 659 660 if (next->ent.type != TRACE_GRAPH_RET) 661 return NULL; 662 663 if (curr->ent.pid != next->ent.pid || 664 curr->graph_ent.func != next->ret.func) 665 return NULL; 666 667 /* this is a leaf, now advance the iterator */ 668 if (ring_iter) 669 ring_buffer_iter_advance(ring_iter); 670 671 return next; 672 } 673 674 static void print_graph_abs_time(u64 t, struct trace_seq *s) 675 { 676 unsigned long usecs_rem; 677 678 usecs_rem = do_div(t, NSEC_PER_SEC); 679 usecs_rem /= 1000; 680 681 trace_seq_printf(s, "%5lu.%06lu | ", 682 (unsigned long)t, usecs_rem); 683 } 684 685 static void 686 print_graph_rel_time(struct trace_iterator *iter, struct trace_seq *s) 687 { 688 unsigned long long usecs; 689 690 usecs = iter->ts - iter->array_buffer->time_start; 691 do_div(usecs, NSEC_PER_USEC); 692 693 trace_seq_printf(s, "%9llu us | ", usecs); 694 } 695 696 static void 697 print_graph_irq(struct trace_iterator *iter, unsigned long addr, 698 enum trace_type type, int cpu, pid_t pid, u32 flags) 699 { 700 struct trace_array *tr = iter->tr; 701 struct trace_seq *s = &iter->seq; 702 struct trace_entry *ent = iter->ent; 703 704 addr += iter->tr->text_delta; 705 706 if (addr < (unsigned long)__irqentry_text_start || 707 addr >= (unsigned long)__irqentry_text_end) 708 return; 709 710 if (tr->trace_flags & TRACE_ITER_CONTEXT_INFO) { 711 /* Absolute time */ 712 if (flags & TRACE_GRAPH_PRINT_ABS_TIME) 713 print_graph_abs_time(iter->ts, s); 714 715 /* Relative time */ 716 if (flags & TRACE_GRAPH_PRINT_REL_TIME) 717 print_graph_rel_time(iter, s); 718 719 /* Cpu */ 720 if (flags & TRACE_GRAPH_PRINT_CPU) 721 print_graph_cpu(s, cpu); 722 723 /* Proc */ 724 if (flags & TRACE_GRAPH_PRINT_PROC) { 725 print_graph_proc(s, pid); 726 trace_seq_puts(s, " | "); 727 } 728 729 /* Latency format */ 730 if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) 731 print_graph_lat_fmt(s, ent); 732 } 733 734 /* No overhead */ 735 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_START); 736 737 if (type == TRACE_GRAPH_ENT) 738 trace_seq_puts(s, "==========>"); 739 else 740 trace_seq_puts(s, "<=========="); 741 742 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_END); 743 trace_seq_putc(s, '\n'); 744 } 745 746 void 747 trace_print_graph_duration(unsigned long long duration, struct trace_seq *s) 748 { 749 unsigned long nsecs_rem = do_div(duration, 1000); 750 /* log10(ULONG_MAX) + '\0' */ 751 char usecs_str[21]; 752 char nsecs_str[5]; 753 int len; 754 int i; 755 756 sprintf(usecs_str, "%lu", (unsigned long) duration); 757 758 /* Print msecs */ 759 trace_seq_printf(s, "%s", usecs_str); 760 761 len = strlen(usecs_str); 762 763 /* Print nsecs (we don't want to exceed 7 numbers) */ 764 if (len < 7) { 765 size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len); 766 767 snprintf(nsecs_str, slen, "%03lu", nsecs_rem); 768 trace_seq_printf(s, ".%s", nsecs_str); 769 len += strlen(nsecs_str) + 1; 770 } 771 772 trace_seq_puts(s, " us "); 773 774 /* Print remaining spaces to fit the row's width */ 775 for (i = len; i < 8; i++) 776 trace_seq_putc(s, ' '); 777 } 778 779 static void 780 print_graph_duration(struct trace_array *tr, unsigned long long duration, 781 struct trace_seq *s, u32 flags) 782 { 783 if (!(flags & TRACE_GRAPH_PRINT_DURATION) || 784 !(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) 785 return; 786 787 /* No real adata, just filling the column with spaces */ 788 switch (flags & TRACE_GRAPH_PRINT_FILL_MASK) { 789 case FLAGS_FILL_FULL: 790 trace_seq_puts(s, " | "); 791 return; 792 case FLAGS_FILL_START: 793 trace_seq_puts(s, " "); 794 return; 795 case FLAGS_FILL_END: 796 trace_seq_puts(s, " |"); 797 return; 798 } 799 800 /* Signal a overhead of time execution to the output */ 801 if (flags & TRACE_GRAPH_PRINT_OVERHEAD) 802 trace_seq_printf(s, "%c ", trace_find_mark(duration)); 803 else 804 trace_seq_puts(s, " "); 805 806 trace_print_graph_duration(duration, s); 807 trace_seq_puts(s, "| "); 808 } 809 810 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL 811 #define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL 812 #else 813 #define __TRACE_GRAPH_PRINT_RETVAL 0 814 #endif 815 816 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 817 #define __TRACE_GRAPH_PRINT_RETADDR TRACE_GRAPH_PRINT_RETADDR 818 static void print_graph_retaddr(struct trace_seq *s, struct fgraph_retaddr_ent_entry *entry, 819 u32 trace_flags, bool comment) 820 { 821 if (comment) 822 trace_seq_puts(s, " /*"); 823 824 trace_seq_puts(s, " <-"); 825 seq_print_ip_sym(s, entry->graph_ent.retaddr, trace_flags | TRACE_ITER_SYM_OFFSET); 826 827 if (comment) 828 trace_seq_puts(s, " */"); 829 } 830 #else 831 #define __TRACE_GRAPH_PRINT_RETADDR 0 832 #define print_graph_retaddr(_seq, _entry, _tflags, _comment) do { } while (0) 833 #endif 834 835 #if defined(CONFIG_FUNCTION_GRAPH_RETVAL) || defined(CONFIG_FUNCTION_GRAPH_RETADDR) 836 837 static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entry *entry, 838 struct ftrace_graph_ret *graph_ret, void *func, 839 u32 opt_flags, u32 trace_flags, int args_size) 840 { 841 unsigned long err_code = 0; 842 unsigned long retval = 0; 843 bool print_retaddr = false; 844 bool print_retval = false; 845 bool hex_format = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL_HEX); 846 847 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL 848 retval = graph_ret->retval; 849 print_retval = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL); 850 #endif 851 852 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 853 print_retaddr = !!(opt_flags & TRACE_GRAPH_PRINT_RETADDR); 854 #endif 855 856 if (print_retval && retval && !hex_format) { 857 /* Check if the return value matches the negative format */ 858 if (IS_ENABLED(CONFIG_64BIT) && (retval & BIT(31)) && 859 (((u64)retval) >> 32) == 0) { 860 err_code = sign_extend64(retval, 31); 861 } else { 862 err_code = retval; 863 } 864 865 if (!IS_ERR_VALUE(err_code)) 866 err_code = 0; 867 } 868 869 if (entry) { 870 if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT) 871 print_retaddr = false; 872 873 trace_seq_printf(s, "%ps", func); 874 875 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) { 876 print_function_args(s, entry->args, (unsigned long)func); 877 trace_seq_putc(s, ';'); 878 } else 879 trace_seq_puts(s, "();"); 880 881 if (print_retval || print_retaddr) 882 trace_seq_puts(s, " /*"); 883 else 884 trace_seq_putc(s, '\n'); 885 } else { 886 print_retaddr = false; 887 trace_seq_printf(s, "} /* %ps", func); 888 } 889 890 if (print_retaddr) 891 print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry, 892 trace_flags, false); 893 894 if (print_retval) { 895 if (hex_format || (err_code == 0)) 896 trace_seq_printf(s, " ret=0x%lx", retval); 897 else 898 trace_seq_printf(s, " ret=%ld", err_code); 899 } 900 901 if (!entry || print_retval || print_retaddr) 902 trace_seq_puts(s, " */\n"); 903 } 904 905 #else 906 907 #define print_graph_retval(_seq, _ent, _ret, _func, _opt_flags, _trace_flags, args_size) \ 908 do {} while (0) 909 910 #endif 911 912 /* Case of a leaf function on its call entry */ 913 static enum print_line_t 914 print_graph_entry_leaf(struct trace_iterator *iter, 915 struct ftrace_graph_ent_entry *entry, 916 struct ftrace_graph_ret_entry *ret_entry, 917 struct trace_seq *s, u32 flags) 918 { 919 struct fgraph_data *data = iter->private; 920 struct trace_array *tr = iter->tr; 921 struct ftrace_graph_ret *graph_ret; 922 struct ftrace_graph_ent *call; 923 unsigned long long duration; 924 unsigned long ret_func; 925 unsigned long func; 926 int args_size; 927 int cpu = iter->cpu; 928 int i; 929 930 args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args); 931 932 graph_ret = &ret_entry->ret; 933 call = &entry->graph_ent; 934 duration = ret_entry->rettime - ret_entry->calltime; 935 936 func = call->func + iter->tr->text_delta; 937 938 if (data) { 939 struct fgraph_cpu_data *cpu_data; 940 941 cpu_data = per_cpu_ptr(data->cpu_data, cpu); 942 943 /* 944 * Comments display at + 1 to depth. Since 945 * this is a leaf function, keep the comments 946 * equal to this depth. 947 */ 948 cpu_data->depth = call->depth - 1; 949 950 /* No need to keep this function around for this depth */ 951 if (call->depth < FTRACE_RETFUNC_DEPTH && 952 !WARN_ON_ONCE(call->depth < 0)) 953 cpu_data->enter_funcs[call->depth] = 0; 954 } 955 956 /* Overhead and duration */ 957 print_graph_duration(tr, duration, s, flags); 958 959 /* Function */ 960 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) 961 trace_seq_putc(s, ' '); 962 963 ret_func = graph_ret->func + iter->tr->text_delta; 964 965 /* 966 * Write out the function return value or return address 967 */ 968 if (flags & (__TRACE_GRAPH_PRINT_RETVAL | __TRACE_GRAPH_PRINT_RETADDR)) { 969 print_graph_retval(s, entry, graph_ret, 970 (void *)graph_ret->func + iter->tr->text_delta, 971 flags, tr->trace_flags, args_size); 972 } else { 973 trace_seq_printf(s, "%ps", (void *)ret_func); 974 975 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) { 976 print_function_args(s, entry->args, ret_func); 977 trace_seq_putc(s, ';'); 978 } else 979 trace_seq_puts(s, "();"); 980 } 981 trace_seq_printf(s, "\n"); 982 983 print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET, 984 cpu, iter->ent->pid, flags); 985 986 return trace_handle_return(s); 987 } 988 989 static enum print_line_t 990 print_graph_entry_nested(struct trace_iterator *iter, 991 struct ftrace_graph_ent_entry *entry, 992 struct trace_seq *s, int cpu, u32 flags) 993 { 994 struct ftrace_graph_ent *call = &entry->graph_ent; 995 struct fgraph_data *data = iter->private; 996 struct trace_array *tr = iter->tr; 997 unsigned long func; 998 int args_size; 999 int i; 1000 1001 if (data) { 1002 struct fgraph_cpu_data *cpu_data; 1003 int cpu = iter->cpu; 1004 1005 cpu_data = per_cpu_ptr(data->cpu_data, cpu); 1006 cpu_data->depth = call->depth; 1007 1008 /* Save this function pointer to see if the exit matches */ 1009 if (call->depth < FTRACE_RETFUNC_DEPTH && 1010 !WARN_ON_ONCE(call->depth < 0)) 1011 cpu_data->enter_funcs[call->depth] = call->func; 1012 } 1013 1014 /* No time */ 1015 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL); 1016 1017 /* Function */ 1018 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) 1019 trace_seq_putc(s, ' '); 1020 1021 func = call->func + iter->tr->text_delta; 1022 1023 trace_seq_printf(s, "%ps", (void *)func); 1024 1025 args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args); 1026 1027 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) 1028 print_function_args(s, entry->args, func); 1029 else 1030 trace_seq_puts(s, "()"); 1031 1032 trace_seq_puts(s, " {"); 1033 1034 if (flags & __TRACE_GRAPH_PRINT_RETADDR && 1035 entry->ent.type == TRACE_GRAPH_RETADDR_ENT) 1036 print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry, 1037 tr->trace_flags, true); 1038 trace_seq_putc(s, '\n'); 1039 1040 if (trace_seq_has_overflowed(s)) 1041 return TRACE_TYPE_PARTIAL_LINE; 1042 1043 /* 1044 * we already consumed the current entry to check the next one 1045 * and see if this is a leaf. 1046 */ 1047 return TRACE_TYPE_NO_CONSUME; 1048 } 1049 1050 static void 1051 print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s, 1052 int type, unsigned long addr, u32 flags) 1053 { 1054 struct fgraph_data *data = iter->private; 1055 struct trace_entry *ent = iter->ent; 1056 struct trace_array *tr = iter->tr; 1057 int cpu = iter->cpu; 1058 1059 /* Pid */ 1060 verif_pid(s, ent->pid, cpu, data); 1061 1062 if (type) 1063 /* Interrupt */ 1064 print_graph_irq(iter, addr, type, cpu, ent->pid, flags); 1065 1066 if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) 1067 return; 1068 1069 /* Absolute time */ 1070 if (flags & TRACE_GRAPH_PRINT_ABS_TIME) 1071 print_graph_abs_time(iter->ts, s); 1072 1073 /* Relative time */ 1074 if (flags & TRACE_GRAPH_PRINT_REL_TIME) 1075 print_graph_rel_time(iter, s); 1076 1077 /* Cpu */ 1078 if (flags & TRACE_GRAPH_PRINT_CPU) 1079 print_graph_cpu(s, cpu); 1080 1081 /* Proc */ 1082 if (flags & TRACE_GRAPH_PRINT_PROC) { 1083 print_graph_proc(s, ent->pid); 1084 trace_seq_puts(s, " | "); 1085 } 1086 1087 /* Latency format */ 1088 if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) 1089 print_graph_lat_fmt(s, ent); 1090 1091 return; 1092 } 1093 1094 /* 1095 * Entry check for irq code 1096 * 1097 * returns 1 if 1098 * - we are inside irq code 1099 * - we just entered irq code 1100 * 1101 * returns 0 if 1102 * - funcgraph-interrupts option is set 1103 * - we are not inside irq code 1104 */ 1105 static int 1106 check_irq_entry(struct trace_iterator *iter, u32 flags, 1107 unsigned long addr, int depth) 1108 { 1109 int cpu = iter->cpu; 1110 int *depth_irq; 1111 struct fgraph_data *data = iter->private; 1112 1113 addr += iter->tr->text_delta; 1114 1115 /* 1116 * If we are either displaying irqs, or we got called as 1117 * a graph event and private data does not exist, 1118 * then we bypass the irq check. 1119 */ 1120 if ((flags & TRACE_GRAPH_PRINT_IRQS) || 1121 (!data)) 1122 return 0; 1123 1124 depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); 1125 1126 /* 1127 * We are inside the irq code 1128 */ 1129 if (*depth_irq >= 0) 1130 return 1; 1131 1132 if ((addr < (unsigned long)__irqentry_text_start) || 1133 (addr >= (unsigned long)__irqentry_text_end)) 1134 return 0; 1135 1136 /* 1137 * We are entering irq code. 1138 */ 1139 *depth_irq = depth; 1140 return 1; 1141 } 1142 1143 /* 1144 * Return check for irq code 1145 * 1146 * returns 1 if 1147 * - we are inside irq code 1148 * - we just left irq code 1149 * 1150 * returns 0 if 1151 * - funcgraph-interrupts option is set 1152 * - we are not inside irq code 1153 */ 1154 static int 1155 check_irq_return(struct trace_iterator *iter, u32 flags, int depth) 1156 { 1157 int cpu = iter->cpu; 1158 int *depth_irq; 1159 struct fgraph_data *data = iter->private; 1160 1161 /* 1162 * If we are either displaying irqs, or we got called as 1163 * a graph event and private data does not exist, 1164 * then we bypass the irq check. 1165 */ 1166 if ((flags & TRACE_GRAPH_PRINT_IRQS) || 1167 (!data)) 1168 return 0; 1169 1170 depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); 1171 1172 /* 1173 * We are not inside the irq code. 1174 */ 1175 if (*depth_irq == -1) 1176 return 0; 1177 1178 /* 1179 * We are inside the irq code, and this is returning entry. 1180 * Let's not trace it and clear the entry depth, since 1181 * we are out of irq code. 1182 * 1183 * This condition ensures that we 'leave the irq code' once 1184 * we are out of the entry depth. Thus protecting us from 1185 * the RETURN entry loss. 1186 */ 1187 if (*depth_irq >= depth) { 1188 *depth_irq = -1; 1189 return 1; 1190 } 1191 1192 /* 1193 * We are inside the irq code, and this is not the entry. 1194 */ 1195 return 1; 1196 } 1197 1198 static enum print_line_t 1199 print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s, 1200 struct trace_iterator *iter, u32 flags) 1201 { 1202 struct fgraph_data *data = iter->private; 1203 struct ftrace_graph_ent *call; 1204 struct ftrace_graph_ret_entry *leaf_ret; 1205 static enum print_line_t ret; 1206 int cpu = iter->cpu; 1207 /* 1208 * print_graph_entry() may consume the current event, 1209 * thus @field may become invalid, so we need to save it. 1210 * sizeof(struct ftrace_graph_ent_entry) is very small, 1211 * it can be safely saved at the stack. 1212 */ 1213 struct ftrace_graph_ent_entry *entry; 1214 u8 save_buf[sizeof(*entry) + FTRACE_REGS_MAX_ARGS * sizeof(long)]; 1215 1216 /* The ent_size is expected to be as big as the entry */ 1217 if (iter->ent_size > sizeof(save_buf)) 1218 iter->ent_size = sizeof(save_buf); 1219 1220 entry = (void *)save_buf; 1221 memcpy(entry, field, iter->ent_size); 1222 1223 call = &entry->graph_ent; 1224 1225 if (check_irq_entry(iter, flags, call->func, call->depth)) 1226 return TRACE_TYPE_HANDLED; 1227 1228 print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags); 1229 1230 leaf_ret = get_return_for_leaf(iter, entry); 1231 if (leaf_ret) 1232 ret = print_graph_entry_leaf(iter, entry, leaf_ret, s, flags); 1233 else 1234 ret = print_graph_entry_nested(iter, entry, s, cpu, flags); 1235 1236 if (data) { 1237 /* 1238 * If we failed to write our output, then we need to make 1239 * note of it. Because we already consumed our entry. 1240 */ 1241 if (s->full) { 1242 data->failed = 1; 1243 data->cpu = cpu; 1244 } else 1245 data->failed = 0; 1246 } 1247 1248 return ret; 1249 } 1250 1251 static enum print_line_t 1252 print_graph_return(struct ftrace_graph_ret_entry *retentry, struct trace_seq *s, 1253 struct trace_entry *ent, struct trace_iterator *iter, 1254 u32 flags) 1255 { 1256 struct ftrace_graph_ret *trace = &retentry->ret; 1257 u64 calltime = retentry->calltime; 1258 u64 rettime = retentry->rettime; 1259 unsigned long long duration = rettime - calltime; 1260 struct fgraph_data *data = iter->private; 1261 struct trace_array *tr = iter->tr; 1262 unsigned long func; 1263 pid_t pid = ent->pid; 1264 int cpu = iter->cpu; 1265 int func_match = 1; 1266 int i; 1267 1268 func = trace->func + iter->tr->text_delta; 1269 1270 if (check_irq_return(iter, flags, trace->depth)) 1271 return TRACE_TYPE_HANDLED; 1272 1273 if (data) { 1274 struct fgraph_cpu_data *cpu_data; 1275 int cpu = iter->cpu; 1276 1277 cpu_data = per_cpu_ptr(data->cpu_data, cpu); 1278 1279 /* 1280 * Comments display at + 1 to depth. This is the 1281 * return from a function, we now want the comments 1282 * to display at the same level of the bracket. 1283 */ 1284 cpu_data->depth = trace->depth - 1; 1285 1286 if (trace->depth < FTRACE_RETFUNC_DEPTH && 1287 !WARN_ON_ONCE(trace->depth < 0)) { 1288 if (cpu_data->enter_funcs[trace->depth] != trace->func) 1289 func_match = 0; 1290 cpu_data->enter_funcs[trace->depth] = 0; 1291 } 1292 } 1293 1294 print_graph_prologue(iter, s, 0, 0, flags); 1295 1296 /* Overhead and duration */ 1297 print_graph_duration(tr, duration, s, flags); 1298 1299 /* Closing brace */ 1300 for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) 1301 trace_seq_putc(s, ' '); 1302 1303 /* 1304 * Always write out the function name and its return value if the 1305 * funcgraph-retval option is enabled. 1306 */ 1307 if (flags & __TRACE_GRAPH_PRINT_RETVAL) { 1308 print_graph_retval(s, NULL, trace, (void *)func, flags, 1309 tr->trace_flags, 0); 1310 } else { 1311 /* 1312 * If the return function does not have a matching entry, 1313 * then the entry was lost. Instead of just printing 1314 * the '}' and letting the user guess what function this 1315 * belongs to, write out the function name. Always do 1316 * that if the funcgraph-tail option is enabled. 1317 */ 1318 if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL)) 1319 trace_seq_puts(s, "}\n"); 1320 else 1321 trace_seq_printf(s, "} /* %ps */\n", (void *)func); 1322 } 1323 1324 /* Overrun */ 1325 if (flags & TRACE_GRAPH_PRINT_OVERRUN) 1326 trace_seq_printf(s, " (Overruns: %u)\n", 1327 trace->overrun); 1328 1329 print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, 1330 cpu, pid, flags); 1331 1332 return trace_handle_return(s); 1333 } 1334 1335 static enum print_line_t 1336 print_graph_comment(struct trace_seq *s, struct trace_entry *ent, 1337 struct trace_iterator *iter, u32 flags) 1338 { 1339 struct trace_array *tr = iter->tr; 1340 unsigned long sym_flags = (tr->trace_flags & TRACE_ITER_SYM_MASK); 1341 struct fgraph_data *data = iter->private; 1342 struct trace_event *event; 1343 int depth = 0; 1344 int ret; 1345 int i; 1346 1347 if (data) 1348 depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth; 1349 1350 print_graph_prologue(iter, s, 0, 0, flags); 1351 1352 /* No time */ 1353 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL); 1354 1355 /* Indentation */ 1356 if (depth > 0) 1357 for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) 1358 trace_seq_putc(s, ' '); 1359 1360 /* The comment */ 1361 trace_seq_puts(s, "/* "); 1362 1363 switch (iter->ent->type) { 1364 case TRACE_BPUTS: 1365 ret = trace_print_bputs_msg_only(iter); 1366 if (ret != TRACE_TYPE_HANDLED) 1367 return ret; 1368 break; 1369 case TRACE_BPRINT: 1370 ret = trace_print_bprintk_msg_only(iter); 1371 if (ret != TRACE_TYPE_HANDLED) 1372 return ret; 1373 break; 1374 case TRACE_PRINT: 1375 ret = trace_print_printk_msg_only(iter); 1376 if (ret != TRACE_TYPE_HANDLED) 1377 return ret; 1378 break; 1379 default: 1380 event = ftrace_find_event(ent->type); 1381 if (!event) 1382 return TRACE_TYPE_UNHANDLED; 1383 1384 ret = event->funcs->trace(iter, sym_flags, event); 1385 if (ret != TRACE_TYPE_HANDLED) 1386 return ret; 1387 } 1388 1389 if (trace_seq_has_overflowed(s)) 1390 goto out; 1391 1392 /* Strip ending newline */ 1393 if (s->buffer[s->seq.len - 1] == '\n') { 1394 s->buffer[s->seq.len - 1] = '\0'; 1395 s->seq.len--; 1396 } 1397 1398 trace_seq_puts(s, " */\n"); 1399 out: 1400 return trace_handle_return(s); 1401 } 1402 1403 1404 enum print_line_t 1405 print_graph_function_flags(struct trace_iterator *iter, u32 flags) 1406 { 1407 struct ftrace_graph_ent_entry *field; 1408 struct fgraph_data *data = iter->private; 1409 struct trace_entry *entry = iter->ent; 1410 struct trace_seq *s = &iter->seq; 1411 int cpu = iter->cpu; 1412 int ret; 1413 1414 if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) { 1415 per_cpu_ptr(data->cpu_data, cpu)->ignore = 0; 1416 return TRACE_TYPE_HANDLED; 1417 } 1418 1419 /* 1420 * If the last output failed, there's a possibility we need 1421 * to print out the missing entry which would never go out. 1422 */ 1423 if (data && data->failed) { 1424 field = &data->ent.ent; 1425 iter->cpu = data->cpu; 1426 ret = print_graph_entry(field, s, iter, flags); 1427 if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) { 1428 per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1; 1429 ret = TRACE_TYPE_NO_CONSUME; 1430 } 1431 iter->cpu = cpu; 1432 return ret; 1433 } 1434 1435 switch (entry->type) { 1436 case TRACE_GRAPH_ENT: { 1437 trace_assign_type(field, entry); 1438 return print_graph_entry(field, s, iter, flags); 1439 } 1440 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 1441 case TRACE_GRAPH_RETADDR_ENT: { 1442 struct fgraph_retaddr_ent_entry saved; 1443 struct fgraph_retaddr_ent_entry *rfield; 1444 1445 trace_assign_type(rfield, entry); 1446 saved = *rfield; 1447 return print_graph_entry((struct ftrace_graph_ent_entry *)&saved, s, iter, flags); 1448 } 1449 #endif 1450 case TRACE_GRAPH_RET: { 1451 struct ftrace_graph_ret_entry *field; 1452 trace_assign_type(field, entry); 1453 return print_graph_return(field, s, entry, iter, flags); 1454 } 1455 case TRACE_STACK: 1456 case TRACE_FN: 1457 /* dont trace stack and functions as comments */ 1458 return TRACE_TYPE_UNHANDLED; 1459 1460 default: 1461 return print_graph_comment(s, entry, iter, flags); 1462 } 1463 1464 return TRACE_TYPE_HANDLED; 1465 } 1466 1467 static enum print_line_t 1468 print_graph_function(struct trace_iterator *iter) 1469 { 1470 return print_graph_function_flags(iter, tracer_flags.val); 1471 } 1472 1473 static enum print_line_t 1474 print_graph_function_event(struct trace_iterator *iter, int flags, 1475 struct trace_event *event) 1476 { 1477 return print_graph_function(iter); 1478 } 1479 1480 static void print_lat_header(struct seq_file *s, u32 flags) 1481 { 1482 static const char spaces[] = " " /* 16 spaces */ 1483 " " /* 4 spaces */ 1484 " "; /* 17 spaces */ 1485 int size = 0; 1486 1487 if (flags & TRACE_GRAPH_PRINT_ABS_TIME) 1488 size += 16; 1489 if (flags & TRACE_GRAPH_PRINT_REL_TIME) 1490 size += 16; 1491 if (flags & TRACE_GRAPH_PRINT_CPU) 1492 size += 4; 1493 if (flags & TRACE_GRAPH_PRINT_PROC) 1494 size += 17; 1495 1496 seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces); 1497 seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces); 1498 seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces); 1499 seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces); 1500 seq_printf(s, "#%.*s||| / \n", size, spaces); 1501 } 1502 1503 static void __print_graph_headers_flags(struct trace_array *tr, 1504 struct seq_file *s, u32 flags) 1505 { 1506 int lat = tr->trace_flags & TRACE_ITER_LATENCY_FMT; 1507 1508 if (lat) 1509 print_lat_header(s, flags); 1510 1511 /* 1st line */ 1512 seq_putc(s, '#'); 1513 if (flags & TRACE_GRAPH_PRINT_ABS_TIME) 1514 seq_puts(s, " TIME "); 1515 if (flags & TRACE_GRAPH_PRINT_REL_TIME) 1516 seq_puts(s, " REL TIME "); 1517 if (flags & TRACE_GRAPH_PRINT_CPU) 1518 seq_puts(s, " CPU"); 1519 if (flags & TRACE_GRAPH_PRINT_PROC) 1520 seq_puts(s, " TASK/PID "); 1521 if (lat) 1522 seq_puts(s, "|||| "); 1523 if (flags & TRACE_GRAPH_PRINT_DURATION) 1524 seq_puts(s, " DURATION "); 1525 seq_puts(s, " FUNCTION CALLS\n"); 1526 1527 /* 2nd line */ 1528 seq_putc(s, '#'); 1529 if (flags & TRACE_GRAPH_PRINT_ABS_TIME) 1530 seq_puts(s, " | "); 1531 if (flags & TRACE_GRAPH_PRINT_REL_TIME) 1532 seq_puts(s, " | "); 1533 if (flags & TRACE_GRAPH_PRINT_CPU) 1534 seq_puts(s, " | "); 1535 if (flags & TRACE_GRAPH_PRINT_PROC) 1536 seq_puts(s, " | | "); 1537 if (lat) 1538 seq_puts(s, "|||| "); 1539 if (flags & TRACE_GRAPH_PRINT_DURATION) 1540 seq_puts(s, " | | "); 1541 seq_puts(s, " | | | |\n"); 1542 } 1543 1544 static void print_graph_headers(struct seq_file *s) 1545 { 1546 print_graph_headers_flags(s, tracer_flags.val); 1547 } 1548 1549 void print_graph_headers_flags(struct seq_file *s, u32 flags) 1550 { 1551 struct trace_iterator *iter = s->private; 1552 struct trace_array *tr = iter->tr; 1553 1554 if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) 1555 return; 1556 1557 if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) { 1558 /* print nothing if the buffers are empty */ 1559 if (trace_empty(iter)) 1560 return; 1561 1562 print_trace_header(s, iter); 1563 } 1564 1565 __print_graph_headers_flags(tr, s, flags); 1566 } 1567 1568 void graph_trace_open(struct trace_iterator *iter) 1569 { 1570 /* pid and depth on the last trace processed */ 1571 struct fgraph_data *data; 1572 gfp_t gfpflags; 1573 int cpu; 1574 1575 iter->private = NULL; 1576 1577 /* We can be called in atomic context via ftrace_dump() */ 1578 gfpflags = (in_atomic() || irqs_disabled()) ? GFP_ATOMIC : GFP_KERNEL; 1579 1580 data = kzalloc(sizeof(*data), gfpflags); 1581 if (!data) 1582 goto out_err; 1583 1584 data->cpu_data = alloc_percpu_gfp(struct fgraph_cpu_data, gfpflags); 1585 if (!data->cpu_data) 1586 goto out_err_free; 1587 1588 for_each_possible_cpu(cpu) { 1589 pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid); 1590 int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth); 1591 int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore); 1592 int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); 1593 1594 *pid = -1; 1595 *depth = 0; 1596 *ignore = 0; 1597 *depth_irq = -1; 1598 } 1599 1600 iter->private = data; 1601 1602 return; 1603 1604 out_err_free: 1605 kfree(data); 1606 out_err: 1607 pr_warn("function graph tracer: not enough memory\n"); 1608 } 1609 1610 void graph_trace_close(struct trace_iterator *iter) 1611 { 1612 struct fgraph_data *data = iter->private; 1613 1614 if (data) { 1615 free_percpu(data->cpu_data); 1616 kfree(data); 1617 } 1618 } 1619 1620 static int 1621 func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set) 1622 { 1623 if (bit == TRACE_GRAPH_PRINT_IRQS) 1624 ftrace_graph_skip_irqs = !set; 1625 1626 if (bit == TRACE_GRAPH_SLEEP_TIME) 1627 ftrace_graph_sleep_time_control(set); 1628 1629 if (bit == TRACE_GRAPH_GRAPH_TIME) 1630 ftrace_graph_graph_time_control(set); 1631 1632 if (bit == TRACE_GRAPH_ARGS) 1633 return ftrace_graph_trace_args(tr, set); 1634 1635 return 0; 1636 } 1637 1638 static struct trace_event_functions graph_functions = { 1639 .trace = print_graph_function_event, 1640 }; 1641 1642 static struct trace_event graph_trace_entry_event = { 1643 .type = TRACE_GRAPH_ENT, 1644 .funcs = &graph_functions, 1645 }; 1646 1647 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 1648 static struct trace_event graph_trace_retaddr_entry_event = { 1649 .type = TRACE_GRAPH_RETADDR_ENT, 1650 .funcs = &graph_functions, 1651 }; 1652 #endif 1653 1654 static struct trace_event graph_trace_ret_event = { 1655 .type = TRACE_GRAPH_RET, 1656 .funcs = &graph_functions 1657 }; 1658 1659 static struct tracer graph_trace __tracer_data = { 1660 .name = "function_graph", 1661 .update_thresh = graph_trace_update_thresh, 1662 .open = graph_trace_open, 1663 .pipe_open = graph_trace_open, 1664 .close = graph_trace_close, 1665 .pipe_close = graph_trace_close, 1666 .init = graph_trace_init, 1667 .reset = graph_trace_reset, 1668 .print_line = print_graph_function, 1669 .print_header = print_graph_headers, 1670 .flags = &tracer_flags, 1671 .set_flag = func_graph_set_flag, 1672 .allow_instances = true, 1673 #ifdef CONFIG_FTRACE_SELFTEST 1674 .selftest = trace_selftest_startup_function_graph, 1675 #endif 1676 }; 1677 1678 1679 static ssize_t 1680 graph_depth_write(struct file *filp, const char __user *ubuf, size_t cnt, 1681 loff_t *ppos) 1682 { 1683 unsigned long val; 1684 int ret; 1685 1686 ret = kstrtoul_from_user(ubuf, cnt, 10, &val); 1687 if (ret) 1688 return ret; 1689 1690 fgraph_max_depth = val; 1691 1692 *ppos += cnt; 1693 1694 return cnt; 1695 } 1696 1697 static ssize_t 1698 graph_depth_read(struct file *filp, char __user *ubuf, size_t cnt, 1699 loff_t *ppos) 1700 { 1701 char buf[15]; /* More than enough to hold UINT_MAX + "\n"*/ 1702 int n; 1703 1704 n = sprintf(buf, "%d\n", fgraph_max_depth); 1705 1706 return simple_read_from_buffer(ubuf, cnt, ppos, buf, n); 1707 } 1708 1709 static const struct file_operations graph_depth_fops = { 1710 .open = tracing_open_generic, 1711 .write = graph_depth_write, 1712 .read = graph_depth_read, 1713 .llseek = generic_file_llseek, 1714 }; 1715 1716 static __init int init_graph_tracefs(void) 1717 { 1718 int ret; 1719 1720 ret = tracing_init_dentry(); 1721 if (ret) 1722 return 0; 1723 1724 trace_create_file("max_graph_depth", TRACE_MODE_WRITE, NULL, 1725 NULL, &graph_depth_fops); 1726 1727 return 0; 1728 } 1729 fs_initcall(init_graph_tracefs); 1730 1731 static __init int init_graph_trace(void) 1732 { 1733 max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1); 1734 1735 if (!register_trace_event(&graph_trace_entry_event)) { 1736 pr_warn("Warning: could not register graph trace events\n"); 1737 return 1; 1738 } 1739 1740 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR 1741 if (!register_trace_event(&graph_trace_retaddr_entry_event)) { 1742 pr_warn("Warning: could not register graph trace retaddr events\n"); 1743 return 1; 1744 } 1745 #endif 1746 1747 if (!register_trace_event(&graph_trace_ret_event)) { 1748 pr_warn("Warning: could not register graph trace events\n"); 1749 return 1; 1750 } 1751 1752 return register_tracer(&graph_trace); 1753 } 1754 1755 core_initcall(init_graph_trace); 1756