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