perf trace: Allow overiding the formatting of syscall fields
[linux-block.git] / tools / perf / builtin-trace.c
CommitLineData
4e319027 1#include <traceevent/event-parse.h>
514f1c67 2#include "builtin.h"
752fde44 3#include "util/color.h"
7c304ee0 4#include "util/debug.h"
514f1c67 5#include "util/evlist.h"
752fde44
ACM
6#include "util/machine.h"
7#include "util/thread.h"
514f1c67 8#include "util/parse-options.h"
2ae3a312 9#include "util/strlist.h"
514f1c67 10#include "util/thread_map.h"
514f1c67
ACM
11
12#include <libaudit.h>
13#include <stdlib.h>
14
13d4ff3e
ACM
15static size_t syscall_arg__scnprintf_hex(char *bf, size_t size, unsigned long arg)
16{
17 return scnprintf(bf, size, "%#lx", arg);
18}
19
beccb2b5
ACM
20#define SCA_HEX syscall_arg__scnprintf_hex
21
514f1c67
ACM
22static struct syscall_fmt {
23 const char *name;
aec1930b 24 const char *alias;
beccb2b5 25 size_t (*arg_scnprintf[6])(char *bf, size_t size, unsigned long arg);
514f1c67
ACM
26 bool errmsg;
27 bool timeout;
04b34729 28 bool hexret;
514f1c67 29} syscall_fmts[] = {
8b745263 30 { .name = "access", .errmsg = true, },
aec1930b 31 { .name = "arch_prctl", .errmsg = true, .alias = "prctl", },
beccb2b5
ACM
32 { .name = "brk", .hexret = true,
33 .arg_scnprintf = { [0] = SCA_HEX, /* brk */ }, },
04b34729 34 { .name = "mmap", .hexret = true, },
a14bb860 35 { .name = "connect", .errmsg = true, },
aec1930b
ACM
36 { .name = "fstat", .errmsg = true, .alias = "newfstat", },
37 { .name = "fstatat", .errmsg = true, .alias = "newfstatat", },
38 { .name = "futex", .errmsg = true, },
beccb2b5
ACM
39 { .name = "ioctl", .errmsg = true,
40 .arg_scnprintf = { [2] = SCA_HEX, /* arg */ }, },
e5959683 41 { .name = "lstat", .errmsg = true, .alias = "newlstat", },
beccb2b5
ACM
42 { .name = "mmap", .hexret = true,
43 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
44 { .name = "mprotect", .errmsg = true,
45 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
04b34729 46 { .name = "mremap", .hexret = true, },
beccb2b5
ACM
47 { .name = "munmap", .errmsg = true,
48 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
8b745263 49 { .name = "open", .errmsg = true, },
aec1930b
ACM
50 { .name = "poll", .errmsg = true, .timeout = true, },
51 { .name = "ppoll", .errmsg = true, .timeout = true, },
e5959683
ACM
52 { .name = "pread", .errmsg = true, .alias = "pread64", },
53 { .name = "pwrite", .errmsg = true, .alias = "pwrite64", },
aec1930b
ACM
54 { .name = "read", .errmsg = true, },
55 { .name = "recvfrom", .errmsg = true, },
56 { .name = "select", .errmsg = true, .timeout = true, },
8b745263 57 { .name = "socket", .errmsg = true, },
aec1930b 58 { .name = "stat", .errmsg = true, .alias = "newstat", },
e5959683 59 { .name = "uname", .errmsg = true, .alias = "newuname", },
514f1c67
ACM
60};
61
62static int syscall_fmt__cmp(const void *name, const void *fmtp)
63{
64 const struct syscall_fmt *fmt = fmtp;
65 return strcmp(name, fmt->name);
66}
67
68static struct syscall_fmt *syscall_fmt__find(const char *name)
69{
70 const int nmemb = ARRAY_SIZE(syscall_fmts);
71 return bsearch(name, syscall_fmts, nmemb, sizeof(struct syscall_fmt), syscall_fmt__cmp);
72}
73
74struct syscall {
75 struct event_format *tp_format;
76 const char *name;
2ae3a312 77 bool filtered;
514f1c67 78 struct syscall_fmt *fmt;
13d4ff3e 79 size_t (**arg_scnprintf)(char *bf, size_t size, unsigned long arg);
514f1c67
ACM
80};
81
60c907ab
ACM
82static size_t fprintf_duration(unsigned long t, FILE *fp)
83{
84 double duration = (double)t / NSEC_PER_MSEC;
85 size_t printed = fprintf(fp, "(");
86
87 if (duration >= 1.0)
88 printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration);
89 else if (duration >= 0.01)
90 printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration);
91 else
92 printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration);
c24ff998 93 return printed + fprintf(fp, "): ");
60c907ab
ACM
94}
95
752fde44
ACM
96struct thread_trace {
97 u64 entry_time;
98 u64 exit_time;
99 bool entry_pending;
efd5745e 100 unsigned long nr_events;
752fde44 101 char *entry_str;
1302d88e 102 double runtime_ms;
752fde44
ACM
103};
104
105static struct thread_trace *thread_trace__new(void)
106{
107 return zalloc(sizeof(struct thread_trace));
108}
109
c24ff998 110static struct thread_trace *thread__trace(struct thread *thread, FILE *fp)
752fde44 111{
efd5745e
ACM
112 struct thread_trace *ttrace;
113
752fde44
ACM
114 if (thread == NULL)
115 goto fail;
116
117 if (thread->priv == NULL)
118 thread->priv = thread_trace__new();
efd5745e 119
752fde44
ACM
120 if (thread->priv == NULL)
121 goto fail;
122
efd5745e
ACM
123 ttrace = thread->priv;
124 ++ttrace->nr_events;
125
126 return ttrace;
752fde44 127fail:
c24ff998 128 color_fprintf(fp, PERF_COLOR_RED,
752fde44
ACM
129 "WARNING: not enough memory, dropping samples!\n");
130 return NULL;
131}
132
514f1c67 133struct trace {
c24ff998 134 struct perf_tool tool;
514f1c67
ACM
135 int audit_machine;
136 struct {
137 int max;
138 struct syscall *table;
139 } syscalls;
140 struct perf_record_opts opts;
752fde44
ACM
141 struct machine host;
142 u64 base_time;
c24ff998 143 FILE *output;
efd5745e 144 unsigned long nr_events;
b059efdf
ACM
145 struct strlist *ev_qualifier;
146 bool not_ev_qualifier;
1302d88e 147 bool sched;
752fde44 148 bool multiple_threads;
ae9ed035 149 double duration_filter;
1302d88e 150 double runtime_ms;
514f1c67
ACM
151};
152
ae9ed035
ACM
153static bool trace__filter_duration(struct trace *trace, double t)
154{
155 return t < (trace->duration_filter * NSEC_PER_MSEC);
156}
157
752fde44
ACM
158static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
159{
160 double ts = (double)(tstamp - trace->base_time) / NSEC_PER_MSEC;
161
60c907ab 162 return fprintf(fp, "%10.3f ", ts);
752fde44
ACM
163}
164
f15eb531
NK
165static bool done = false;
166
167static void sig_handler(int sig __maybe_unused)
168{
169 done = true;
170}
171
752fde44 172static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
60c907ab 173 u64 duration, u64 tstamp, FILE *fp)
752fde44
ACM
174{
175 size_t printed = trace__fprintf_tstamp(trace, tstamp, fp);
60c907ab 176 printed += fprintf_duration(duration, fp);
752fde44
ACM
177
178 if (trace->multiple_threads)
38051234 179 printed += fprintf(fp, "%d ", thread->tid);
752fde44
ACM
180
181 return printed;
182}
183
c24ff998
ACM
184static int trace__process_event(struct trace *trace, struct machine *machine,
185 union perf_event *event)
752fde44
ACM
186{
187 int ret = 0;
188
189 switch (event->header.type) {
190 case PERF_RECORD_LOST:
c24ff998 191 color_fprintf(trace->output, PERF_COLOR_RED,
752fde44
ACM
192 "LOST %" PRIu64 " events!\n", event->lost.lost);
193 ret = machine__process_lost_event(machine, event);
194 default:
195 ret = machine__process_event(machine, event);
196 break;
197 }
198
199 return ret;
200}
201
c24ff998 202static int trace__tool_process(struct perf_tool *tool,
752fde44
ACM
203 union perf_event *event,
204 struct perf_sample *sample __maybe_unused,
205 struct machine *machine)
206{
c24ff998
ACM
207 struct trace *trace = container_of(tool, struct trace, tool);
208 return trace__process_event(trace, machine, event);
752fde44
ACM
209}
210
211static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
212{
213 int err = symbol__init();
214
215 if (err)
216 return err;
217
218 machine__init(&trace->host, "", HOST_KERNEL_ID);
219 machine__create_kernel_maps(&trace->host);
220
221 if (perf_target__has_task(&trace->opts.target)) {
c24ff998 222 err = perf_event__synthesize_thread_map(&trace->tool, evlist->threads,
752fde44
ACM
223 trace__tool_process,
224 &trace->host);
225 } else {
c24ff998 226 err = perf_event__synthesize_threads(&trace->tool, trace__tool_process,
752fde44
ACM
227 &trace->host);
228 }
229
230 if (err)
231 symbol__exit();
232
233 return err;
234}
235
13d4ff3e
ACM
236static int syscall__set_arg_fmts(struct syscall *sc)
237{
238 struct format_field *field;
239 int idx = 0;
240
241 sc->arg_scnprintf = calloc(sc->tp_format->format.nr_fields - 1, sizeof(void *));
242 if (sc->arg_scnprintf == NULL)
243 return -1;
244
245 for (field = sc->tp_format->format.fields->next; field; field = field->next) {
beccb2b5
ACM
246 if (sc->fmt && sc->fmt->arg_scnprintf[idx])
247 sc->arg_scnprintf[idx] = sc->fmt->arg_scnprintf[idx];
248 else if (field->flags & FIELD_IS_POINTER)
13d4ff3e
ACM
249 sc->arg_scnprintf[idx] = syscall_arg__scnprintf_hex;
250 ++idx;
251 }
252
253 return 0;
254}
255
514f1c67
ACM
256static int trace__read_syscall_info(struct trace *trace, int id)
257{
258 char tp_name[128];
259 struct syscall *sc;
3a531260
ACM
260 const char *name = audit_syscall_to_name(id, trace->audit_machine);
261
262 if (name == NULL)
263 return -1;
514f1c67
ACM
264
265 if (id > trace->syscalls.max) {
266 struct syscall *nsyscalls = realloc(trace->syscalls.table, (id + 1) * sizeof(*sc));
267
268 if (nsyscalls == NULL)
269 return -1;
270
271 if (trace->syscalls.max != -1) {
272 memset(nsyscalls + trace->syscalls.max + 1, 0,
273 (id - trace->syscalls.max) * sizeof(*sc));
274 } else {
275 memset(nsyscalls, 0, (id + 1) * sizeof(*sc));
276 }
277
278 trace->syscalls.table = nsyscalls;
279 trace->syscalls.max = id;
280 }
281
282 sc = trace->syscalls.table + id;
3a531260 283 sc->name = name;
2ae3a312 284
b059efdf
ACM
285 if (trace->ev_qualifier) {
286 bool in = strlist__find(trace->ev_qualifier, name) != NULL;
287
288 if (!(in ^ trace->not_ev_qualifier)) {
289 sc->filtered = true;
290 /*
291 * No need to do read tracepoint information since this will be
292 * filtered out.
293 */
294 return 0;
295 }
2ae3a312
ACM
296 }
297
3a531260 298 sc->fmt = syscall_fmt__find(sc->name);
514f1c67 299
aec1930b 300 snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name);
514f1c67 301 sc->tp_format = event_format__new("syscalls", tp_name);
aec1930b
ACM
302
303 if (sc->tp_format == NULL && sc->fmt && sc->fmt->alias) {
304 snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->fmt->alias);
305 sc->tp_format = event_format__new("syscalls", tp_name);
306 }
514f1c67 307
13d4ff3e
ACM
308 if (sc->tp_format == NULL)
309 return -1;
310
311 return syscall__set_arg_fmts(sc);
514f1c67
ACM
312}
313
752fde44
ACM
314static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
315 unsigned long *args)
514f1c67
ACM
316{
317 int i = 0;
318 size_t printed = 0;
319
320 if (sc->tp_format != NULL) {
321 struct format_field *field;
322
323 for (field = sc->tp_format->format.fields->next; field; field = field->next) {
752fde44 324 printed += scnprintf(bf + printed, size - printed,
13d4ff3e
ACM
325 "%s%s: ", printed ? ", " : "", field->name);
326
327 if (sc->arg_scnprintf && sc->arg_scnprintf[i])
328 printed += sc->arg_scnprintf[i](bf + printed, size - printed, args[i]);
329 else
330 printed += scnprintf(bf + printed, size - printed,
331 "%ld", args[i]);
332 ++i;
514f1c67
ACM
333 }
334 } else {
335 while (i < 6) {
752fde44
ACM
336 printed += scnprintf(bf + printed, size - printed,
337 "%sarg%d: %ld",
338 printed ? ", " : "", i, args[i]);
514f1c67
ACM
339 ++i;
340 }
341 }
342
343 return printed;
344}
345
ba3d7dee
ACM
346typedef int (*tracepoint_handler)(struct trace *trace, struct perf_evsel *evsel,
347 struct perf_sample *sample);
348
349static struct syscall *trace__syscall_info(struct trace *trace,
350 struct perf_evsel *evsel,
351 struct perf_sample *sample)
352{
353 int id = perf_evsel__intval(evsel, sample, "id");
354
355 if (id < 0) {
adaa18bf
ACM
356
357 /*
358 * XXX: Noticed on x86_64, reproduced as far back as 3.0.36, haven't tried
359 * before that, leaving at a higher verbosity level till that is
360 * explained. Reproduced with plain ftrace with:
361 *
362 * echo 1 > /t/events/raw_syscalls/sys_exit/enable
363 * grep "NR -1 " /t/trace_pipe
364 *
365 * After generating some load on the machine.
366 */
367 if (verbose > 1) {
368 static u64 n;
369 fprintf(trace->output, "Invalid syscall %d id, skipping (%s, %" PRIu64 ") ...\n",
370 id, perf_evsel__name(evsel), ++n);
371 }
ba3d7dee
ACM
372 return NULL;
373 }
374
375 if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL) &&
376 trace__read_syscall_info(trace, id))
377 goto out_cant_read;
378
379 if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL))
380 goto out_cant_read;
381
382 return &trace->syscalls.table[id];
383
384out_cant_read:
7c304ee0
ACM
385 if (verbose) {
386 fprintf(trace->output, "Problems reading syscall %d", id);
387 if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL)
388 fprintf(trace->output, "(%s)", trace->syscalls.table[id].name);
389 fputs(" information\n", trace->output);
390 }
ba3d7dee
ACM
391 return NULL;
392}
393
394static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
395 struct perf_sample *sample)
396{
752fde44 397 char *msg;
ba3d7dee 398 void *args;
752fde44 399 size_t printed = 0;
2ae3a312 400 struct thread *thread;
ba3d7dee 401 struct syscall *sc = trace__syscall_info(trace, evsel, sample);
2ae3a312
ACM
402 struct thread_trace *ttrace;
403
404 if (sc == NULL)
405 return -1;
ba3d7dee 406
2ae3a312
ACM
407 if (sc->filtered)
408 return 0;
409
410 thread = machine__findnew_thread(&trace->host, sample->tid);
c24ff998 411 ttrace = thread__trace(thread, trace->output);
2ae3a312 412 if (ttrace == NULL)
ba3d7dee
ACM
413 return -1;
414
415 args = perf_evsel__rawptr(evsel, sample, "args");
416 if (args == NULL) {
c24ff998 417 fprintf(trace->output, "Problems reading syscall arguments\n");
ba3d7dee
ACM
418 return -1;
419 }
420
752fde44
ACM
421 ttrace = thread->priv;
422
423 if (ttrace->entry_str == NULL) {
424 ttrace->entry_str = malloc(1024);
425 if (!ttrace->entry_str)
426 return -1;
427 }
428
429 ttrace->entry_time = sample->time;
430 msg = ttrace->entry_str;
431 printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);
432
433 printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed, args);
434
435 if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
ae9ed035 436 if (!trace->duration_filter) {
c24ff998
ACM
437 trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output);
438 fprintf(trace->output, "%-70s\n", ttrace->entry_str);
ae9ed035 439 }
752fde44
ACM
440 } else
441 ttrace->entry_pending = true;
ba3d7dee
ACM
442
443 return 0;
444}
445
446static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
447 struct perf_sample *sample)
448{
449 int ret;
60c907ab 450 u64 duration = 0;
2ae3a312 451 struct thread *thread;
ba3d7dee 452 struct syscall *sc = trace__syscall_info(trace, evsel, sample);
2ae3a312
ACM
453 struct thread_trace *ttrace;
454
455 if (sc == NULL)
456 return -1;
ba3d7dee 457
2ae3a312
ACM
458 if (sc->filtered)
459 return 0;
460
461 thread = machine__findnew_thread(&trace->host, sample->tid);
c24ff998 462 ttrace = thread__trace(thread, trace->output);
2ae3a312 463 if (ttrace == NULL)
ba3d7dee
ACM
464 return -1;
465
466 ret = perf_evsel__intval(evsel, sample, "ret");
467
752fde44
ACM
468 ttrace = thread->priv;
469
470 ttrace->exit_time = sample->time;
471
ae9ed035 472 if (ttrace->entry_time) {
60c907ab 473 duration = sample->time - ttrace->entry_time;
ae9ed035
ACM
474 if (trace__filter_duration(trace, duration))
475 goto out;
476 } else if (trace->duration_filter)
477 goto out;
60c907ab 478
c24ff998 479 trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output);
752fde44
ACM
480
481 if (ttrace->entry_pending) {
c24ff998 482 fprintf(trace->output, "%-70s", ttrace->entry_str);
752fde44 483 } else {
c24ff998
ACM
484 fprintf(trace->output, " ... [");
485 color_fprintf(trace->output, PERF_COLOR_YELLOW, "continued");
486 fprintf(trace->output, "]: %s()", sc->name);
752fde44
ACM
487 }
488
da3c9a44
ACM
489 if (sc->fmt == NULL) {
490signed_print:
491 fprintf(trace->output, ") = %d", ret);
492 } else if (ret < 0 && sc->fmt->errmsg) {
ba3d7dee
ACM
493 char bf[256];
494 const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
495 *e = audit_errno_to_name(-ret);
496
c24ff998 497 fprintf(trace->output, ") = -1 %s %s", e, emsg);
da3c9a44 498 } else if (ret == 0 && sc->fmt->timeout)
c24ff998 499 fprintf(trace->output, ") = 0 Timeout");
04b34729
ACM
500 else if (sc->fmt->hexret)
501 fprintf(trace->output, ") = %#x", ret);
ba3d7dee 502 else
da3c9a44 503 goto signed_print;
ba3d7dee 504
c24ff998 505 fputc('\n', trace->output);
ae9ed035 506out:
752fde44
ACM
507 ttrace->entry_pending = false;
508
ba3d7dee
ACM
509 return 0;
510}
511
1302d88e
ACM
512static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel,
513 struct perf_sample *sample)
514{
515 u64 runtime = perf_evsel__intval(evsel, sample, "runtime");
516 double runtime_ms = (double)runtime / NSEC_PER_MSEC;
517 struct thread *thread = machine__findnew_thread(&trace->host, sample->tid);
c24ff998 518 struct thread_trace *ttrace = thread__trace(thread, trace->output);
1302d88e
ACM
519
520 if (ttrace == NULL)
521 goto out_dump;
522
523 ttrace->runtime_ms += runtime_ms;
524 trace->runtime_ms += runtime_ms;
525 return 0;
526
527out_dump:
c24ff998 528 fprintf(trace->output, "%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n",
1302d88e
ACM
529 evsel->name,
530 perf_evsel__strval(evsel, sample, "comm"),
531 (pid_t)perf_evsel__intval(evsel, sample, "pid"),
532 runtime,
533 perf_evsel__intval(evsel, sample, "vruntime"));
534 return 0;
535}
536
f15eb531 537static int trace__run(struct trace *trace, int argc, const char **argv)
514f1c67 538{
334fe7a3 539 struct perf_evlist *evlist = perf_evlist__new();
ba3d7dee 540 struct perf_evsel *evsel;
efd5745e
ACM
541 int err = -1, i;
542 unsigned long before;
f15eb531 543 const bool forks = argc > 0;
514f1c67
ACM
544
545 if (evlist == NULL) {
c24ff998 546 fprintf(trace->output, "Not enough memory to run!\n");
514f1c67
ACM
547 goto out;
548 }
549
39876e7d
ACM
550 if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) ||
551 perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) {
c24ff998 552 fprintf(trace->output, "Couldn't read the raw_syscalls tracepoints information!\n");
514f1c67
ACM
553 goto out_delete_evlist;
554 }
555
1302d88e
ACM
556 if (trace->sched &&
557 perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime",
558 trace__sched_stat_runtime)) {
c24ff998 559 fprintf(trace->output, "Couldn't read the sched_stat_runtime tracepoint information!\n");
1302d88e
ACM
560 goto out_delete_evlist;
561 }
562
514f1c67
ACM
563 err = perf_evlist__create_maps(evlist, &trace->opts.target);
564 if (err < 0) {
c24ff998 565 fprintf(trace->output, "Problems parsing the target to trace, check your options!\n");
514f1c67
ACM
566 goto out_delete_evlist;
567 }
568
752fde44
ACM
569 err = trace__symbols_init(trace, evlist);
570 if (err < 0) {
c24ff998 571 fprintf(trace->output, "Problems initializing symbol libraries!\n");
3beb0861 572 goto out_delete_maps;
752fde44
ACM
573 }
574
f77a9518 575 perf_evlist__config(evlist, &trace->opts);
514f1c67 576
f15eb531
NK
577 signal(SIGCHLD, sig_handler);
578 signal(SIGINT, sig_handler);
579
580 if (forks) {
6ef73ec4 581 err = perf_evlist__prepare_workload(evlist, &trace->opts.target,
55e162ea 582 argv, false, false);
f15eb531 583 if (err < 0) {
c24ff998 584 fprintf(trace->output, "Couldn't run the workload!\n");
3beb0861 585 goto out_delete_maps;
f15eb531
NK
586 }
587 }
588
514f1c67
ACM
589 err = perf_evlist__open(evlist);
590 if (err < 0) {
c24ff998 591 fprintf(trace->output, "Couldn't create the events: %s\n", strerror(errno));
3beb0861 592 goto out_delete_maps;
514f1c67
ACM
593 }
594
595 err = perf_evlist__mmap(evlist, UINT_MAX, false);
596 if (err < 0) {
c24ff998 597 fprintf(trace->output, "Couldn't mmap the events: %s\n", strerror(errno));
3beb0861 598 goto out_close_evlist;
514f1c67
ACM
599 }
600
601 perf_evlist__enable(evlist);
f15eb531
NK
602
603 if (forks)
604 perf_evlist__start_workload(evlist);
605
752fde44 606 trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1;
514f1c67 607again:
efd5745e 608 before = trace->nr_events;
514f1c67
ACM
609
610 for (i = 0; i < evlist->nr_mmaps; i++) {
611 union perf_event *event;
612
613 while ((event = perf_evlist__mmap_read(evlist, i)) != NULL) {
614 const u32 type = event->header.type;
ba3d7dee 615 tracepoint_handler handler;
514f1c67 616 struct perf_sample sample;
514f1c67 617
efd5745e 618 ++trace->nr_events;
514f1c67 619
514f1c67
ACM
620 err = perf_evlist__parse_sample(evlist, event, &sample);
621 if (err) {
c24ff998 622 fprintf(trace->output, "Can't parse sample, err = %d, skipping...\n", err);
514f1c67
ACM
623 continue;
624 }
625
752fde44
ACM
626 if (trace->base_time == 0)
627 trace->base_time = sample.time;
628
629 if (type != PERF_RECORD_SAMPLE) {
c24ff998 630 trace__process_event(trace, &trace->host, event);
752fde44
ACM
631 continue;
632 }
633
514f1c67
ACM
634 evsel = perf_evlist__id2evsel(evlist, sample.id);
635 if (evsel == NULL) {
c24ff998 636 fprintf(trace->output, "Unknown tp ID %" PRIu64 ", skipping...\n", sample.id);
514f1c67
ACM
637 continue;
638 }
639
fc551f8d 640 if (sample.raw_data == NULL) {
c24ff998 641 fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
fc551f8d
ACM
642 perf_evsel__name(evsel), sample.tid,
643 sample.cpu, sample.raw_size);
644 continue;
645 }
646
ba3d7dee
ACM
647 handler = evsel->handler.func;
648 handler(trace, evsel, &sample);
514f1c67
ACM
649 }
650 }
651
efd5745e 652 if (trace->nr_events == before) {
f15eb531 653 if (done)
3beb0861 654 goto out_unmap_evlist;
f15eb531 655
514f1c67 656 poll(evlist->pollfd, evlist->nr_fds, -1);
f15eb531
NK
657 }
658
659 if (done)
660 perf_evlist__disable(evlist);
514f1c67
ACM
661
662 goto again;
663
3beb0861
NK
664out_unmap_evlist:
665 perf_evlist__munmap(evlist);
666out_close_evlist:
667 perf_evlist__close(evlist);
668out_delete_maps:
669 perf_evlist__delete_maps(evlist);
514f1c67
ACM
670out_delete_evlist:
671 perf_evlist__delete(evlist);
672out:
673 return err;
674}
675
1302d88e
ACM
676static size_t trace__fprintf_threads_header(FILE *fp)
677{
678 size_t printed;
679
680 printed = fprintf(fp, "\n _____________________________________________________________________\n");
681 printed += fprintf(fp," __) Summary of events (__\n\n");
682 printed += fprintf(fp," [ task - pid ] [ events ] [ ratio ] [ runtime ]\n");
683 printed += fprintf(fp," _____________________________________________________________________\n\n");
684
685 return printed;
686}
687
688static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
689{
690 size_t printed = trace__fprintf_threads_header(fp);
691 struct rb_node *nd;
692
693 for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) {
694 struct thread *thread = rb_entry(nd, struct thread, rb_node);
695 struct thread_trace *ttrace = thread->priv;
696 const char *color;
697 double ratio;
698
699 if (ttrace == NULL)
700 continue;
701
702 ratio = (double)ttrace->nr_events / trace->nr_events * 100.0;
703
704 color = PERF_COLOR_NORMAL;
705 if (ratio > 50.0)
706 color = PERF_COLOR_RED;
707 else if (ratio > 25.0)
708 color = PERF_COLOR_GREEN;
709 else if (ratio > 5.0)
710 color = PERF_COLOR_YELLOW;
711
712 printed += color_fprintf(fp, color, "%20s", thread->comm);
38051234 713 printed += fprintf(fp, " - %-5d :%11lu [", thread->tid, ttrace->nr_events);
1302d88e
ACM
714 printed += color_fprintf(fp, color, "%5.1f%%", ratio);
715 printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms);
716 }
717
718 return printed;
719}
720
ae9ed035
ACM
721static int trace__set_duration(const struct option *opt, const char *str,
722 int unset __maybe_unused)
723{
724 struct trace *trace = opt->value;
725
726 trace->duration_filter = atof(str);
727 return 0;
728}
729
c24ff998
ACM
730static int trace__open_output(struct trace *trace, const char *filename)
731{
732 struct stat st;
733
734 if (!stat(filename, &st) && st.st_size) {
735 char oldname[PATH_MAX];
736
737 scnprintf(oldname, sizeof(oldname), "%s.old", filename);
738 unlink(oldname);
739 rename(filename, oldname);
740 }
741
742 trace->output = fopen(filename, "w");
743
744 return trace->output == NULL ? -errno : 0;
745}
746
514f1c67
ACM
747int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
748{
749 const char * const trace_usage[] = {
f15eb531
NK
750 "perf trace [<options>] [<command>]",
751 "perf trace [<options>] -- <command> [<options>]",
514f1c67
ACM
752 NULL
753 };
754 struct trace trace = {
755 .audit_machine = audit_detect_machine(),
756 .syscalls = {
757 . max = -1,
758 },
759 .opts = {
760 .target = {
761 .uid = UINT_MAX,
762 .uses_mmap = true,
763 },
764 .user_freq = UINT_MAX,
765 .user_interval = ULLONG_MAX,
766 .no_delay = true,
767 .mmap_pages = 1024,
768 },
c24ff998 769 .output = stdout,
514f1c67 770 };
c24ff998 771 const char *output_name = NULL;
2ae3a312 772 const char *ev_qualifier_str = NULL;
514f1c67 773 const struct option trace_options[] = {
2ae3a312
ACM
774 OPT_STRING('e', "expr", &ev_qualifier_str, "expr",
775 "list of events to trace"),
c24ff998 776 OPT_STRING('o', "output", &output_name, "file", "output file name"),
514f1c67
ACM
777 OPT_STRING('p', "pid", &trace.opts.target.pid, "pid",
778 "trace events on existing process id"),
ac9be8ee 779 OPT_STRING('t', "tid", &trace.opts.target.tid, "tid",
514f1c67 780 "trace events on existing thread id"),
ac9be8ee 781 OPT_BOOLEAN('a', "all-cpus", &trace.opts.target.system_wide,
514f1c67 782 "system-wide collection from all CPUs"),
ac9be8ee 783 OPT_STRING('C', "cpu", &trace.opts.target.cpu_list, "cpu",
514f1c67 784 "list of cpus to monitor"),
ac9be8ee 785 OPT_BOOLEAN('i', "no-inherit", &trace.opts.no_inherit,
514f1c67 786 "child tasks do not inherit counters"),
ac9be8ee 787 OPT_UINTEGER('m', "mmap-pages", &trace.opts.mmap_pages,
514f1c67 788 "number of mmap data pages"),
ac9be8ee 789 OPT_STRING('u', "uid", &trace.opts.target.uid_str, "user",
514f1c67 790 "user to profile"),
ae9ed035
ACM
791 OPT_CALLBACK(0, "duration", &trace, "float",
792 "show only events with duration > N.M ms",
793 trace__set_duration),
1302d88e 794 OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"),
7c304ee0 795 OPT_INCR('v', "verbose", &verbose, "be more verbose"),
514f1c67
ACM
796 OPT_END()
797 };
798 int err;
32caf0d1 799 char bf[BUFSIZ];
514f1c67
ACM
800
801 argc = parse_options(argc, argv, trace_options, trace_usage, 0);
514f1c67 802
c24ff998
ACM
803 if (output_name != NULL) {
804 err = trace__open_output(&trace, output_name);
805 if (err < 0) {
806 perror("failed to create output file");
807 goto out;
808 }
809 }
810
2ae3a312 811 if (ev_qualifier_str != NULL) {
b059efdf
ACM
812 const char *s = ev_qualifier_str;
813
814 trace.not_ev_qualifier = *s == '!';
815 if (trace.not_ev_qualifier)
816 ++s;
817 trace.ev_qualifier = strlist__new(true, s);
2ae3a312 818 if (trace.ev_qualifier == NULL) {
c24ff998
ACM
819 fputs("Not enough memory to parse event qualifier",
820 trace.output);
821 err = -ENOMEM;
822 goto out_close;
2ae3a312
ACM
823 }
824 }
825
32caf0d1
NK
826 err = perf_target__validate(&trace.opts.target);
827 if (err) {
828 perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
c24ff998
ACM
829 fprintf(trace.output, "%s", bf);
830 goto out_close;
32caf0d1
NK
831 }
832
514f1c67
ACM
833 err = perf_target__parse_uid(&trace.opts.target);
834 if (err) {
514f1c67 835 perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
c24ff998
ACM
836 fprintf(trace.output, "%s", bf);
837 goto out_close;
514f1c67
ACM
838 }
839
f15eb531 840 if (!argc && perf_target__none(&trace.opts.target))
ee76120e
NK
841 trace.opts.target.system_wide = true;
842
1302d88e
ACM
843 err = trace__run(&trace, argc, argv);
844
845 if (trace.sched && !err)
c24ff998 846 trace__fprintf_thread_summary(&trace, trace.output);
1302d88e 847
c24ff998
ACM
848out_close:
849 if (output_name != NULL)
850 fclose(trace.output);
851out:
1302d88e 852 return err;
514f1c67 853}