1 // SPDX-License-Identifier: LGPL-2.1
2 /*
3 * Copyright (C) 2009, 2010 Red Hat Inc, Steven Rostedt <srostedt@redhat.com>
4 *
5 */
6 #include <stdio.h>
7 #include <stdlib.h>
8 #include <string.h>
9 #include <sys/param.h>
10
11 #include "trace-cmd-private.h"
12
13 #define MAX_LINUX_ERRNO 4095
14 #define IS_LINUX_ERR_VALUE(x) ((unsigned long long)(void *)(x) >= (unsigned long long)-MAX_LINUX_ERRNO)
15
16 struct tep_plugin_option trace_ftrace_options[] = {
17 {
18 .name = "tailprint",
19 .plugin_alias = "fgraph",
20 .description =
21 "Print function name at function exit in function graph",
22 },
23 {
24 .name = "depth",
25 .plugin_alias = "fgraph",
26 .description =
27 "Show the depth of each entry",
28 },
29 {
30 .name = "retval-skip",
31 .plugin_alias = "fgraph",
32 .description =
33 "Skip printing function retval in function graph",
34 },
35 {
36 .name = "retval-dec",
37 .plugin_alias = "fgraph",
38 .description =
39 "Print function retval in decimal at function exit in function graph",
40 },
41 {
42 .name = "retval-hex",
43 .plugin_alias = "fgraph",
44 .description =
45 "Print function retval in hex at function exit in function graph",
46 },
47 {
48 .name = NULL,
49 }
50 };
51
52 static struct tep_plugin_option *fgraph_tail = &trace_ftrace_options[0];
53 static struct tep_plugin_option *fgraph_depth = &trace_ftrace_options[1];
54 static struct tep_plugin_option *fgraph_retval_skip = &trace_ftrace_options[2];
55 static struct tep_plugin_option *fgraph_retval_dec = &trace_ftrace_options[3];
56 static struct tep_plugin_option *fgraph_retval_hex = &trace_ftrace_options[4];
57
find_ret_event(struct tracecmd_ftrace * finfo,struct tep_handle * pevent)58 static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
59 {
60 struct tep_event *event;
61
62 /* Store the func ret id and event for later use */
63 event = tep_find_event_by_name(pevent, "ftrace", "funcgraph_exit");
64 if (!event)
65 return -1;
66
67 finfo->fgraph_ret_id = event->id;
68 finfo->fgraph_ret_event = event;
69 return 0;
70 }
71
72 #define ret_event_check(finfo, pevent) \
73 do { \
74 if (!finfo->fgraph_ret_event && find_ret_event(finfo, pevent) < 0) \
75 return -1; \
76 } while (0)
77
function_handler(struct trace_seq * s,struct tep_record * record,struct tep_event * event,void * context)78 static int function_handler(struct trace_seq *s, struct tep_record *record,
79 struct tep_event *event, void *context)
80 {
81 struct tep_handle *pevent = event->tep;
82 unsigned long long function;
83 const char *func;
84
85 if (tep_get_field_val(s, event, "ip", record, &function, 1))
86 return trace_seq_putc(s, '!');
87
88 func = tep_find_function(pevent, function);
89 if (func)
90 trace_seq_printf(s, "%s <-- ", func);
91 else
92 trace_seq_printf(s, "0x%llx", function);
93
94 if (tep_get_field_val(s, event, "parent_ip", record, &function, 1))
95 return trace_seq_putc(s, '!');
96
97 func = tep_find_function(pevent, function);
98 if (func)
99 trace_seq_printf(s, "%s", func);
100 else
101 trace_seq_printf(s, "0x%llx", function);
102
103 return 0;
104 }
105
106 #define TRACE_GRAPH_INDENT 2
107
108 static struct tep_record *
get_return_for_leaf(struct trace_seq * s,int cpu,int cur_pid,unsigned long long cur_func,struct tep_record * next,struct tracecmd_ftrace * finfo)109 get_return_for_leaf(struct trace_seq *s, int cpu, int cur_pid,
110 unsigned long long cur_func, struct tep_record *next,
111 struct tracecmd_ftrace *finfo)
112 {
113 unsigned long long val;
114 unsigned long long type;
115 unsigned long long pid;
116
117 /* Searching a common field, can use any event */
118 if (tep_get_common_field_val(s, finfo->fgraph_ret_event, "common_type", next, &type, 1))
119 return NULL;
120
121 if (type != finfo->fgraph_ret_id)
122 return NULL;
123
124 if (tep_get_common_field_val(s, finfo->fgraph_ret_event, "common_pid", next, &pid, 1))
125 return NULL;
126
127 if (cur_pid != pid)
128 return NULL;
129
130 /* We aleady know this is a funcgraph_ret_event */
131 if (tep_get_field_val(s, finfo->fgraph_ret_event, "func", next, &val, 1))
132 return NULL;
133
134 if (cur_func != val)
135 return NULL;
136
137 /* this is a leaf, now advance the iterator */
138 return tracecmd_read_data(tracecmd_curr_thread_handle, cpu);
139 }
140
141 /* Signal a overhead of time execution to the output */
print_graph_overhead(struct trace_seq * s,unsigned long long duration)142 static void print_graph_overhead(struct trace_seq *s,
143 unsigned long long duration)
144 {
145 /* Non nested entry or return */
146 if (duration == ~0ULL)
147 return (void)trace_seq_printf(s, " ");
148
149 /* Duration exceeded 1 sec */
150 if (duration > 1000000000ULL)
151 return (void)trace_seq_printf(s, "$ ");
152
153 /* Duration exceeded 1000 usecs */
154 if (duration > 1000000ULL)
155 return (void)trace_seq_printf(s, "# ");
156
157 /* Duration exceeded 100 usecs */
158 if (duration > 100000ULL)
159 return (void)trace_seq_printf(s, "! ");
160
161 /* Duration exceeded 10 usecs */
162 if (duration > 10000ULL)
163 return (void)trace_seq_printf(s, "+ ");
164
165 trace_seq_printf(s, " ");
166 }
167
print_graph_duration(struct trace_seq * s,unsigned long long duration)168 static void print_graph_duration(struct trace_seq *s, unsigned long long duration)
169 {
170 unsigned long usecs = duration / 1000;
171 unsigned long nsecs_rem = duration % 1000;
172 /* log10(ULONG_MAX) + '\0' */
173 char msecs_str[21];
174 char nsecs_str[5];
175 int len;
176 int i;
177
178 sprintf(msecs_str, "%lu", usecs);
179
180 /* Print msecs */
181 len = s->len;
182 trace_seq_printf(s, "%lu", usecs);
183
184 /* Print nsecs (we don't want to exceed 7 numbers) */
185 if ((s->len - len) < 7) {
186 snprintf(nsecs_str, MIN(sizeof(nsecs_str), 8 - len), "%03lu", nsecs_rem);
187 trace_seq_printf(s, ".%s", nsecs_str);
188 }
189
190 len = s->len - len;
191
192 trace_seq_puts(s, " us ");
193
194 /* Print remaining spaces to fit the row's width */
195 for (i = len; i < 7; i++)
196 trace_seq_putc(s, ' ');
197
198 trace_seq_puts(s, "| ");
199 }
200
201 static int
print_graph_entry_leaf(struct trace_seq * s,struct tep_event * event,struct tep_record * record,struct tep_record * ret_rec,struct tracecmd_ftrace * finfo)202 print_graph_entry_leaf(struct trace_seq *s,
203 struct tep_event *event,
204 struct tep_record *record,
205 struct tep_record *ret_rec,
206 struct tracecmd_ftrace *finfo)
207 {
208 struct tep_handle *pevent = event->tep;
209 unsigned long long rettime, calltime;
210 unsigned long long duration, depth;
211 unsigned long long val;
212 unsigned long long retval;
213 bool fgraph_retval_supported = true;
214 const char *func;
215 int ret;
216 int i;
217
218 if (tep_get_field_val(s, finfo->fgraph_ret_event, "rettime", ret_rec, &rettime, 1))
219 return trace_seq_putc(s, '!');
220
221 if (tep_get_field_val(s, finfo->fgraph_ret_event, "calltime", ret_rec, &calltime, 1))
222 return trace_seq_putc(s, '!');
223
224 if (!tep_find_field(finfo->fgraph_ret_event, "retval")) {
225 fgraph_retval_supported = false;
226 } else {
227 if (tep_get_field_val(s, finfo->fgraph_ret_event, "retval", ret_rec, &retval, 1))
228 return trace_seq_putc(s, '!');
229 }
230
231 duration = rettime - calltime;
232
233 /* Overhead */
234 print_graph_overhead(s, duration);
235
236 /* Duration */
237 print_graph_duration(s, duration);
238
239 if (tep_get_field_val(s, event, "depth", record, &depth, 1))
240 return trace_seq_putc(s, '!');
241
242 /* Function */
243 for (i = 0; i < (int)(depth * TRACE_GRAPH_INDENT); i++)
244 trace_seq_putc(s, ' ');
245
246 if (tep_get_field_val(s, event, "func", record, &val, 1))
247 return trace_seq_putc(s, '!');
248 func = tep_find_function(pevent, val);
249
250 if (func)
251 ret = trace_seq_printf(s, "%s();", func);
252 else
253 ret = trace_seq_printf(s, "%llx();", val);
254
255 if (ret && fgraph_depth->set)
256 ret = trace_seq_printf(s, " (%lld)", depth);
257
258 /* Return Value */
259 if (ret && fgraph_retval_supported && !fgraph_retval_skip->set) {
260 if (fgraph_retval_dec->set) {
261 ret = trace_seq_printf(s, " (ret=%lld)", retval);
262 } else if (fgraph_retval_hex->set) {
263 ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
264 } else {
265 /* Error codes are in decimal; others are in hex */
266 if (!IS_LINUX_ERR_VALUE(retval))
267 ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
268 else
269 ret = trace_seq_printf(s, " (ret=%lld)", retval);
270 }
271 }
272
273 return ret;
274 }
275
print_graph_nested(struct trace_seq * s,struct tep_event * event,struct tep_record * record)276 static int print_graph_nested(struct trace_seq *s,
277 struct tep_event *event,
278 struct tep_record *record)
279 {
280 struct tep_handle *pevent = event->tep;
281 unsigned long long depth;
282 unsigned long long val;
283 const char *func;
284 int ret;
285 int i;
286
287 /* No overhead */
288 print_graph_overhead(s, -1);
289
290 /* No time */
291 trace_seq_puts(s, " | ");
292
293 if (tep_get_field_val(s, event, "depth", record, &depth, 1))
294 return trace_seq_putc(s, '!');
295
296 /* Function */
297 for (i = 0; i < (int)(depth * TRACE_GRAPH_INDENT); i++)
298 trace_seq_putc(s, ' ');
299
300 if (tep_get_field_val(s, event, "func", record, &val, 1))
301 return trace_seq_putc(s, '!');
302
303 func = tep_find_function(pevent, val);
304
305 if (func)
306 ret = trace_seq_printf(s, "%s() {", func);
307 else
308 ret = trace_seq_printf(s, "%llx() {", val);
309
310 if (ret && fgraph_depth->set)
311 ret = trace_seq_printf(s, " (%lld)", depth);
312
313 return ret;
314 }
315
316 static int
fgraph_ent_handler(struct trace_seq * s,struct tep_record * record,struct tep_event * event,void * context)317 fgraph_ent_handler(struct trace_seq *s, struct tep_record *record,
318 struct tep_event *event, void *context)
319 {
320 struct tracecmd_ftrace *finfo = context;
321 struct tep_record *rec;
322 unsigned long long val, pid;
323 int cpu;
324
325 ret_event_check(finfo, event->tep);
326
327 if (tep_get_common_field_val(s, event, "common_pid", record, &pid, 1))
328 return trace_seq_putc(s, '!');
329
330 if (tep_get_field_val(s, event, "func", record, &val, 1))
331 return trace_seq_putc(s, '!');
332
333 rec = tracecmd_peek_next_data(tracecmd_curr_thread_handle, &cpu);
334
335 /*
336 * If the next event is on another CPU, show it.
337 * Even if the next event is the return of this function.
338 */
339 if (cpu != record->cpu)
340 rec = NULL;
341
342 if (rec)
343 rec = get_return_for_leaf(s, cpu, pid, val, rec, finfo);
344
345 if (rec) {
346 /*
347 * If this is a leaf function, then get_return_for_leaf
348 * returns the return of the function
349 */
350 print_graph_entry_leaf(s, event, record, rec, finfo);
351 tracecmd_free_record(rec);
352 } else
353 print_graph_nested(s, event, record);
354
355 return 0;
356 }
357
358 static int
fgraph_ret_handler(struct trace_seq * s,struct tep_record * record,struct tep_event * event,void * context)359 fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
360 struct tep_event *event, void *context)
361 {
362 struct tracecmd_ftrace *finfo = context;
363 unsigned long long rettime, calltime;
364 unsigned long long duration, depth;
365 unsigned long long val;
366 const char *func;
367 unsigned long long retval;
368 bool fgraph_retval_supported = true;
369 int i;
370
371 ret_event_check(finfo, event->tep);
372
373 if (tep_get_field_val(s, event, "rettime", record, &rettime, 1))
374 return trace_seq_putc(s, '!');
375
376 if (tep_get_field_val(s, event, "calltime", record, &calltime, 1))
377 return trace_seq_putc(s, '!');
378
379 if (!tep_find_field(event, "retval")) {
380 fgraph_retval_supported = false;
381 } else {
382 if (tep_get_field_val(s, event, "retval", record, &retval, 1))
383 return trace_seq_putc(s, '!');
384 }
385
386 duration = rettime - calltime;
387
388 /* Overhead */
389 print_graph_overhead(s, duration);
390
391 /* Duration */
392 print_graph_duration(s, duration);
393
394 if (tep_get_field_val(s, event, "depth", record, &depth, 1))
395 return trace_seq_putc(s, '!');
396
397 /* Function */
398 for (i = 0; i < (int)(depth * TRACE_GRAPH_INDENT); i++)
399 trace_seq_putc(s, ' ');
400
401 trace_seq_putc(s, '}');
402
403 if (fgraph_tail->set) {
404 if (tep_get_field_val(s, event, "func", record, &val, 0))
405 return 0;
406 func = tep_find_function(event->tep, val);
407 if (!func)
408 return 0;
409 trace_seq_printf(s, " /* %s */", func);
410 }
411
412 if (fgraph_depth->set)
413 trace_seq_printf(s, " (%lld)", depth);
414
415 /* Return Value */
416 if (fgraph_retval_supported && !fgraph_retval_skip->set) {
417 if (fgraph_retval_dec->set) {
418 trace_seq_printf(s, " (ret=%lld)", retval);
419 } else if (fgraph_retval_hex->set) {
420 trace_seq_printf(s, " (ret=0x%llx)", retval);
421 } else {
422 /* Error codes are in decimal; others are in hex */
423 if (!IS_LINUX_ERR_VALUE(retval))
424 trace_seq_printf(s, " (ret=0x%llx)", retval);
425 else
426 trace_seq_printf(s, " (ret=%lld)", retval);
427 }
428 }
429
430 return 0;
431 }
432
433 /**
434 * tracecmd_ftrace_load_options - load the ftrace options
435 *
436 * This routine is used for trace-cmd list, to load the builtin
437 * ftrace options in order to list them. As the list command does
438 * not load a trace.dat file where this would normally be loaded.
439 */
tracecmd_ftrace_load_options(void)440 void tracecmd_ftrace_load_options(void)
441 {
442 tep_plugin_add_options("ftrace", trace_ftrace_options);
443 }
444
tracecmd_ftrace_overrides(struct tracecmd_input * handle,struct tracecmd_ftrace * finfo)445 int tracecmd_ftrace_overrides(struct tracecmd_input *handle,
446 struct tracecmd_ftrace *finfo)
447 {
448 struct tep_handle *pevent;
449 struct tep_event *event;
450
451 finfo->handle = handle;
452
453 pevent = tracecmd_get_tep(handle);
454
455 tep_register_event_handler(pevent, -1, "ftrace", "function",
456 function_handler, NULL);
457
458 tep_register_event_handler(pevent, -1, "ftrace", "funcgraph_entry",
459 fgraph_ent_handler, finfo);
460
461 tep_register_event_handler(pevent, -1, "ftrace", "funcgraph_exit",
462 fgraph_ret_handler, finfo);
463
464 tep_plugin_add_options("ftrace", trace_ftrace_options);
465
466 /* Store the func ret id and event for later use */
467 event = tep_find_event_by_name(pevent, "ftrace", "funcgraph_exit");
468 if (!event)
469 return 0;
470
471 finfo->long_size = tracecmd_long_size(handle);
472
473 finfo->fgraph_ret_id = event->id;
474 finfo->fgraph_ret_event = event;
475
476 return 0;
477 }
478