kernel/trace/trace_functions_graph.c

   1 /*
   2  *
   3  * Function graph tracer.
   4  * Copyright (c) 2008 Frederic Weisbecker <fweisbec@gmail.com>
   5  * Mostly borrowed from function tracer which
   6  * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
   7  *
   8  */
   9 #include <linux/debugfs.h>
  10 #include <linux/uaccess.h>
  11 #include <linux/ftrace.h>
  12 #include <linux/fs.h>
  13
  14 #include "trace.h"
  15
  16 #define TRACE_GRAPH_INDENT      2
  17
  18 /* Flag options */
  19 #define TRACE_GRAPH_PRINT_OVERRUN       0x1
  20 #define TRACE_GRAPH_PRINT_CPU           0x2
  21 #define TRACE_GRAPH_PRINT_OVERHEAD      0x4
  22 #define TRACE_GRAPH_PRINT_PROC          0x8
  23
  24 static struct tracer_opt trace_opts[] = {
  25         /* Display overruns ? */
  26         { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
  27         /* Display CPU ? */
  28         { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
  29         /* Display Overhead ? */
  30         { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
  31         /* Display proc name/pid */
  32         { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
  33         { } /* Empty entry */
  34 };
  35
  36 static struct tracer_flags tracer_flags = {
  37         /* Don't display overruns and proc by default */
  38         .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD,
  39         .opts = trace_opts
  40 };
  41
  42 /* pid on the last trace processed */
  43 static pid_t last_pid[NR_CPUS] = { [0 ... NR_CPUS-1] = -1 };
  44
  45 static int graph_trace_init(struct trace_array *tr)
  46 {
  47         int cpu, ret;
  48
  49         for_each_online_cpu(cpu)
  50                 tracing_reset(tr, cpu);
  51
  52         ret = register_ftrace_graph(&trace_graph_return,
  53                                         &trace_graph_entry);
  54         if (ret)
  55                 return ret;
  56         tracing_start_cmdline_record();
  57
  58         return 0;
  59 }
  60
  61 static void graph_trace_reset(struct trace_array *tr)
  62 {
  63         tracing_stop_cmdline_record();
  64         unregister_ftrace_graph();
  65 }
  66
  67 static inline int log10_cpu(int nb)
  68 {
  69         if (nb / 100)
  70                 return 3;
  71         if (nb / 10)
  72                 return 2;
  73         return 1;
  74 }
  75
  76 static enum print_line_t
  77 print_graph_cpu(struct trace_seq *s, int cpu)
  78 {
  79         int i;
  80         int ret;
  81         int log10_this = log10_cpu(cpu);
  82         int log10_all = log10_cpu(cpus_weight_nr(cpu_online_map));
  83
  84
  85         /*
  86          * Start with a space character - to make it stand out
  87          * to the right a bit when trace output is pasted into
  88          * email:
  89          */
  90         ret = trace_seq_printf(s, " ");
  91
  92         /*
  93          * Tricky - we space the CPU field according to the max
  94          * number of online CPUs. On a 2-cpu system it would take
  95          * a maximum of 1 digit - on a 128 cpu system it would
  96          * take up to 3 digits:
  97          */
  98         for (i = 0; i < log10_all - log10_this; i++) {
  99                 ret = trace_seq_printf(s, " ");
 100                 if (!ret)
 101                         return TRACE_TYPE_PARTIAL_LINE;
 102         }
 103         ret = trace_seq_printf(s, "%d) ", cpu);
 104         if (!ret)
 105                 return TRACE_TYPE_PARTIAL_LINE;
 106
 107         return TRACE_TYPE_HANDLED;
 108 }
 109
 110 #define TRACE_GRAPH_PROCINFO_LENGTH     14
 111
 112 static enum print_line_t
 113 print_graph_proc(struct trace_seq *s, pid_t pid)
 114 {
 115         int i;
 116         int ret;
 117         int len;
 118         char comm[8];
 119         int spaces = 0;
 120         /* sign + log10(MAX_INT) + '\0' */
 121         char pid_str[11];
 122
 123         strncpy(comm, trace_find_cmdline(pid), 7);
 124         comm[7] = '\0';
 125         sprintf(pid_str, "%d", pid);
 126
 127         /* 1 stands for the "-" character */
 128         len = strlen(comm) + strlen(pid_str) + 1;
 129
 130         if (len < TRACE_GRAPH_PROCINFO_LENGTH)
 131                 spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
 132
 133         /* First spaces to align center */
 134         for (i = 0; i < spaces / 2; i++) {
 135                 ret = trace_seq_printf(s, " ");
 136                 if (!ret)
 137                         return TRACE_TYPE_PARTIAL_LINE;
 138         }
 139
 140         ret = trace_seq_printf(s, "%s-%s", comm, pid_str);
 141         if (!ret)
 142                 return TRACE_TYPE_PARTIAL_LINE;
 143
 144         /* Last spaces to align center */
 145         for (i = 0; i < spaces - (spaces / 2); i++) {
 146                 ret = trace_seq_printf(s, " ");
 147                 if (!ret)
 148                         return TRACE_TYPE_PARTIAL_LINE;
 149         }
 150         return TRACE_TYPE_HANDLED;
 151 }
 152
 153
 154 /* If the pid changed since the last trace, output this event */
 155 static enum print_line_t
 156 verif_pid(struct trace_seq *s, pid_t pid, int cpu)
 157 {
 158         pid_t prev_pid;
 159         int ret;
 160
 161         if (last_pid[cpu] != -1 && last_pid[cpu] == pid)
 162                 return TRACE_TYPE_HANDLED;
 163
 164         prev_pid = last_pid[cpu];
 165         last_pid[cpu] = pid;
 166
 167 /*
 168  * Context-switch trace line:
 169
 170  ------------------------------------------
 171  | 1)  migration/0--1  =>  sshd-1755
 172  ------------------------------------------
 173
 174  */
 175         ret = trace_seq_printf(s,
 176                 "\n ------------------------------------------\n |");
 177         if (!ret)
 178                 TRACE_TYPE_PARTIAL_LINE;
 179
 180         ret = print_graph_cpu(s, cpu);
 181         if (ret == TRACE_TYPE_PARTIAL_LINE)
 182                 TRACE_TYPE_PARTIAL_LINE;
 183
 184         ret = print_graph_proc(s, prev_pid);
 185         if (ret == TRACE_TYPE_PARTIAL_LINE)
 186                 TRACE_TYPE_PARTIAL_LINE;
 187
 188         ret = trace_seq_printf(s, " => ");
 189         if (!ret)
 190                 TRACE_TYPE_PARTIAL_LINE;
 191
 192         ret = print_graph_proc(s, pid);
 193         if (ret == TRACE_TYPE_PARTIAL_LINE)
 194                 TRACE_TYPE_PARTIAL_LINE;
 195
 196         ret = trace_seq_printf(s,
 197                 "\n ------------------------------------------\n\n");
 198         if (!ret)
 199                 TRACE_TYPE_PARTIAL_LINE;
 200
 201         return ret;
 202 }
 203
 204 static bool
 205 trace_branch_is_leaf(struct trace_iterator *iter,
 206                 struct ftrace_graph_ent_entry *curr)
 207 {
 208         struct ring_buffer_iter *ring_iter;
 209         struct ring_buffer_event *event;
 210         struct ftrace_graph_ret_entry *next;
 211
 212         ring_iter = iter->buffer_iter[iter->cpu];
 213
 214         if (!ring_iter)
 215                 return false;
 216
 217         event = ring_buffer_iter_peek(ring_iter, NULL);
 218
 219         if (!event)
 220                 return false;
 221
 222         next = ring_buffer_event_data(event);
 223
 224         if (next->ent.type != TRACE_GRAPH_RET)
 225                 return false;
 226
 227         if (curr->ent.pid != next->ent.pid ||
 228                         curr->graph_ent.func != next->ret.func)
 229                 return false;
 230
 231         return true;
 232 }
 233
 234
 235 static inline int
 236 print_graph_duration(unsigned long long duration, struct trace_seq *s)
 237 {
 238         unsigned long nsecs_rem = do_div(duration, 1000);
 239         return trace_seq_printf(s, "%4llu.%3lu us |  ", duration, nsecs_rem);
 240 }
 241
 242 /* Signal a overhead of time execution to the output */
 243 static int
 244 print_graph_overhead(unsigned long long duration, struct trace_seq *s)
 245 {
 246         /* Duration exceeded 100 msecs */
 247         if (duration > 100000ULL)
 248                 return trace_seq_printf(s, "! ");
 249
 250         /* Duration exceeded 10 msecs */
 251         if (duration > 10000ULL)
 252                 return trace_seq_printf(s, "+ ");
 253
 254         return trace_seq_printf(s, "  ");
 255 }
 256
 257 /* Case of a leaf function on its call entry */
 258 static enum print_line_t
 259 print_graph_entry_leaf(struct trace_iterator *iter,
 260                 struct ftrace_graph_ent_entry *entry, struct trace_seq *s)
 261 {
 262         struct ftrace_graph_ret_entry *ret_entry;
 263         struct ftrace_graph_ret *graph_ret;
 264         struct ring_buffer_event *event;
 265         struct ftrace_graph_ent *call;
 266         unsigned long long duration;
 267         int ret;
 268         int i;
 269
 270         event = ring_buffer_read(iter->buffer_iter[iter->cpu], NULL);
 271         ret_entry = ring_buffer_event_data(event);
 272         graph_ret = &ret_entry->ret;
 273         call = &entry->graph_ent;
 274         duration = graph_ret->rettime - graph_ret->calltime;
 275
 276         /* Must not exceed 8 characters: 9999.999 us */
 277         if (duration > 10000000ULL)
 278                 duration = 9999999ULL;
 279
 280         /* Overhead */
 281         if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
 282                 ret = print_graph_overhead(duration, s);
 283                 if (!ret)
 284                         return TRACE_TYPE_PARTIAL_LINE;
 285         }
 286
 287         /* Duration */
 288         ret = print_graph_duration(duration, s);
 289         if (!ret)
 290                 return TRACE_TYPE_PARTIAL_LINE;
 291
 292         /* Function */
 293         for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
 294                 ret = trace_seq_printf(s, " ");
 295                 if (!ret)
 296                         return TRACE_TYPE_PARTIAL_LINE;
 297         }
 298
 299         ret = seq_print_ip_sym(s, call->func, 0);
 300         if (!ret)
 301                 return TRACE_TYPE_PARTIAL_LINE;
 302
 303         ret = trace_seq_printf(s, "();\n");
 304         if (!ret)
 305                 return TRACE_TYPE_PARTIAL_LINE;
 306
 307         return TRACE_TYPE_HANDLED;
 308 }
 309
 310 static enum print_line_t
 311 print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
 312                         struct trace_seq *s)
 313 {
 314         int i;
 315         int ret;
 316         struct ftrace_graph_ent *call = &entry->graph_ent;
 317
 318         /* No overhead */
 319         if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
 320                 ret = trace_seq_printf(s, "  ");
 321                 if (!ret)
 322                         return TRACE_TYPE_PARTIAL_LINE;
 323         }
 324
 325         /* No time */
 326         ret = trace_seq_printf(s, "            |  ");
 327
 328         /* Function */
 329         for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
 330                 ret = trace_seq_printf(s, " ");
 331                 if (!ret)
 332                         return TRACE_TYPE_PARTIAL_LINE;
 333         }
 334
 335         ret = seq_print_ip_sym(s, call->func, 0);
 336         if (!ret)
 337                 return TRACE_TYPE_PARTIAL_LINE;
 338
 339         ret = trace_seq_printf(s, "() {\n");
 340         if (!ret)
 341                 return TRACE_TYPE_PARTIAL_LINE;
 342
 343         return TRACE_TYPE_HANDLED;
 344 }
 345
 346 static enum print_line_t
 347 print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
 348                         struct trace_iterator *iter, int cpu)
 349 {
 350         int ret;
 351         struct trace_entry *ent = iter->ent;
 352
 353         /* Pid */
 354         if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE)
 355                 return TRACE_TYPE_PARTIAL_LINE;
 356
 357         /* Cpu */
 358         if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
 359                 ret = print_graph_cpu(s, cpu);
 360                 if (ret == TRACE_TYPE_PARTIAL_LINE)
 361                         return TRACE_TYPE_PARTIAL_LINE;
 362         }
 363
 364         /* Proc */
 365         if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
 366                 ret = print_graph_proc(s, ent->pid);
 367                 if (ret == TRACE_TYPE_PARTIAL_LINE)
 368                         return TRACE_TYPE_PARTIAL_LINE;
 369
 370                 ret = trace_seq_printf(s, " | ");
 371                 if (!ret)
 372                         return TRACE_TYPE_PARTIAL_LINE;
 373         }
 374
 375         if (trace_branch_is_leaf(iter, field))
 376                 return print_graph_entry_leaf(iter, field, s);
 377         else
 378                 return print_graph_entry_nested(field, s);
 379
 380 }
 381
 382 static enum print_line_t
 383 print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 384                    struct trace_entry *ent, int cpu)
 385 {
 386         int i;
 387         int ret;
 388         unsigned long long duration = trace->rettime - trace->calltime;
 389
 390         /* Must not exceed 8 characters: xxxx.yyy us */
 391         if (duration > 10000000ULL)
 392                 duration = 9999999ULL;
 393
 394         /* Pid */
 395         if (verif_pid(s, ent->pid, cpu) == TRACE_TYPE_PARTIAL_LINE)
 396                 return TRACE_TYPE_PARTIAL_LINE;
 397
 398         /* Cpu */
 399         if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
 400                 ret = print_graph_cpu(s, cpu);
 401                 if (ret == TRACE_TYPE_PARTIAL_LINE)
 402                         return TRACE_TYPE_PARTIAL_LINE;
 403         }
 404
 405         /* Proc */
 406         if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
 407                 ret = print_graph_proc(s, ent->pid);
 408                 if (ret == TRACE_TYPE_PARTIAL_LINE)
 409                         return TRACE_TYPE_PARTIAL_LINE;
 410
 411                 ret = trace_seq_printf(s, " | ");
 412                 if (!ret)
 413                         return TRACE_TYPE_PARTIAL_LINE;
 414         }
 415
 416         /* Overhead */
 417         if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERHEAD) {
 418                 ret = print_graph_overhead(duration, s);
 419                 if (!ret)
 420                         return TRACE_TYPE_PARTIAL_LINE;
 421         }
 422
 423         /* Duration */
 424         ret = print_graph_duration(duration, s);
 425         if (!ret)
 426                 return TRACE_TYPE_PARTIAL_LINE;
 427
 428         /* Closing brace */
 429         for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
 430                 ret = trace_seq_printf(s, " ");
 431                 if (!ret)
 432                         return TRACE_TYPE_PARTIAL_LINE;
 433         }
 434
 435         ret = trace_seq_printf(s, "}\n");
 436         if (!ret)
 437                 return TRACE_TYPE_PARTIAL_LINE;
 438
 439         /* Overrun */
 440         if (tracer_flags.val & TRACE_GRAPH_PRINT_OVERRUN) {
 441                 ret = trace_seq_printf(s, " (Overruns: %lu)\n",
 442                                         trace->overrun);
 443                 if (!ret)
 444                         return TRACE_TYPE_PARTIAL_LINE;
 445         }
 446         return TRACE_TYPE_HANDLED;
 447 }
 448
 449 enum print_line_t
 450 print_graph_function(struct trace_iterator *iter)
 451 {
 452         struct trace_seq *s = &iter->seq;
 453         struct trace_entry *entry = iter->ent;
 454
 455         switch (entry->type) {
 456         case TRACE_GRAPH_ENT: {
 457                 struct ftrace_graph_ent_entry *field;
 458                 trace_assign_type(field, entry);
 459                 return print_graph_entry(field, s, iter,
 460                                          iter->cpu);
 461         }
 462         case TRACE_GRAPH_RET: {
 463                 struct ftrace_graph_ret_entry *field;
 464                 trace_assign_type(field, entry);
 465                 return print_graph_return(&field->ret, s, entry, iter->cpu);
 466         }
 467         default:
 468                 return TRACE_TYPE_UNHANDLED;
 469         }
 470 }
 471
 472 static struct tracer graph_trace __read_mostly = {
 473         .name        = "function_graph",
 474         .init        = graph_trace_init,
 475         .reset       = graph_trace_reset,
 476         .print_line = print_graph_function,
 477         .flags          = &tracer_flags,
 478 };
 479
 480 static __init int init_graph_trace(void)
 481 {
 482         return register_tracer(&graph_trace);
 483 }
 484
 485 device_initcall(init_graph_trace);