perf trace: Allow syscall arg formatters to mask args
[deliverable/linux.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 6#include "util/machine.h"
6810fc91 7#include "util/session.h"
752fde44 8#include "util/thread.h"
514f1c67 9#include "util/parse-options.h"
2ae3a312 10#include "util/strlist.h"
bdc89661 11#include "util/intlist.h"
514f1c67 12#include "util/thread_map.h"
514f1c67
ACM
13
14#include <libaudit.h>
15#include <stdlib.h>
ae685380 16#include <sys/mman.h>
514f1c67 17
6e7eeb51
ACM
18static size_t syscall_arg__scnprintf_hex(char *bf, size_t size,
19 unsigned long arg, u8 *arg_mask __maybe_unused)
13d4ff3e
ACM
20{
21 return scnprintf(bf, size, "%#lx", arg);
22}
23
beccb2b5
ACM
24#define SCA_HEX syscall_arg__scnprintf_hex
25
6e7eeb51
ACM
26static size_t syscall_arg__scnprintf_mmap_prot(char *bf, size_t size,
27 unsigned long arg, u8 *arg_mask __maybe_unused)
ae685380
ACM
28{
29 int printed = 0, prot = arg;
30
31 if (prot == PROT_NONE)
32 return scnprintf(bf, size, "NONE");
33#define P_MMAP_PROT(n) \
34 if (prot & PROT_##n) { \
35 printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
36 prot &= ~PROT_##n; \
37 }
38
39 P_MMAP_PROT(EXEC);
40 P_MMAP_PROT(READ);
41 P_MMAP_PROT(WRITE);
42#ifdef PROT_SEM
43 P_MMAP_PROT(SEM);
44#endif
45 P_MMAP_PROT(GROWSDOWN);
46 P_MMAP_PROT(GROWSUP);
47#undef P_MMAP_PROT
48
49 if (prot)
50 printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", prot);
51
52 return printed;
53}
54
55#define SCA_MMAP_PROT syscall_arg__scnprintf_mmap_prot
56
6e7eeb51
ACM
57static size_t syscall_arg__scnprintf_mmap_flags(char *bf, size_t size,
58 unsigned long arg, u8 *arg_mask __maybe_unused)
941557e0
ACM
59{
60 int printed = 0, flags = arg;
61
62#define P_MMAP_FLAG(n) \
63 if (flags & MAP_##n) { \
64 printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
65 flags &= ~MAP_##n; \
66 }
67
68 P_MMAP_FLAG(SHARED);
69 P_MMAP_FLAG(PRIVATE);
70 P_MMAP_FLAG(32BIT);
71 P_MMAP_FLAG(ANONYMOUS);
72 P_MMAP_FLAG(DENYWRITE);
73 P_MMAP_FLAG(EXECUTABLE);
74 P_MMAP_FLAG(FILE);
75 P_MMAP_FLAG(FIXED);
76 P_MMAP_FLAG(GROWSDOWN);
f2935f3e 77#ifdef MAP_HUGETLB
941557e0 78 P_MMAP_FLAG(HUGETLB);
f2935f3e 79#endif
941557e0
ACM
80 P_MMAP_FLAG(LOCKED);
81 P_MMAP_FLAG(NONBLOCK);
82 P_MMAP_FLAG(NORESERVE);
83 P_MMAP_FLAG(POPULATE);
84 P_MMAP_FLAG(STACK);
85#ifdef MAP_UNINITIALIZED
86 P_MMAP_FLAG(UNINITIALIZED);
87#endif
88#undef P_MMAP_FLAG
89
90 if (flags)
91 printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags);
92
93 return printed;
94}
95
96#define SCA_MMAP_FLAGS syscall_arg__scnprintf_mmap_flags
97
6e7eeb51
ACM
98static size_t syscall_arg__scnprintf_madvise_behavior(char *bf, size_t size,
99 unsigned long arg, u8 *arg_mask __maybe_unused)
9e9716d1
ACM
100{
101 int behavior = arg;
102
103 switch (behavior) {
104#define P_MADV_BHV(n) case MADV_##n: return scnprintf(bf, size, #n)
105 P_MADV_BHV(NORMAL);
106 P_MADV_BHV(RANDOM);
107 P_MADV_BHV(SEQUENTIAL);
108 P_MADV_BHV(WILLNEED);
109 P_MADV_BHV(DONTNEED);
110 P_MADV_BHV(REMOVE);
111 P_MADV_BHV(DONTFORK);
112 P_MADV_BHV(DOFORK);
113 P_MADV_BHV(HWPOISON);
114#ifdef MADV_SOFT_OFFLINE
115 P_MADV_BHV(SOFT_OFFLINE);
116#endif
117 P_MADV_BHV(MERGEABLE);
118 P_MADV_BHV(UNMERGEABLE);
f2935f3e 119#ifdef MADV_HUGEPAGE
9e9716d1 120 P_MADV_BHV(HUGEPAGE);
f2935f3e
DA
121#endif
122#ifdef MADV_NOHUGEPAGE
9e9716d1 123 P_MADV_BHV(NOHUGEPAGE);
f2935f3e 124#endif
9e9716d1
ACM
125#ifdef MADV_DONTDUMP
126 P_MADV_BHV(DONTDUMP);
127#endif
128#ifdef MADV_DODUMP
129 P_MADV_BHV(DODUMP);
130#endif
131#undef P_MADV_PHV
132 default: break;
133 }
134
135 return scnprintf(bf, size, "%#x", behavior);
136}
137
138#define SCA_MADV_BHV syscall_arg__scnprintf_madvise_behavior
139
514f1c67
ACM
140static struct syscall_fmt {
141 const char *name;
aec1930b 142 const char *alias;
6e7eeb51 143 size_t (*arg_scnprintf[6])(char *bf, size_t size, unsigned long arg, u8 *arg_mask);
514f1c67
ACM
144 bool errmsg;
145 bool timeout;
04b34729 146 bool hexret;
514f1c67 147} syscall_fmts[] = {
8b745263 148 { .name = "access", .errmsg = true, },
aec1930b 149 { .name = "arch_prctl", .errmsg = true, .alias = "prctl", },
beccb2b5
ACM
150 { .name = "brk", .hexret = true,
151 .arg_scnprintf = { [0] = SCA_HEX, /* brk */ }, },
04b34729 152 { .name = "mmap", .hexret = true, },
a14bb860 153 { .name = "connect", .errmsg = true, },
aec1930b
ACM
154 { .name = "fstat", .errmsg = true, .alias = "newfstat", },
155 { .name = "fstatat", .errmsg = true, .alias = "newfstatat", },
156 { .name = "futex", .errmsg = true, },
beccb2b5
ACM
157 { .name = "ioctl", .errmsg = true,
158 .arg_scnprintf = { [2] = SCA_HEX, /* arg */ }, },
e5959683 159 { .name = "lstat", .errmsg = true, .alias = "newlstat", },
9e9716d1
ACM
160 { .name = "madvise", .errmsg = true,
161 .arg_scnprintf = { [0] = SCA_HEX, /* start */
162 [2] = SCA_MADV_BHV, /* behavior */ }, },
beccb2b5 163 { .name = "mmap", .hexret = true,
ae685380 164 .arg_scnprintf = { [0] = SCA_HEX, /* addr */
941557e0
ACM
165 [2] = SCA_MMAP_PROT, /* prot */
166 [3] = SCA_MMAP_FLAGS, /* flags */ }, },
beccb2b5 167 { .name = "mprotect", .errmsg = true,
ae685380
ACM
168 .arg_scnprintf = { [0] = SCA_HEX, /* start */
169 [2] = SCA_MMAP_PROT, /* prot */ }, },
170 { .name = "mremap", .hexret = true,
171 .arg_scnprintf = { [0] = SCA_HEX, /* addr */
172 [4] = SCA_HEX, /* new_addr */ }, },
beccb2b5
ACM
173 { .name = "munmap", .errmsg = true,
174 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
8b745263 175 { .name = "open", .errmsg = true, },
aec1930b
ACM
176 { .name = "poll", .errmsg = true, .timeout = true, },
177 { .name = "ppoll", .errmsg = true, .timeout = true, },
e5959683
ACM
178 { .name = "pread", .errmsg = true, .alias = "pread64", },
179 { .name = "pwrite", .errmsg = true, .alias = "pwrite64", },
aec1930b
ACM
180 { .name = "read", .errmsg = true, },
181 { .name = "recvfrom", .errmsg = true, },
182 { .name = "select", .errmsg = true, .timeout = true, },
8b745263 183 { .name = "socket", .errmsg = true, },
aec1930b 184 { .name = "stat", .errmsg = true, .alias = "newstat", },
e5959683 185 { .name = "uname", .errmsg = true, .alias = "newuname", },
514f1c67
ACM
186};
187
188static int syscall_fmt__cmp(const void *name, const void *fmtp)
189{
190 const struct syscall_fmt *fmt = fmtp;
191 return strcmp(name, fmt->name);
192}
193
194static struct syscall_fmt *syscall_fmt__find(const char *name)
195{
196 const int nmemb = ARRAY_SIZE(syscall_fmts);
197 return bsearch(name, syscall_fmts, nmemb, sizeof(struct syscall_fmt), syscall_fmt__cmp);
198}
199
200struct syscall {
201 struct event_format *tp_format;
202 const char *name;
2ae3a312 203 bool filtered;
514f1c67 204 struct syscall_fmt *fmt;
6e7eeb51
ACM
205 size_t (**arg_scnprintf)(char *bf, size_t size,
206 unsigned long arg, u8 *args_mask);
514f1c67
ACM
207};
208
60c907ab
ACM
209static size_t fprintf_duration(unsigned long t, FILE *fp)
210{
211 double duration = (double)t / NSEC_PER_MSEC;
212 size_t printed = fprintf(fp, "(");
213
214 if (duration >= 1.0)
215 printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration);
216 else if (duration >= 0.01)
217 printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration);
218 else
219 printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration);
c24ff998 220 return printed + fprintf(fp, "): ");
60c907ab
ACM
221}
222
752fde44
ACM
223struct thread_trace {
224 u64 entry_time;
225 u64 exit_time;
226 bool entry_pending;
efd5745e 227 unsigned long nr_events;
752fde44 228 char *entry_str;
1302d88e 229 double runtime_ms;
752fde44
ACM
230};
231
232static struct thread_trace *thread_trace__new(void)
233{
234 return zalloc(sizeof(struct thread_trace));
235}
236
c24ff998 237static struct thread_trace *thread__trace(struct thread *thread, FILE *fp)
752fde44 238{
efd5745e
ACM
239 struct thread_trace *ttrace;
240
752fde44
ACM
241 if (thread == NULL)
242 goto fail;
243
244 if (thread->priv == NULL)
245 thread->priv = thread_trace__new();
efd5745e 246
752fde44
ACM
247 if (thread->priv == NULL)
248 goto fail;
249
efd5745e
ACM
250 ttrace = thread->priv;
251 ++ttrace->nr_events;
252
253 return ttrace;
752fde44 254fail:
c24ff998 255 color_fprintf(fp, PERF_COLOR_RED,
752fde44
ACM
256 "WARNING: not enough memory, dropping samples!\n");
257 return NULL;
258}
259
514f1c67 260struct trace {
c24ff998 261 struct perf_tool tool;
514f1c67
ACM
262 int audit_machine;
263 struct {
264 int max;
265 struct syscall *table;
266 } syscalls;
267 struct perf_record_opts opts;
752fde44
ACM
268 struct machine host;
269 u64 base_time;
c24ff998 270 FILE *output;
efd5745e 271 unsigned long nr_events;
b059efdf
ACM
272 struct strlist *ev_qualifier;
273 bool not_ev_qualifier;
bdc89661
DA
274 struct intlist *tid_list;
275 struct intlist *pid_list;
1302d88e 276 bool sched;
752fde44 277 bool multiple_threads;
ae9ed035 278 double duration_filter;
1302d88e 279 double runtime_ms;
514f1c67
ACM
280};
281
ae9ed035
ACM
282static bool trace__filter_duration(struct trace *trace, double t)
283{
284 return t < (trace->duration_filter * NSEC_PER_MSEC);
285}
286
752fde44
ACM
287static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
288{
289 double ts = (double)(tstamp - trace->base_time) / NSEC_PER_MSEC;
290
60c907ab 291 return fprintf(fp, "%10.3f ", ts);
752fde44
ACM
292}
293
f15eb531
NK
294static bool done = false;
295
296static void sig_handler(int sig __maybe_unused)
297{
298 done = true;
299}
300
752fde44 301static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
60c907ab 302 u64 duration, u64 tstamp, FILE *fp)
752fde44
ACM
303{
304 size_t printed = trace__fprintf_tstamp(trace, tstamp, fp);
60c907ab 305 printed += fprintf_duration(duration, fp);
752fde44
ACM
306
307 if (trace->multiple_threads)
38051234 308 printed += fprintf(fp, "%d ", thread->tid);
752fde44
ACM
309
310 return printed;
311}
312
c24ff998
ACM
313static int trace__process_event(struct trace *trace, struct machine *machine,
314 union perf_event *event)
752fde44
ACM
315{
316 int ret = 0;
317
318 switch (event->header.type) {
319 case PERF_RECORD_LOST:
c24ff998 320 color_fprintf(trace->output, PERF_COLOR_RED,
752fde44
ACM
321 "LOST %" PRIu64 " events!\n", event->lost.lost);
322 ret = machine__process_lost_event(machine, event);
323 default:
324 ret = machine__process_event(machine, event);
325 break;
326 }
327
328 return ret;
329}
330
c24ff998 331static int trace__tool_process(struct perf_tool *tool,
752fde44
ACM
332 union perf_event *event,
333 struct perf_sample *sample __maybe_unused,
334 struct machine *machine)
335{
c24ff998
ACM
336 struct trace *trace = container_of(tool, struct trace, tool);
337 return trace__process_event(trace, machine, event);
752fde44
ACM
338}
339
340static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
341{
342 int err = symbol__init();
343
344 if (err)
345 return err;
346
347 machine__init(&trace->host, "", HOST_KERNEL_ID);
348 machine__create_kernel_maps(&trace->host);
349
350 if (perf_target__has_task(&trace->opts.target)) {
c24ff998 351 err = perf_event__synthesize_thread_map(&trace->tool, evlist->threads,
752fde44
ACM
352 trace__tool_process,
353 &trace->host);
354 } else {
c24ff998 355 err = perf_event__synthesize_threads(&trace->tool, trace__tool_process,
752fde44
ACM
356 &trace->host);
357 }
358
359 if (err)
360 symbol__exit();
361
362 return err;
363}
364
13d4ff3e
ACM
365static int syscall__set_arg_fmts(struct syscall *sc)
366{
367 struct format_field *field;
368 int idx = 0;
369
370 sc->arg_scnprintf = calloc(sc->tp_format->format.nr_fields - 1, sizeof(void *));
371 if (sc->arg_scnprintf == NULL)
372 return -1;
373
374 for (field = sc->tp_format->format.fields->next; field; field = field->next) {
beccb2b5
ACM
375 if (sc->fmt && sc->fmt->arg_scnprintf[idx])
376 sc->arg_scnprintf[idx] = sc->fmt->arg_scnprintf[idx];
377 else if (field->flags & FIELD_IS_POINTER)
13d4ff3e
ACM
378 sc->arg_scnprintf[idx] = syscall_arg__scnprintf_hex;
379 ++idx;
380 }
381
382 return 0;
383}
384
514f1c67
ACM
385static int trace__read_syscall_info(struct trace *trace, int id)
386{
387 char tp_name[128];
388 struct syscall *sc;
3a531260
ACM
389 const char *name = audit_syscall_to_name(id, trace->audit_machine);
390
391 if (name == NULL)
392 return -1;
514f1c67
ACM
393
394 if (id > trace->syscalls.max) {
395 struct syscall *nsyscalls = realloc(trace->syscalls.table, (id + 1) * sizeof(*sc));
396
397 if (nsyscalls == NULL)
398 return -1;
399
400 if (trace->syscalls.max != -1) {
401 memset(nsyscalls + trace->syscalls.max + 1, 0,
402 (id - trace->syscalls.max) * sizeof(*sc));
403 } else {
404 memset(nsyscalls, 0, (id + 1) * sizeof(*sc));
405 }
406
407 trace->syscalls.table = nsyscalls;
408 trace->syscalls.max = id;
409 }
410
411 sc = trace->syscalls.table + id;
3a531260 412 sc->name = name;
2ae3a312 413
b059efdf
ACM
414 if (trace->ev_qualifier) {
415 bool in = strlist__find(trace->ev_qualifier, name) != NULL;
416
417 if (!(in ^ trace->not_ev_qualifier)) {
418 sc->filtered = true;
419 /*
420 * No need to do read tracepoint information since this will be
421 * filtered out.
422 */
423 return 0;
424 }
2ae3a312
ACM
425 }
426
3a531260 427 sc->fmt = syscall_fmt__find(sc->name);
514f1c67 428
aec1930b 429 snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name);
514f1c67 430 sc->tp_format = event_format__new("syscalls", tp_name);
aec1930b
ACM
431
432 if (sc->tp_format == NULL && sc->fmt && sc->fmt->alias) {
433 snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->fmt->alias);
434 sc->tp_format = event_format__new("syscalls", tp_name);
435 }
514f1c67 436
13d4ff3e
ACM
437 if (sc->tp_format == NULL)
438 return -1;
439
440 return syscall__set_arg_fmts(sc);
514f1c67
ACM
441}
442
752fde44
ACM
443static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
444 unsigned long *args)
514f1c67
ACM
445{
446 int i = 0;
447 size_t printed = 0;
448
449 if (sc->tp_format != NULL) {
450 struct format_field *field;
6e7eeb51
ACM
451 u8 mask = 0, bit = 1;
452
453 for (field = sc->tp_format->format.fields->next; field;
454 field = field->next, ++i, bit <<= 1) {
455 if (mask & bit)
456 continue;
514f1c67 457
752fde44 458 printed += scnprintf(bf + printed, size - printed,
13d4ff3e
ACM
459 "%s%s: ", printed ? ", " : "", field->name);
460
6e7eeb51
ACM
461 if (sc->arg_scnprintf && sc->arg_scnprintf[i]) {
462 printed += sc->arg_scnprintf[i](bf + printed, size - printed,
463 args[i], &mask);
464 } else {
13d4ff3e
ACM
465 printed += scnprintf(bf + printed, size - printed,
466 "%ld", args[i]);
6e7eeb51 467 }
514f1c67
ACM
468 }
469 } else {
470 while (i < 6) {
752fde44
ACM
471 printed += scnprintf(bf + printed, size - printed,
472 "%sarg%d: %ld",
473 printed ? ", " : "", i, args[i]);
514f1c67
ACM
474 ++i;
475 }
476 }
477
478 return printed;
479}
480
ba3d7dee
ACM
481typedef int (*tracepoint_handler)(struct trace *trace, struct perf_evsel *evsel,
482 struct perf_sample *sample);
483
484static struct syscall *trace__syscall_info(struct trace *trace,
485 struct perf_evsel *evsel,
486 struct perf_sample *sample)
487{
488 int id = perf_evsel__intval(evsel, sample, "id");
489
490 if (id < 0) {
adaa18bf
ACM
491
492 /*
493 * XXX: Noticed on x86_64, reproduced as far back as 3.0.36, haven't tried
494 * before that, leaving at a higher verbosity level till that is
495 * explained. Reproduced with plain ftrace with:
496 *
497 * echo 1 > /t/events/raw_syscalls/sys_exit/enable
498 * grep "NR -1 " /t/trace_pipe
499 *
500 * After generating some load on the machine.
501 */
502 if (verbose > 1) {
503 static u64 n;
504 fprintf(trace->output, "Invalid syscall %d id, skipping (%s, %" PRIu64 ") ...\n",
505 id, perf_evsel__name(evsel), ++n);
506 }
ba3d7dee
ACM
507 return NULL;
508 }
509
510 if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL) &&
511 trace__read_syscall_info(trace, id))
512 goto out_cant_read;
513
514 if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL))
515 goto out_cant_read;
516
517 return &trace->syscalls.table[id];
518
519out_cant_read:
7c304ee0
ACM
520 if (verbose) {
521 fprintf(trace->output, "Problems reading syscall %d", id);
522 if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL)
523 fprintf(trace->output, "(%s)", trace->syscalls.table[id].name);
524 fputs(" information\n", trace->output);
525 }
ba3d7dee
ACM
526 return NULL;
527}
528
529static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
530 struct perf_sample *sample)
531{
752fde44 532 char *msg;
ba3d7dee 533 void *args;
752fde44 534 size_t printed = 0;
2ae3a312 535 struct thread *thread;
ba3d7dee 536 struct syscall *sc = trace__syscall_info(trace, evsel, sample);
2ae3a312
ACM
537 struct thread_trace *ttrace;
538
539 if (sc == NULL)
540 return -1;
ba3d7dee 541
2ae3a312
ACM
542 if (sc->filtered)
543 return 0;
544
314add6b
AH
545 thread = machine__findnew_thread(&trace->host, sample->pid,
546 sample->tid);
c24ff998 547 ttrace = thread__trace(thread, trace->output);
2ae3a312 548 if (ttrace == NULL)
ba3d7dee
ACM
549 return -1;
550
551 args = perf_evsel__rawptr(evsel, sample, "args");
552 if (args == NULL) {
c24ff998 553 fprintf(trace->output, "Problems reading syscall arguments\n");
ba3d7dee
ACM
554 return -1;
555 }
556
752fde44
ACM
557 ttrace = thread->priv;
558
559 if (ttrace->entry_str == NULL) {
560 ttrace->entry_str = malloc(1024);
561 if (!ttrace->entry_str)
562 return -1;
563 }
564
565 ttrace->entry_time = sample->time;
566 msg = ttrace->entry_str;
567 printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);
568
569 printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed, args);
570
571 if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
ae9ed035 572 if (!trace->duration_filter) {
c24ff998
ACM
573 trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output);
574 fprintf(trace->output, "%-70s\n", ttrace->entry_str);
ae9ed035 575 }
752fde44
ACM
576 } else
577 ttrace->entry_pending = true;
ba3d7dee
ACM
578
579 return 0;
580}
581
582static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
583 struct perf_sample *sample)
584{
585 int ret;
60c907ab 586 u64 duration = 0;
2ae3a312 587 struct thread *thread;
ba3d7dee 588 struct syscall *sc = trace__syscall_info(trace, evsel, sample);
2ae3a312
ACM
589 struct thread_trace *ttrace;
590
591 if (sc == NULL)
592 return -1;
ba3d7dee 593
2ae3a312
ACM
594 if (sc->filtered)
595 return 0;
596
314add6b
AH
597 thread = machine__findnew_thread(&trace->host, sample->pid,
598 sample->tid);
c24ff998 599 ttrace = thread__trace(thread, trace->output);
2ae3a312 600 if (ttrace == NULL)
ba3d7dee
ACM
601 return -1;
602
603 ret = perf_evsel__intval(evsel, sample, "ret");
604
752fde44
ACM
605 ttrace = thread->priv;
606
607 ttrace->exit_time = sample->time;
608
ae9ed035 609 if (ttrace->entry_time) {
60c907ab 610 duration = sample->time - ttrace->entry_time;
ae9ed035
ACM
611 if (trace__filter_duration(trace, duration))
612 goto out;
613 } else if (trace->duration_filter)
614 goto out;
60c907ab 615
c24ff998 616 trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output);
752fde44
ACM
617
618 if (ttrace->entry_pending) {
c24ff998 619 fprintf(trace->output, "%-70s", ttrace->entry_str);
752fde44 620 } else {
c24ff998
ACM
621 fprintf(trace->output, " ... [");
622 color_fprintf(trace->output, PERF_COLOR_YELLOW, "continued");
623 fprintf(trace->output, "]: %s()", sc->name);
752fde44
ACM
624 }
625
da3c9a44
ACM
626 if (sc->fmt == NULL) {
627signed_print:
628 fprintf(trace->output, ") = %d", ret);
629 } else if (ret < 0 && sc->fmt->errmsg) {
ba3d7dee
ACM
630 char bf[256];
631 const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
632 *e = audit_errno_to_name(-ret);
633
c24ff998 634 fprintf(trace->output, ") = -1 %s %s", e, emsg);
da3c9a44 635 } else if (ret == 0 && sc->fmt->timeout)
c24ff998 636 fprintf(trace->output, ") = 0 Timeout");
04b34729
ACM
637 else if (sc->fmt->hexret)
638 fprintf(trace->output, ") = %#x", ret);
ba3d7dee 639 else
da3c9a44 640 goto signed_print;
ba3d7dee 641
c24ff998 642 fputc('\n', trace->output);
ae9ed035 643out:
752fde44
ACM
644 ttrace->entry_pending = false;
645
ba3d7dee
ACM
646 return 0;
647}
648
1302d88e
ACM
649static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel,
650 struct perf_sample *sample)
651{
652 u64 runtime = perf_evsel__intval(evsel, sample, "runtime");
653 double runtime_ms = (double)runtime / NSEC_PER_MSEC;
314add6b
AH
654 struct thread *thread = machine__findnew_thread(&trace->host,
655 sample->pid,
656 sample->tid);
c24ff998 657 struct thread_trace *ttrace = thread__trace(thread, trace->output);
1302d88e
ACM
658
659 if (ttrace == NULL)
660 goto out_dump;
661
662 ttrace->runtime_ms += runtime_ms;
663 trace->runtime_ms += runtime_ms;
664 return 0;
665
666out_dump:
c24ff998 667 fprintf(trace->output, "%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n",
1302d88e
ACM
668 evsel->name,
669 perf_evsel__strval(evsel, sample, "comm"),
670 (pid_t)perf_evsel__intval(evsel, sample, "pid"),
671 runtime,
672 perf_evsel__intval(evsel, sample, "vruntime"));
673 return 0;
674}
675
bdc89661
DA
676static bool skip_sample(struct trace *trace, struct perf_sample *sample)
677{
678 if ((trace->pid_list && intlist__find(trace->pid_list, sample->pid)) ||
679 (trace->tid_list && intlist__find(trace->tid_list, sample->tid)))
680 return false;
681
682 if (trace->pid_list || trace->tid_list)
683 return true;
684
685 return false;
686}
687
6810fc91
DA
688static int trace__process_sample(struct perf_tool *tool,
689 union perf_event *event __maybe_unused,
690 struct perf_sample *sample,
691 struct perf_evsel *evsel,
692 struct machine *machine __maybe_unused)
693{
694 struct trace *trace = container_of(tool, struct trace, tool);
695 int err = 0;
696
697 tracepoint_handler handler = evsel->handler.func;
698
bdc89661
DA
699 if (skip_sample(trace, sample))
700 return 0;
701
6810fc91
DA
702 if (trace->base_time == 0)
703 trace->base_time = sample->time;
704
705 if (handler)
706 handler(trace, evsel, sample);
707
708 return err;
709}
710
711static bool
712perf_session__has_tp(struct perf_session *session, const char *name)
713{
714 struct perf_evsel *evsel;
715
716 evsel = perf_evlist__find_tracepoint_by_name(session->evlist, name);
717
718 return evsel != NULL;
719}
720
bdc89661
DA
721static int parse_target_str(struct trace *trace)
722{
723 if (trace->opts.target.pid) {
724 trace->pid_list = intlist__new(trace->opts.target.pid);
725 if (trace->pid_list == NULL) {
726 pr_err("Error parsing process id string\n");
727 return -EINVAL;
728 }
729 }
730
731 if (trace->opts.target.tid) {
732 trace->tid_list = intlist__new(trace->opts.target.tid);
733 if (trace->tid_list == NULL) {
734 pr_err("Error parsing thread id string\n");
735 return -EINVAL;
736 }
737 }
738
739 return 0;
740}
741
f15eb531 742static int trace__run(struct trace *trace, int argc, const char **argv)
514f1c67 743{
334fe7a3 744 struct perf_evlist *evlist = perf_evlist__new();
ba3d7dee 745 struct perf_evsel *evsel;
efd5745e
ACM
746 int err = -1, i;
747 unsigned long before;
f15eb531 748 const bool forks = argc > 0;
514f1c67
ACM
749
750 if (evlist == NULL) {
c24ff998 751 fprintf(trace->output, "Not enough memory to run!\n");
514f1c67
ACM
752 goto out;
753 }
754
39876e7d
ACM
755 if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) ||
756 perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) {
c24ff998 757 fprintf(trace->output, "Couldn't read the raw_syscalls tracepoints information!\n");
514f1c67
ACM
758 goto out_delete_evlist;
759 }
760
1302d88e
ACM
761 if (trace->sched &&
762 perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime",
763 trace__sched_stat_runtime)) {
c24ff998 764 fprintf(trace->output, "Couldn't read the sched_stat_runtime tracepoint information!\n");
1302d88e
ACM
765 goto out_delete_evlist;
766 }
767
514f1c67
ACM
768 err = perf_evlist__create_maps(evlist, &trace->opts.target);
769 if (err < 0) {
c24ff998 770 fprintf(trace->output, "Problems parsing the target to trace, check your options!\n");
514f1c67
ACM
771 goto out_delete_evlist;
772 }
773
752fde44
ACM
774 err = trace__symbols_init(trace, evlist);
775 if (err < 0) {
c24ff998 776 fprintf(trace->output, "Problems initializing symbol libraries!\n");
3beb0861 777 goto out_delete_maps;
752fde44
ACM
778 }
779
f77a9518 780 perf_evlist__config(evlist, &trace->opts);
514f1c67 781
f15eb531
NK
782 signal(SIGCHLD, sig_handler);
783 signal(SIGINT, sig_handler);
784
785 if (forks) {
6ef73ec4 786 err = perf_evlist__prepare_workload(evlist, &trace->opts.target,
55e162ea 787 argv, false, false);
f15eb531 788 if (err < 0) {
c24ff998 789 fprintf(trace->output, "Couldn't run the workload!\n");
3beb0861 790 goto out_delete_maps;
f15eb531
NK
791 }
792 }
793
514f1c67
ACM
794 err = perf_evlist__open(evlist);
795 if (err < 0) {
c24ff998 796 fprintf(trace->output, "Couldn't create the events: %s\n", strerror(errno));
3beb0861 797 goto out_delete_maps;
514f1c67
ACM
798 }
799
800 err = perf_evlist__mmap(evlist, UINT_MAX, false);
801 if (err < 0) {
c24ff998 802 fprintf(trace->output, "Couldn't mmap the events: %s\n", strerror(errno));
3beb0861 803 goto out_close_evlist;
514f1c67
ACM
804 }
805
806 perf_evlist__enable(evlist);
f15eb531
NK
807
808 if (forks)
809 perf_evlist__start_workload(evlist);
810
752fde44 811 trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1;
514f1c67 812again:
efd5745e 813 before = trace->nr_events;
514f1c67
ACM
814
815 for (i = 0; i < evlist->nr_mmaps; i++) {
816 union perf_event *event;
817
818 while ((event = perf_evlist__mmap_read(evlist, i)) != NULL) {
819 const u32 type = event->header.type;
ba3d7dee 820 tracepoint_handler handler;
514f1c67 821 struct perf_sample sample;
514f1c67 822
efd5745e 823 ++trace->nr_events;
514f1c67 824
514f1c67
ACM
825 err = perf_evlist__parse_sample(evlist, event, &sample);
826 if (err) {
c24ff998 827 fprintf(trace->output, "Can't parse sample, err = %d, skipping...\n", err);
514f1c67
ACM
828 continue;
829 }
830
752fde44
ACM
831 if (trace->base_time == 0)
832 trace->base_time = sample.time;
833
834 if (type != PERF_RECORD_SAMPLE) {
c24ff998 835 trace__process_event(trace, &trace->host, event);
752fde44
ACM
836 continue;
837 }
838
514f1c67
ACM
839 evsel = perf_evlist__id2evsel(evlist, sample.id);
840 if (evsel == NULL) {
c24ff998 841 fprintf(trace->output, "Unknown tp ID %" PRIu64 ", skipping...\n", sample.id);
514f1c67
ACM
842 continue;
843 }
844
fc551f8d 845 if (sample.raw_data == NULL) {
c24ff998 846 fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
fc551f8d
ACM
847 perf_evsel__name(evsel), sample.tid,
848 sample.cpu, sample.raw_size);
849 continue;
850 }
851
ba3d7dee
ACM
852 handler = evsel->handler.func;
853 handler(trace, evsel, &sample);
514f1c67
ACM
854 }
855 }
856
efd5745e 857 if (trace->nr_events == before) {
f15eb531 858 if (done)
3beb0861 859 goto out_unmap_evlist;
f15eb531 860
514f1c67 861 poll(evlist->pollfd, evlist->nr_fds, -1);
f15eb531
NK
862 }
863
864 if (done)
865 perf_evlist__disable(evlist);
514f1c67
ACM
866
867 goto again;
868
3beb0861
NK
869out_unmap_evlist:
870 perf_evlist__munmap(evlist);
871out_close_evlist:
872 perf_evlist__close(evlist);
873out_delete_maps:
874 perf_evlist__delete_maps(evlist);
514f1c67
ACM
875out_delete_evlist:
876 perf_evlist__delete(evlist);
877out:
878 return err;
879}
880
6810fc91
DA
881static int trace__replay(struct trace *trace)
882{
883 const struct perf_evsel_str_handler handlers[] = {
884 { "raw_syscalls:sys_enter", trace__sys_enter, },
885 { "raw_syscalls:sys_exit", trace__sys_exit, },
886 };
887
888 struct perf_session *session;
889 int err = -1;
890
891 trace->tool.sample = trace__process_sample;
892 trace->tool.mmap = perf_event__process_mmap;
893 trace->tool.comm = perf_event__process_comm;
894 trace->tool.exit = perf_event__process_exit;
895 trace->tool.fork = perf_event__process_fork;
896 trace->tool.attr = perf_event__process_attr;
897 trace->tool.tracing_data = perf_event__process_tracing_data;
898 trace->tool.build_id = perf_event__process_build_id;
899
900 trace->tool.ordered_samples = true;
901 trace->tool.ordering_requires_timestamps = true;
902
903 /* add tid to output */
904 trace->multiple_threads = true;
905
906 if (symbol__init() < 0)
907 return -1;
908
909 session = perf_session__new(input_name, O_RDONLY, 0, false,
910 &trace->tool);
911 if (session == NULL)
912 return -ENOMEM;
913
914 err = perf_session__set_tracepoints_handlers(session, handlers);
915 if (err)
916 goto out;
917
918 if (!perf_session__has_tp(session, "raw_syscalls:sys_enter")) {
919 pr_err("Data file does not have raw_syscalls:sys_enter events\n");
920 goto out;
921 }
922
923 if (!perf_session__has_tp(session, "raw_syscalls:sys_exit")) {
924 pr_err("Data file does not have raw_syscalls:sys_exit events\n");
925 goto out;
926 }
927
bdc89661
DA
928 err = parse_target_str(trace);
929 if (err != 0)
930 goto out;
931
6810fc91
DA
932 setup_pager();
933
934 err = perf_session__process_events(session, &trace->tool);
935 if (err)
936 pr_err("Failed to process events, error %d", err);
937
938out:
939 perf_session__delete(session);
940
941 return err;
942}
943
1302d88e
ACM
944static size_t trace__fprintf_threads_header(FILE *fp)
945{
946 size_t printed;
947
948 printed = fprintf(fp, "\n _____________________________________________________________________\n");
949 printed += fprintf(fp," __) Summary of events (__\n\n");
950 printed += fprintf(fp," [ task - pid ] [ events ] [ ratio ] [ runtime ]\n");
951 printed += fprintf(fp," _____________________________________________________________________\n\n");
952
953 return printed;
954}
955
956static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
957{
958 size_t printed = trace__fprintf_threads_header(fp);
959 struct rb_node *nd;
960
961 for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) {
962 struct thread *thread = rb_entry(nd, struct thread, rb_node);
963 struct thread_trace *ttrace = thread->priv;
964 const char *color;
965 double ratio;
966
967 if (ttrace == NULL)
968 continue;
969
970 ratio = (double)ttrace->nr_events / trace->nr_events * 100.0;
971
972 color = PERF_COLOR_NORMAL;
973 if (ratio > 50.0)
974 color = PERF_COLOR_RED;
975 else if (ratio > 25.0)
976 color = PERF_COLOR_GREEN;
977 else if (ratio > 5.0)
978 color = PERF_COLOR_YELLOW;
979
980 printed += color_fprintf(fp, color, "%20s", thread->comm);
38051234 981 printed += fprintf(fp, " - %-5d :%11lu [", thread->tid, ttrace->nr_events);
1302d88e
ACM
982 printed += color_fprintf(fp, color, "%5.1f%%", ratio);
983 printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms);
984 }
985
986 return printed;
987}
988
ae9ed035
ACM
989static int trace__set_duration(const struct option *opt, const char *str,
990 int unset __maybe_unused)
991{
992 struct trace *trace = opt->value;
993
994 trace->duration_filter = atof(str);
995 return 0;
996}
997
c24ff998
ACM
998static int trace__open_output(struct trace *trace, const char *filename)
999{
1000 struct stat st;
1001
1002 if (!stat(filename, &st) && st.st_size) {
1003 char oldname[PATH_MAX];
1004
1005 scnprintf(oldname, sizeof(oldname), "%s.old", filename);
1006 unlink(oldname);
1007 rename(filename, oldname);
1008 }
1009
1010 trace->output = fopen(filename, "w");
1011
1012 return trace->output == NULL ? -errno : 0;
1013}
1014
514f1c67
ACM
1015int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
1016{
1017 const char * const trace_usage[] = {
f15eb531
NK
1018 "perf trace [<options>] [<command>]",
1019 "perf trace [<options>] -- <command> [<options>]",
514f1c67
ACM
1020 NULL
1021 };
1022 struct trace trace = {
1023 .audit_machine = audit_detect_machine(),
1024 .syscalls = {
1025 . max = -1,
1026 },
1027 .opts = {
1028 .target = {
1029 .uid = UINT_MAX,
1030 .uses_mmap = true,
1031 },
1032 .user_freq = UINT_MAX,
1033 .user_interval = ULLONG_MAX,
1034 .no_delay = true,
1035 .mmap_pages = 1024,
1036 },
c24ff998 1037 .output = stdout,
514f1c67 1038 };
c24ff998 1039 const char *output_name = NULL;
2ae3a312 1040 const char *ev_qualifier_str = NULL;
514f1c67 1041 const struct option trace_options[] = {
2ae3a312
ACM
1042 OPT_STRING('e', "expr", &ev_qualifier_str, "expr",
1043 "list of events to trace"),
c24ff998 1044 OPT_STRING('o', "output", &output_name, "file", "output file name"),
6810fc91 1045 OPT_STRING('i', "input", &input_name, "file", "Analyze events in file"),
514f1c67
ACM
1046 OPT_STRING('p', "pid", &trace.opts.target.pid, "pid",
1047 "trace events on existing process id"),
ac9be8ee 1048 OPT_STRING('t', "tid", &trace.opts.target.tid, "tid",
514f1c67 1049 "trace events on existing thread id"),
ac9be8ee 1050 OPT_BOOLEAN('a', "all-cpus", &trace.opts.target.system_wide,
514f1c67 1051 "system-wide collection from all CPUs"),
ac9be8ee 1052 OPT_STRING('C', "cpu", &trace.opts.target.cpu_list, "cpu",
514f1c67 1053 "list of cpus to monitor"),
6810fc91 1054 OPT_BOOLEAN(0, "no-inherit", &trace.opts.no_inherit,
514f1c67 1055 "child tasks do not inherit counters"),
ac9be8ee 1056 OPT_UINTEGER('m', "mmap-pages", &trace.opts.mmap_pages,
514f1c67 1057 "number of mmap data pages"),
ac9be8ee 1058 OPT_STRING('u', "uid", &trace.opts.target.uid_str, "user",
514f1c67 1059 "user to profile"),
ae9ed035
ACM
1060 OPT_CALLBACK(0, "duration", &trace, "float",
1061 "show only events with duration > N.M ms",
1062 trace__set_duration),
1302d88e 1063 OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"),
7c304ee0 1064 OPT_INCR('v', "verbose", &verbose, "be more verbose"),
514f1c67
ACM
1065 OPT_END()
1066 };
1067 int err;
32caf0d1 1068 char bf[BUFSIZ];
514f1c67
ACM
1069
1070 argc = parse_options(argc, argv, trace_options, trace_usage, 0);
514f1c67 1071
c24ff998
ACM
1072 if (output_name != NULL) {
1073 err = trace__open_output(&trace, output_name);
1074 if (err < 0) {
1075 perror("failed to create output file");
1076 goto out;
1077 }
1078 }
1079
2ae3a312 1080 if (ev_qualifier_str != NULL) {
b059efdf
ACM
1081 const char *s = ev_qualifier_str;
1082
1083 trace.not_ev_qualifier = *s == '!';
1084 if (trace.not_ev_qualifier)
1085 ++s;
1086 trace.ev_qualifier = strlist__new(true, s);
2ae3a312 1087 if (trace.ev_qualifier == NULL) {
c24ff998
ACM
1088 fputs("Not enough memory to parse event qualifier",
1089 trace.output);
1090 err = -ENOMEM;
1091 goto out_close;
2ae3a312
ACM
1092 }
1093 }
1094
32caf0d1
NK
1095 err = perf_target__validate(&trace.opts.target);
1096 if (err) {
1097 perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
c24ff998
ACM
1098 fprintf(trace.output, "%s", bf);
1099 goto out_close;
32caf0d1
NK
1100 }
1101
514f1c67
ACM
1102 err = perf_target__parse_uid(&trace.opts.target);
1103 if (err) {
514f1c67 1104 perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
c24ff998
ACM
1105 fprintf(trace.output, "%s", bf);
1106 goto out_close;
514f1c67
ACM
1107 }
1108
f15eb531 1109 if (!argc && perf_target__none(&trace.opts.target))
ee76120e
NK
1110 trace.opts.target.system_wide = true;
1111
6810fc91
DA
1112 if (input_name)
1113 err = trace__replay(&trace);
1114 else
1115 err = trace__run(&trace, argc, argv);
1302d88e
ACM
1116
1117 if (trace.sched && !err)
c24ff998 1118 trace__fprintf_thread_summary(&trace, trace.output);
1302d88e 1119
c24ff998
ACM
1120out_close:
1121 if (output_name != NULL)
1122 fclose(trace.output);
1123out:
1302d88e 1124 return err;
514f1c67 1125}
This page took 0.099844 seconds and 5 git commands to generate.