diff options
author | Artem Bityutskiy <Artem.Bityutskiy@nokia.com> | 2009-09-21 05:09:22 -0400 |
---|---|---|
committer | Artem Bityutskiy <Artem.Bityutskiy@nokia.com> | 2009-09-21 05:09:22 -0400 |
commit | 7cce2f4cb7f5f641f78c8e3eea4e7b1b96cb71c0 (patch) | |
tree | b064d077928cf224660ab1e1841cdab2c9fd8b08 /kernel/trace/trace_functions_graph.c | |
parent | e055f7e873d900925c222cf2d1ec955af4a9ca90 (diff) | |
parent | ebc79c4f8da0f92efa968e0328f32334a2ce80cf (diff) |
Merge branch 'master' of git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux-2.6 into linux-next
Conflicts:
fs/ubifs/super.c
Merge the upstream tree in order to resolve a conflict with the
per-bdi writeback changes from the linux-2.6-block tree.
Diffstat (limited to 'kernel/trace/trace_functions_graph.c')
-rw-r--r-- | kernel/trace/trace_functions_graph.c | 239 |
1 files changed, 191 insertions, 48 deletions
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c index d2249abafb53..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 | ||
@@ -843,9 +946,16 @@ print_graph_function(struct trace_iterator *iter) | |||
843 | 946 | ||
844 | switch (entry->type) { | 947 | switch (entry->type) { |
845 | case TRACE_GRAPH_ENT: { | 948 | case TRACE_GRAPH_ENT: { |
846 | struct ftrace_graph_ent_entry *field; | 949 | /* |
950 | * print_graph_entry() may consume the current event, | ||
951 | * thus @field may become invalid, so we need to save it. | ||
952 | * sizeof(struct ftrace_graph_ent_entry) is very small, | ||
953 | * it can be safely saved at the stack. | ||
954 | */ | ||
955 | struct ftrace_graph_ent_entry *field, saved; | ||
847 | trace_assign_type(field, entry); | 956 | trace_assign_type(field, entry); |
848 | return print_graph_entry(field, s, iter); | 957 | saved = *field; |
958 | return print_graph_entry(&saved, s, iter); | ||
849 | } | 959 | } |
850 | case TRACE_GRAPH_RET: { | 960 | case TRACE_GRAPH_RET: { |
851 | struct ftrace_graph_ret_entry *field; | 961 | struct ftrace_graph_ret_entry *field; |
@@ -859,28 +969,59 @@ print_graph_function(struct trace_iterator *iter) | |||
859 | return TRACE_TYPE_HANDLED; | 969 | return TRACE_TYPE_HANDLED; |
860 | } | 970 | } |
861 | 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 | |||
862 | static void print_graph_headers(struct seq_file *s) | 994 | static void print_graph_headers(struct seq_file *s) |
863 | { | 995 | { |
996 | int lat = trace_flags & TRACE_ITER_LATENCY_FMT; | ||
997 | |||
998 | if (lat) | ||
999 | print_lat_header(s); | ||
1000 | |||
864 | /* 1st line */ | 1001 | /* 1st line */ |
865 | seq_printf(s, "# "); | 1002 | seq_printf(s, "#"); |
866 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) | 1003 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) |
867 | seq_printf(s, " TIME "); | 1004 | seq_printf(s, " TIME "); |
868 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) | 1005 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) |
869 | seq_printf(s, "CPU"); | 1006 | seq_printf(s, " CPU"); |
870 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) | 1007 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) |
871 | seq_printf(s, " TASK/PID "); | 1008 | seq_printf(s, " TASK/PID "); |
1009 | if (lat) | ||
1010 | seq_printf(s, "|||||"); | ||
872 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) | 1011 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) |
873 | seq_printf(s, " DURATION "); | 1012 | seq_printf(s, " DURATION "); |
874 | seq_printf(s, " FUNCTION CALLS\n"); | 1013 | seq_printf(s, " FUNCTION CALLS\n"); |
875 | 1014 | ||
876 | /* 2nd line */ | 1015 | /* 2nd line */ |
877 | seq_printf(s, "# "); | 1016 | seq_printf(s, "#"); |
878 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) | 1017 | if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) |
879 | seq_printf(s, " | "); | 1018 | seq_printf(s, " | "); |
880 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) | 1019 | if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) |
881 | seq_printf(s, "| "); | 1020 | seq_printf(s, " | "); |
882 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) | 1021 | if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) |
883 | seq_printf(s, " | | "); | 1022 | seq_printf(s, " | | "); |
1023 | if (lat) | ||
1024 | seq_printf(s, "|||||"); | ||
884 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) | 1025 | if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION) |
885 | seq_printf(s, " | | "); | 1026 | seq_printf(s, " | | "); |
886 | seq_printf(s, " | | | |\n"); | 1027 | seq_printf(s, " | | | |\n"); |
@@ -927,6 +1068,8 @@ static struct tracer graph_trace __read_mostly = { | |||
927 | 1068 | ||
928 | static __init int init_graph_trace(void) | 1069 | static __init int init_graph_trace(void) |
929 | { | 1070 | { |
1071 | max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); | ||
1072 | |||
930 | return register_tracer(&graph_trace); | 1073 | return register_tracer(&graph_trace); |
931 | } | 1074 | } |
932 | 1075 | ||