diff options
Diffstat (limited to 'kernel/trace/trace_functions_graph.c')
| -rw-r--r-- | kernel/trace/trace_functions_graph.c | 228 |
1 files changed, 182 insertions, 46 deletions
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c index 420ec3487579..45e6c01b2e4d 100644 --- a/kernel/trace/trace_functions_graph.c +++ b/kernel/trace/trace_functions_graph.c | |||
| @@ -52,7 +52,7 @@ static struct tracer_flags tracer_flags = { | |||
| 52 | .opts = trace_opts | 52 | .opts = trace_opts |
| 53 | }; | 53 | }; |
| 54 | 54 | ||
| 55 | /* pid on the last trace processed */ | 55 | static struct trace_array *graph_array; |
| 56 | 56 | ||
| 57 | 57 | ||
| 58 | /* Add a function return address to the trace stack on thread info.*/ | 58 | /* Add a function return address to the trace stack on thread info.*/ |
| @@ -124,7 +124,7 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret, | |||
| 124 | if (unlikely(current->ret_stack[index].fp != frame_pointer)) { | 124 | if (unlikely(current->ret_stack[index].fp != frame_pointer)) { |
| 125 | ftrace_graph_stop(); | 125 | ftrace_graph_stop(); |
| 126 | WARN(1, "Bad frame pointer: expected %lx, received %lx\n" | 126 | WARN(1, "Bad frame pointer: expected %lx, received %lx\n" |
| 127 | " from func %pF return to %lx\n", | 127 | " from func %ps return to %lx\n", |
| 128 | current->ret_stack[index].fp, | 128 | current->ret_stack[index].fp, |
| 129 | frame_pointer, | 129 | frame_pointer, |
| 130 | (void *)current->ret_stack[index].func, | 130 | (void *)current->ret_stack[index].func, |
| @@ -166,10 +166,123 @@ unsigned long ftrace_return_to_handler(unsigned long frame_pointer) | |||
| 166 | return ret; | 166 | return ret; |
| 167 | } | 167 | } |
| 168 | 168 | ||
| 169 | static int __trace_graph_entry(struct trace_array *tr, | ||
| 170 | struct ftrace_graph_ent *trace, | ||
| 171 | unsigned long flags, | ||
| 172 | int pc) | ||
| 173 | { | ||
| 174 | struct ftrace_event_call *call = &event_funcgraph_entry; | ||
| 175 | struct ring_buffer_event *event; | ||
| 176 | struct ring_buffer *buffer = tr->buffer; | ||
| 177 | struct ftrace_graph_ent_entry *entry; | ||
| 178 | |||
| 179 | if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled)))) | ||
| 180 | return 0; | ||
| 181 | |||
| 182 | event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, | ||
| 183 | sizeof(*entry), flags, pc); | ||
| 184 | if (!event) | ||
| 185 | return 0; | ||
| 186 | entry = ring_buffer_event_data(event); | ||
| 187 | entry->graph_ent = *trace; | ||
| 188 | if (!filter_current_check_discard(buffer, call, entry, event)) | ||
| 189 | ring_buffer_unlock_commit(buffer, event); | ||
| 190 | |||
| 191 | return 1; | ||
| 192 | } | ||
| 193 | |||
| 194 | int trace_graph_entry(struct ftrace_graph_ent *trace) | ||
| 195 | { | ||
| 196 | struct trace_array *tr = graph_array; | ||
| 197 | struct trace_array_cpu *data; | ||
| 198 | unsigned long flags; | ||
| 199 | long disabled; | ||
| 200 | int ret; | ||
| 201 | int cpu; | ||
| 202 | int pc; | ||
| 203 | |||
| 204 | if (unlikely(!tr)) | ||
| 205 | return 0; | ||
| 206 | |||
| 207 | if (!ftrace_trace_task(current)) | ||
| 208 | return 0; | ||
| 209 | |||
| 210 | if (!ftrace_graph_addr(trace->func)) | ||
| 211 | return 0; | ||
| 212 | |||
| 213 | local_irq_save(flags); | ||
| 214 | cpu = raw_smp_processor_id(); | ||
| 215 | data = tr->data[cpu]; | ||
| 216 | disabled = atomic_inc_return(&data->disabled); | ||
| 217 | if (likely(disabled == 1)) { | ||
| 218 | pc = preempt_count(); | ||
| 219 | ret = __trace_graph_entry(tr, trace, flags, pc); | ||
| 220 | } else { | ||
| 221 | ret = 0; | ||
| 222 | } | ||
| 223 | /* Only do the atomic if it is not already set */ | ||
| 224 | if (!test_tsk_trace_graph(current)) | ||
| 225 | set_tsk_trace_graph(current); | ||
| 226 | |||
| 227 | atomic_dec(&data->disabled); | ||
| 228 | local_irq_restore(flags); | ||
| 229 | |||
| 230 | return ret; | ||
| 231 | } | ||
| 232 | |||
| 233 | static void __trace_graph_return(struct trace_array *tr, | ||
| 234 | struct ftrace_graph_ret *trace, | ||
| 235 | unsigned long flags, | ||
| 236 | int pc) | ||
| 237 | { | ||
| 238 | struct ftrace_event_call *call = &event_funcgraph_exit; | ||
| 239 | struct ring_buffer_event *event; | ||
| 240 | struct ring_buffer *buffer = tr->buffer; | ||
| 241 | struct ftrace_graph_ret_entry *entry; | ||
| 242 | |||
| 243 | if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled)))) | ||
| 244 | return; | ||
| 245 | |||
| 246 | event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET, | ||
| 247 | sizeof(*entry), flags, pc); | ||
| 248 | if (!event) | ||
| 249 | return; | ||
| 250 | entry = ring_buffer_event_data(event); | ||
| 251 | entry->ret = *trace; | ||
| 252 | if (!filter_current_check_discard(buffer, call, entry, event)) | ||
| 253 | ring_buffer_unlock_commit(buffer, event); | ||
| 254 | } | ||
| 255 | |||
| 256 | void trace_graph_return(struct ftrace_graph_ret *trace) | ||
| 257 | { | ||
| 258 | struct trace_array *tr = graph_array; | ||
| 259 | struct trace_array_cpu *data; | ||
| 260 | unsigned long flags; | ||
| 261 | long disabled; | ||
| 262 | int cpu; | ||
| 263 | int pc; | ||
| 264 | |||
| 265 | local_irq_save(flags); | ||
| 266 | cpu = raw_smp_processor_id(); | ||
| 267 | data = tr->data[cpu]; | ||
| 268 | disabled = atomic_inc_return(&data->disabled); | ||
| 269 | if (likely(disabled == 1)) { | ||
| 270 | pc = preempt_count(); | ||
| 271 | __trace_graph_return(tr, trace, flags, pc); | ||
| 272 | } | ||
| 273 | if (!trace->depth) | ||
| 274 | clear_tsk_trace_graph(current); | ||
| 275 | atomic_dec(&data->disabled); | ||
| 276 | local_irq_restore(flags); | ||
| 277 | } | ||
| 278 | |||
| 169 | static int graph_trace_init(struct trace_array *tr) | 279 | static int graph_trace_init(struct trace_array *tr) |
| 170 | { | 280 | { |
| 171 | int ret = register_ftrace_graph(&trace_graph_return, | 281 | int ret; |
| 172 | &trace_graph_entry); | 282 | |
| 283 | graph_array = tr; | ||
| 284 | ret = register_ftrace_graph(&trace_graph_return, | ||
| 285 | &trace_graph_entry); | ||
| 173 | if (ret) | 286 | if (ret) |
| 174 | return ret; | 287 | return ret; |
| 175 | tracing_start_cmdline_record(); | 288 | tracing_start_cmdline_record(); |
| @@ -177,49 +290,30 @@ static int graph_trace_init(struct trace_array *tr) | |||
| 177 | return 0; | 290 | return 0; |
| 178 | } | 291 | } |
| 179 | 292 | ||
| 293 | void set_graph_array(struct trace_array *tr) | ||
| 294 | { | ||
| 295 | graph_array = tr; | ||
| 296 | } | ||
| 297 | |||
| 180 | static void graph_trace_reset(struct trace_array *tr) | 298 | static void graph_trace_reset(struct trace_array *tr) |
| 181 | { | 299 | { |
| 182 | tracing_stop_cmdline_record(); | 300 | tracing_stop_cmdline_record(); |
| 183 | unregister_ftrace_graph(); | 301 | unregister_ftrace_graph(); |
| 184 | } | 302 | } |
| 185 | 303 | ||
| 186 | static inline int log10_cpu(int nb) | 304 | static int max_bytes_for_cpu; |
| 187 | { | ||
| 188 | if (nb / 100) | ||
| 189 | return 3; | ||
| 190 | if (nb / 10) | ||
| 191 | return 2; | ||
| 192 | return 1; | ||
| 193 | } | ||
| 194 | 305 | ||
| 195 | static enum print_line_t | 306 | static enum print_line_t |
| 196 | print_graph_cpu(struct trace_seq *s, int cpu) | 307 | print_graph_cpu(struct trace_seq *s, int cpu) |
| 197 | { | 308 | { |
| 198 | int i; | ||
| 199 | int ret; | 309 | int ret; |
| 200 | int log10_this = log10_cpu(cpu); | ||
| 201 | int log10_all = log10_cpu(cpumask_weight(cpu_online_mask)); | ||
| 202 | |||
| 203 | 310 | ||
| 204 | /* | 311 | /* |
| 205 | * Start with a space character - to make it stand out | 312 | * Start with a space character - to make it stand out |
| 206 | * to the right a bit when trace output is pasted into | 313 | * to the right a bit when trace output is pasted into |
| 207 | * email: | 314 | * email: |
| 208 | */ | 315 | */ |
| 209 | ret = trace_seq_printf(s, " "); | 316 | ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu); |
| 210 | |||
| 211 | /* | ||
| 212 | * Tricky - we space the CPU field according to the max | ||
| 213 | * number of online CPUs. On a 2-cpu system it would take | ||
| 214 | * a maximum of 1 digit - on a 128 cpu system it would | ||
| 215 | * take up to 3 digits: | ||
| 216 | */ | ||
| 217 | for (i = 0; i < log10_all - log10_this; i++) { | ||
| 218 | ret = trace_seq_printf(s, " "); | ||
| 219 | if (!ret) | ||
| 220 | return TRACE_TYPE_PARTIAL_LINE; | ||
| 221 | } | ||
| 222 | ret = trace_seq_printf(s, "%d) ", cpu); | ||
| 223 | if (!ret) | 317 | if (!ret) |
| 224 | return TRACE_TYPE_PARTIAL_LINE; | 318 | return TRACE_TYPE_PARTIAL_LINE; |
| 225 | 319 | ||
| @@ -270,6 +364,15 @@ print_graph_proc(struct trace_seq *s, pid_t pid) | |||
| 270 | } | 364 | } |
| 271 | 365 | ||
| 272 | 366 | ||
| 367 | static enum print_line_t | ||
| 368 | print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry) | ||
| 369 | { | ||
| 370 | if (!trace_seq_putc(s, ' ')) | ||
| 371 | return 0; | ||
| 372 | |||
| 373 | return trace_print_lat_fmt(s, entry); | ||
| 374 | } | ||
| 375 | |||
| 273 | /* If the pid changed since the last trace, output this event */ | 376 | /* If the pid changed since the last trace, output this event */ |
| 274 | static enum print_line_t | 377 | static enum print_line_t |
| 275 | verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data) | 378 | verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data) |
| @@ -427,6 +530,7 @@ print_graph_irq(struct trace_iterator *iter, unsigned long addr, | |||
| 427 | if (ret == TRACE_TYPE_PARTIAL_LINE) | 530 | if (ret == TRACE_TYPE_PARTIAL_LINE) |
| 428 | return TRACE_TYPE_PARTIAL_LINE; | 531 | return TRACE_TYPE_PARTIAL_LINE; |
| 429 | } | 532 | } |
| 533 | |||
| 430 | /* Proc */ | 534 | /* Proc */ |
| 431 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) { | 535 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) { |
| 432 | ret = print_graph_proc(s, pid); | 536 | ret = print_graph_proc(s, pid); |
| @@ -565,11 +669,7 @@ print_graph_entry_leaf(struct trace_iterator *iter, | |||
| 565 | return TRACE_TYPE_PARTIAL_LINE; | 669 | return TRACE_TYPE_PARTIAL_LINE; |
| 566 | } | 670 | } |
| 567 | 671 | ||
| 568 | ret = seq_print_ip_sym(s, call->func, 0); | 672 | ret = trace_seq_printf(s, "%ps();\n", (void *)call->func); |
| 569 | if (!ret) | ||
| 570 | return TRACE_TYPE_PARTIAL_LINE; | ||
| 571 | |||
| 572 | ret = trace_seq_printf(s, "();\n"); | ||
| 573 | if (!ret) | 673 | if (!ret) |
| 574 | return TRACE_TYPE_PARTIAL_LINE; | 674 | return TRACE_TYPE_PARTIAL_LINE; |
| 575 | 675 | ||
| @@ -612,11 +712,7 @@ print_graph_entry_nested(struct trace_iterator *iter, | |||
| 612 | return TRACE_TYPE_PARTIAL_LINE; | 712 | return TRACE_TYPE_PARTIAL_LINE; |
| 613 | } | 713 | } |
| 614 | 714 | ||
| 615 | ret = seq_print_ip_sym(s, call->func, 0); | 715 | ret = trace_seq_printf(s, "%ps() {\n", (void *)call->func); |
| 616 | if (!ret) | ||
| 617 | return TRACE_TYPE_PARTIAL_LINE; | ||
| 618 | |||
| 619 | ret = trace_seq_printf(s, "() {\n"); | ||
| 620 | if (!ret) | 716 | if (!ret) |
| 621 | return TRACE_TYPE_PARTIAL_LINE; | 717 | return TRACE_TYPE_PARTIAL_LINE; |
| 622 | 718 | ||
| @@ -672,6 +768,13 @@ print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s, | |||
| 672 | return TRACE_TYPE_PARTIAL_LINE; | 768 | return TRACE_TYPE_PARTIAL_LINE; |
| 673 | } | 769 | } |
| 674 | 770 | ||
| 771 | /* Latency format */ | ||
| 772 | if (trace_flags & TRACE_ITER_LATENCY_FMT) { | ||
| 773 | ret = print_graph_lat_fmt(s, ent); | ||
| 774 | if (ret == TRACE_TYPE_PARTIAL_LINE) | ||
| 775 | return TRACE_TYPE_PARTIAL_LINE; | ||
| 776 | } | ||
| 777 | |||
| 675 | return 0; | 778 | return 0; |
| 676 | } | 779 | } |
| 677 | 780 | ||
| @@ -866,28 +969,59 @@ print_graph_function(struct trace_iterator *iter) | |||
| 866 | return TRACE_TYPE_HANDLED; | 969 | return TRACE_TYPE_HANDLED; |
| 867 | } | 970 | } |
| 868 | 971 | ||
| 972 | static void print_lat_header(struct seq_file *s) | ||
| 973 | { | ||
| 974 | static const char spaces[] = " " /* 16 spaces */ | ||
| 975 | " " /* 4 spaces */ | ||
| 976 | " "; /* 17 spaces */ | ||
| 977 | int size = 0; | ||
| 978 | |||
| 979 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) | ||
| 980 | size += 16; | ||
| 981 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) | ||
| 982 | size += 4; | ||
| 983 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) | ||
| 984 | size += 17; | ||
| 985 | |||
| 986 | seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces); | ||
| 987 | seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces); | ||
| 988 | seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces); | ||
| 989 | seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces); | ||
| 990 | seq_printf(s, "#%.*s||| / _-=> lock-depth \n", size, spaces); | ||
| 991 | seq_printf(s, "#%.*s|||| / \n", size, spaces); | ||
| 992 | } | ||
| 993 | |||
| 869 | static void print_graph_headers(struct seq_file *s) | 994 | static void print_graph_headers(struct seq_file *s) |
| 870 | { | 995 | { |
| 996 | int lat = trace_flags & TRACE_ITER_LATENCY_FMT; | ||
| 997 | |||
| 998 | if (lat) | ||
| 999 | print_lat_header(s); | ||
| 1000 | |||
| 871 | /* 1st line */ | 1001 | /* 1st line */ |
| 872 | seq_printf(s, "# "); | 1002 | seq_printf(s, "#"); |
| 873 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) | 1003 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) |
| 874 | seq_printf(s, " TIME "); | 1004 | seq_printf(s, " TIME "); |
| 875 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) | 1005 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) |
| 876 | seq_printf(s, "CPU"); | 1006 | seq_printf(s, " CPU"); |
| 877 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) | 1007 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) |
| 878 | seq_printf(s, " TASK/PID "); | 1008 | seq_printf(s, " TASK/PID "); |
| 1009 | if (lat) | ||
| 1010 | seq_printf(s, "|||||"); | ||
| 879 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) | 1011 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) |
| 880 | seq_printf(s, " DURATION "); | 1012 | seq_printf(s, " DURATION "); |
| 881 | seq_printf(s, " FUNCTION CALLS\n"); | 1013 | seq_printf(s, " FUNCTION CALLS\n"); |
| 882 | 1014 | ||
| 883 | /* 2nd line */ | 1015 | /* 2nd line */ |
| 884 | seq_printf(s, "# "); | 1016 | seq_printf(s, "#"); |
| 885 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) | 1017 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) |
| 886 | seq_printf(s, " | "); | 1018 | seq_printf(s, " | "); |
| 887 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) | 1019 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) |
| 888 | seq_printf(s, "| "); | 1020 | seq_printf(s, " | "); |
| 889 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) | 1021 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) |
| 890 | seq_printf(s, " | | "); | 1022 | seq_printf(s, " | | "); |
| 1023 | if (lat) | ||
| 1024 | seq_printf(s, "|||||"); | ||
| 891 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) | 1025 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) |
| 892 | seq_printf(s, " | | "); | 1026 | seq_printf(s, " | | "); |
| 893 | seq_printf(s, " | | | |\n"); | 1027 | seq_printf(s, " | | | |\n"); |
| @@ -934,6 +1068,8 @@ static struct tracer graph_trace __read_mostly = { | |||
| 934 | 1068 | ||
| 935 | static __init int init_graph_trace(void) | 1069 | static __init int init_graph_trace(void) |
| 936 | { | 1070 | { |
| 1071 | max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); | ||
| 1072 | |||
| 937 | return register_tracer(&graph_trace); | 1073 | return register_tracer(&graph_trace); |
| 938 | } | 1074 | } |
| 939 | 1075 | ||
