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