diff options
Diffstat (limited to 'tools/perf/builtin-trace.c')
-rw-r--r-- | tools/perf/builtin-trace.c | 721 |
1 files changed, 652 insertions, 69 deletions
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index ab3ed4af1466..b6f0725068bd 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c | |||
@@ -1,34 +1,331 @@ | |||
1 | #include <traceevent/event-parse.h> | ||
1 | #include "builtin.h" | 2 | #include "builtin.h" |
2 | #include "util/color.h" | 3 | #include "util/color.h" |
4 | #include "util/debug.h" | ||
3 | #include "util/evlist.h" | 5 | #include "util/evlist.h" |
4 | #include "util/machine.h" | 6 | #include "util/machine.h" |
7 | #include "util/session.h" | ||
5 | #include "util/thread.h" | 8 | #include "util/thread.h" |
6 | #include "util/parse-options.h" | 9 | #include "util/parse-options.h" |
10 | #include "util/strlist.h" | ||
11 | #include "util/intlist.h" | ||
7 | #include "util/thread_map.h" | 12 | #include "util/thread_map.h" |
8 | #include "event-parse.h" | ||
9 | 13 | ||
10 | #include <libaudit.h> | 14 | #include <libaudit.h> |
11 | #include <stdlib.h> | 15 | #include <stdlib.h> |
16 | #include <sys/mman.h> | ||
17 | #include <linux/futex.h> | ||
18 | |||
19 | static size_t syscall_arg__scnprintf_hex(char *bf, size_t size, | ||
20 | unsigned long arg, | ||
21 | u8 arg_idx __maybe_unused, | ||
22 | u8 *arg_mask __maybe_unused) | ||
23 | { | ||
24 | return scnprintf(bf, size, "%#lx", arg); | ||
25 | } | ||
26 | |||
27 | #define SCA_HEX syscall_arg__scnprintf_hex | ||
28 | |||
29 | static size_t syscall_arg__scnprintf_whence(char *bf, size_t size, | ||
30 | unsigned long arg, | ||
31 | u8 arg_idx __maybe_unused, | ||
32 | u8 *arg_mask __maybe_unused) | ||
33 | { | ||
34 | int whence = arg; | ||
35 | |||
36 | switch (whence) { | ||
37 | #define P_WHENCE(n) case SEEK_##n: return scnprintf(bf, size, #n) | ||
38 | P_WHENCE(SET); | ||
39 | P_WHENCE(CUR); | ||
40 | P_WHENCE(END); | ||
41 | #ifdef SEEK_DATA | ||
42 | P_WHENCE(DATA); | ||
43 | #endif | ||
44 | #ifdef SEEK_HOLE | ||
45 | P_WHENCE(HOLE); | ||
46 | #endif | ||
47 | #undef P_WHENCE | ||
48 | default: break; | ||
49 | } | ||
50 | |||
51 | return scnprintf(bf, size, "%#x", whence); | ||
52 | } | ||
53 | |||
54 | #define SCA_WHENCE syscall_arg__scnprintf_whence | ||
55 | |||
56 | static size_t syscall_arg__scnprintf_mmap_prot(char *bf, size_t size, | ||
57 | unsigned long arg, | ||
58 | u8 arg_idx __maybe_unused, | ||
59 | u8 *arg_mask __maybe_unused) | ||
60 | { | ||
61 | int printed = 0, prot = arg; | ||
62 | |||
63 | if (prot == PROT_NONE) | ||
64 | return scnprintf(bf, size, "NONE"); | ||
65 | #define P_MMAP_PROT(n) \ | ||
66 | if (prot & PROT_##n) { \ | ||
67 | printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \ | ||
68 | prot &= ~PROT_##n; \ | ||
69 | } | ||
70 | |||
71 | P_MMAP_PROT(EXEC); | ||
72 | P_MMAP_PROT(READ); | ||
73 | P_MMAP_PROT(WRITE); | ||
74 | #ifdef PROT_SEM | ||
75 | P_MMAP_PROT(SEM); | ||
76 | #endif | ||
77 | P_MMAP_PROT(GROWSDOWN); | ||
78 | P_MMAP_PROT(GROWSUP); | ||
79 | #undef P_MMAP_PROT | ||
80 | |||
81 | if (prot) | ||
82 | printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", prot); | ||
83 | |||
84 | return printed; | ||
85 | } | ||
86 | |||
87 | #define SCA_MMAP_PROT syscall_arg__scnprintf_mmap_prot | ||
88 | |||
89 | static size_t syscall_arg__scnprintf_mmap_flags(char *bf, size_t size, | ||
90 | unsigned long arg, u8 arg_idx __maybe_unused, | ||
91 | u8 *arg_mask __maybe_unused) | ||
92 | { | ||
93 | int printed = 0, flags = arg; | ||
94 | |||
95 | #define P_MMAP_FLAG(n) \ | ||
96 | if (flags & MAP_##n) { \ | ||
97 | printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \ | ||
98 | flags &= ~MAP_##n; \ | ||
99 | } | ||
100 | |||
101 | P_MMAP_FLAG(SHARED); | ||
102 | P_MMAP_FLAG(PRIVATE); | ||
103 | P_MMAP_FLAG(32BIT); | ||
104 | P_MMAP_FLAG(ANONYMOUS); | ||
105 | P_MMAP_FLAG(DENYWRITE); | ||
106 | P_MMAP_FLAG(EXECUTABLE); | ||
107 | P_MMAP_FLAG(FILE); | ||
108 | P_MMAP_FLAG(FIXED); | ||
109 | P_MMAP_FLAG(GROWSDOWN); | ||
110 | #ifdef MAP_HUGETLB | ||
111 | P_MMAP_FLAG(HUGETLB); | ||
112 | #endif | ||
113 | P_MMAP_FLAG(LOCKED); | ||
114 | P_MMAP_FLAG(NONBLOCK); | ||
115 | P_MMAP_FLAG(NORESERVE); | ||
116 | P_MMAP_FLAG(POPULATE); | ||
117 | P_MMAP_FLAG(STACK); | ||
118 | #ifdef MAP_UNINITIALIZED | ||
119 | P_MMAP_FLAG(UNINITIALIZED); | ||
120 | #endif | ||
121 | #undef P_MMAP_FLAG | ||
122 | |||
123 | if (flags) | ||
124 | printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags); | ||
125 | |||
126 | return printed; | ||
127 | } | ||
128 | |||
129 | #define SCA_MMAP_FLAGS syscall_arg__scnprintf_mmap_flags | ||
130 | |||
131 | static size_t syscall_arg__scnprintf_madvise_behavior(char *bf, size_t size, | ||
132 | unsigned long arg, u8 arg_idx __maybe_unused, | ||
133 | u8 *arg_mask __maybe_unused) | ||
134 | { | ||
135 | int behavior = arg; | ||
136 | |||
137 | switch (behavior) { | ||
138 | #define P_MADV_BHV(n) case MADV_##n: return scnprintf(bf, size, #n) | ||
139 | P_MADV_BHV(NORMAL); | ||
140 | P_MADV_BHV(RANDOM); | ||
141 | P_MADV_BHV(SEQUENTIAL); | ||
142 | P_MADV_BHV(WILLNEED); | ||
143 | P_MADV_BHV(DONTNEED); | ||
144 | P_MADV_BHV(REMOVE); | ||
145 | P_MADV_BHV(DONTFORK); | ||
146 | P_MADV_BHV(DOFORK); | ||
147 | P_MADV_BHV(HWPOISON); | ||
148 | #ifdef MADV_SOFT_OFFLINE | ||
149 | P_MADV_BHV(SOFT_OFFLINE); | ||
150 | #endif | ||
151 | P_MADV_BHV(MERGEABLE); | ||
152 | P_MADV_BHV(UNMERGEABLE); | ||
153 | #ifdef MADV_HUGEPAGE | ||
154 | P_MADV_BHV(HUGEPAGE); | ||
155 | #endif | ||
156 | #ifdef MADV_NOHUGEPAGE | ||
157 | P_MADV_BHV(NOHUGEPAGE); | ||
158 | #endif | ||
159 | #ifdef MADV_DONTDUMP | ||
160 | P_MADV_BHV(DONTDUMP); | ||
161 | #endif | ||
162 | #ifdef MADV_DODUMP | ||
163 | P_MADV_BHV(DODUMP); | ||
164 | #endif | ||
165 | #undef P_MADV_PHV | ||
166 | default: break; | ||
167 | } | ||
168 | |||
169 | return scnprintf(bf, size, "%#x", behavior); | ||
170 | } | ||
171 | |||
172 | #define SCA_MADV_BHV syscall_arg__scnprintf_madvise_behavior | ||
173 | |||
174 | static size_t syscall_arg__scnprintf_futex_op(char *bf, size_t size, unsigned long arg, | ||
175 | u8 arg_idx __maybe_unused, u8 *arg_mask) | ||
176 | { | ||
177 | enum syscall_futex_args { | ||
178 | SCF_UADDR = (1 << 0), | ||
179 | SCF_OP = (1 << 1), | ||
180 | SCF_VAL = (1 << 2), | ||
181 | SCF_TIMEOUT = (1 << 3), | ||
182 | SCF_UADDR2 = (1 << 4), | ||
183 | SCF_VAL3 = (1 << 5), | ||
184 | }; | ||
185 | int op = arg; | ||
186 | int cmd = op & FUTEX_CMD_MASK; | ||
187 | size_t printed = 0; | ||
188 | |||
189 | switch (cmd) { | ||
190 | #define P_FUTEX_OP(n) case FUTEX_##n: printed = scnprintf(bf, size, #n); | ||
191 | P_FUTEX_OP(WAIT); *arg_mask |= SCF_VAL3|SCF_UADDR2; break; | ||
192 | P_FUTEX_OP(WAKE); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break; | ||
193 | P_FUTEX_OP(FD); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break; | ||
194 | P_FUTEX_OP(REQUEUE); *arg_mask |= SCF_VAL3|SCF_TIMEOUT; break; | ||
195 | P_FUTEX_OP(CMP_REQUEUE); *arg_mask |= SCF_TIMEOUT; break; | ||
196 | P_FUTEX_OP(CMP_REQUEUE_PI); *arg_mask |= SCF_TIMEOUT; break; | ||
197 | P_FUTEX_OP(WAKE_OP); break; | ||
198 | P_FUTEX_OP(LOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break; | ||
199 | P_FUTEX_OP(UNLOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break; | ||
200 | P_FUTEX_OP(TRYLOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2; break; | ||
201 | P_FUTEX_OP(WAIT_BITSET); *arg_mask |= SCF_UADDR2; break; | ||
202 | P_FUTEX_OP(WAKE_BITSET); *arg_mask |= SCF_UADDR2; break; | ||
203 | P_FUTEX_OP(WAIT_REQUEUE_PI); break; | ||
204 | default: printed = scnprintf(bf, size, "%#x", cmd); break; | ||
205 | } | ||
206 | |||
207 | if (op & FUTEX_PRIVATE_FLAG) | ||
208 | printed += scnprintf(bf + printed, size - printed, "|PRIV"); | ||
209 | |||
210 | if (op & FUTEX_CLOCK_REALTIME) | ||
211 | printed += scnprintf(bf + printed, size - printed, "|CLKRT"); | ||
212 | |||
213 | return printed; | ||
214 | } | ||
215 | |||
216 | #define SCA_FUTEX_OP syscall_arg__scnprintf_futex_op | ||
217 | |||
218 | static size_t syscall_arg__scnprintf_open_flags(char *bf, size_t size, | ||
219 | unsigned long arg, | ||
220 | u8 arg_idx, u8 *arg_mask) | ||
221 | { | ||
222 | int printed = 0, flags = arg; | ||
223 | |||
224 | if (!(flags & O_CREAT)) | ||
225 | *arg_mask |= 1 << (arg_idx + 1); /* Mask the mode parm */ | ||
226 | |||
227 | if (flags == 0) | ||
228 | return scnprintf(bf, size, "RDONLY"); | ||
229 | #define P_FLAG(n) \ | ||
230 | if (flags & O_##n) { \ | ||
231 | printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \ | ||
232 | flags &= ~O_##n; \ | ||
233 | } | ||
234 | |||
235 | P_FLAG(APPEND); | ||
236 | P_FLAG(ASYNC); | ||
237 | P_FLAG(CLOEXEC); | ||
238 | P_FLAG(CREAT); | ||
239 | P_FLAG(DIRECT); | ||
240 | P_FLAG(DIRECTORY); | ||
241 | P_FLAG(EXCL); | ||
242 | P_FLAG(LARGEFILE); | ||
243 | P_FLAG(NOATIME); | ||
244 | P_FLAG(NOCTTY); | ||
245 | #ifdef O_NONBLOCK | ||
246 | P_FLAG(NONBLOCK); | ||
247 | #elif O_NDELAY | ||
248 | P_FLAG(NDELAY); | ||
249 | #endif | ||
250 | #ifdef O_PATH | ||
251 | P_FLAG(PATH); | ||
252 | #endif | ||
253 | P_FLAG(RDWR); | ||
254 | #ifdef O_DSYNC | ||
255 | if ((flags & O_SYNC) == O_SYNC) | ||
256 | printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", "SYNC"); | ||
257 | else { | ||
258 | P_FLAG(DSYNC); | ||
259 | } | ||
260 | #else | ||
261 | P_FLAG(SYNC); | ||
262 | #endif | ||
263 | P_FLAG(TRUNC); | ||
264 | P_FLAG(WRONLY); | ||
265 | #undef P_FLAG | ||
266 | |||
267 | if (flags) | ||
268 | printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags); | ||
269 | |||
270 | return printed; | ||
271 | } | ||
272 | |||
273 | #define SCA_OPEN_FLAGS syscall_arg__scnprintf_open_flags | ||
12 | 274 | ||
13 | static struct syscall_fmt { | 275 | static struct syscall_fmt { |
14 | const char *name; | 276 | const char *name; |
15 | const char *alias; | 277 | const char *alias; |
278 | size_t (*arg_scnprintf[6])(char *bf, size_t size, unsigned long arg, u8 arg_idx, u8 *arg_mask); | ||
16 | bool errmsg; | 279 | bool errmsg; |
17 | bool timeout; | 280 | bool timeout; |
281 | bool hexret; | ||
18 | } syscall_fmts[] = { | 282 | } syscall_fmts[] = { |
19 | { .name = "access", .errmsg = true, }, | 283 | { .name = "access", .errmsg = true, }, |
20 | { .name = "arch_prctl", .errmsg = true, .alias = "prctl", }, | 284 | { .name = "arch_prctl", .errmsg = true, .alias = "prctl", }, |
285 | { .name = "brk", .hexret = true, | ||
286 | .arg_scnprintf = { [0] = SCA_HEX, /* brk */ }, }, | ||
287 | { .name = "mmap", .hexret = true, }, | ||
288 | { .name = "connect", .errmsg = true, }, | ||
21 | { .name = "fstat", .errmsg = true, .alias = "newfstat", }, | 289 | { .name = "fstat", .errmsg = true, .alias = "newfstat", }, |
22 | { .name = "fstatat", .errmsg = true, .alias = "newfstatat", }, | 290 | { .name = "fstatat", .errmsg = true, .alias = "newfstatat", }, |
23 | { .name = "futex", .errmsg = true, }, | 291 | { .name = "futex", .errmsg = true, |
24 | { .name = "open", .errmsg = true, }, | 292 | .arg_scnprintf = { [1] = SCA_FUTEX_OP, /* op */ }, }, |
293 | { .name = "ioctl", .errmsg = true, | ||
294 | .arg_scnprintf = { [2] = SCA_HEX, /* arg */ }, }, | ||
295 | { .name = "lseek", .errmsg = true, | ||
296 | .arg_scnprintf = { [2] = SCA_WHENCE, /* whence */ }, }, | ||
297 | { .name = "lstat", .errmsg = true, .alias = "newlstat", }, | ||
298 | { .name = "madvise", .errmsg = true, | ||
299 | .arg_scnprintf = { [0] = SCA_HEX, /* start */ | ||
300 | [2] = SCA_MADV_BHV, /* behavior */ }, }, | ||
301 | { .name = "mmap", .hexret = true, | ||
302 | .arg_scnprintf = { [0] = SCA_HEX, /* addr */ | ||
303 | [2] = SCA_MMAP_PROT, /* prot */ | ||
304 | [3] = SCA_MMAP_FLAGS, /* flags */ }, }, | ||
305 | { .name = "mprotect", .errmsg = true, | ||
306 | .arg_scnprintf = { [0] = SCA_HEX, /* start */ | ||
307 | [2] = SCA_MMAP_PROT, /* prot */ }, }, | ||
308 | { .name = "mremap", .hexret = true, | ||
309 | .arg_scnprintf = { [0] = SCA_HEX, /* addr */ | ||
310 | [4] = SCA_HEX, /* new_addr */ }, }, | ||
311 | { .name = "munmap", .errmsg = true, | ||
312 | .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, }, | ||
313 | { .name = "open", .errmsg = true, | ||
314 | .arg_scnprintf = { [1] = SCA_OPEN_FLAGS, /* flags */ }, }, | ||
315 | { .name = "open_by_handle_at", .errmsg = true, | ||
316 | .arg_scnprintf = { [2] = SCA_OPEN_FLAGS, /* flags */ }, }, | ||
317 | { .name = "openat", .errmsg = true, | ||
318 | .arg_scnprintf = { [2] = SCA_OPEN_FLAGS, /* flags */ }, }, | ||
25 | { .name = "poll", .errmsg = true, .timeout = true, }, | 319 | { .name = "poll", .errmsg = true, .timeout = true, }, |
26 | { .name = "ppoll", .errmsg = true, .timeout = true, }, | 320 | { .name = "ppoll", .errmsg = true, .timeout = true, }, |
321 | { .name = "pread", .errmsg = true, .alias = "pread64", }, | ||
322 | { .name = "pwrite", .errmsg = true, .alias = "pwrite64", }, | ||
27 | { .name = "read", .errmsg = true, }, | 323 | { .name = "read", .errmsg = true, }, |
28 | { .name = "recvfrom", .errmsg = true, }, | 324 | { .name = "recvfrom", .errmsg = true, }, |
29 | { .name = "select", .errmsg = true, .timeout = true, }, | 325 | { .name = "select", .errmsg = true, .timeout = true, }, |
30 | { .name = "socket", .errmsg = true, }, | 326 | { .name = "socket", .errmsg = true, }, |
31 | { .name = "stat", .errmsg = true, .alias = "newstat", }, | 327 | { .name = "stat", .errmsg = true, .alias = "newstat", }, |
328 | { .name = "uname", .errmsg = true, .alias = "newuname", }, | ||
32 | }; | 329 | }; |
33 | 330 | ||
34 | static int syscall_fmt__cmp(const void *name, const void *fmtp) | 331 | static int syscall_fmt__cmp(const void *name, const void *fmtp) |
@@ -46,7 +343,10 @@ static struct syscall_fmt *syscall_fmt__find(const char *name) | |||
46 | struct syscall { | 343 | struct syscall { |
47 | struct event_format *tp_format; | 344 | struct event_format *tp_format; |
48 | const char *name; | 345 | const char *name; |
346 | bool filtered; | ||
49 | struct syscall_fmt *fmt; | 347 | struct syscall_fmt *fmt; |
348 | size_t (**arg_scnprintf)(char *bf, size_t size, | ||
349 | unsigned long arg, u8 arg_idx, u8 *args_mask); | ||
50 | }; | 350 | }; |
51 | 351 | ||
52 | static size_t fprintf_duration(unsigned long t, FILE *fp) | 352 | static size_t fprintf_duration(unsigned long t, FILE *fp) |
@@ -60,7 +360,7 @@ static size_t fprintf_duration(unsigned long t, FILE *fp) | |||
60 | printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration); | 360 | printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration); |
61 | else | 361 | else |
62 | printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration); | 362 | printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration); |
63 | return printed + fprintf(stdout, "): "); | 363 | return printed + fprintf(fp, "): "); |
64 | } | 364 | } |
65 | 365 | ||
66 | struct thread_trace { | 366 | struct thread_trace { |
@@ -77,7 +377,7 @@ static struct thread_trace *thread_trace__new(void) | |||
77 | return zalloc(sizeof(struct thread_trace)); | 377 | return zalloc(sizeof(struct thread_trace)); |
78 | } | 378 | } |
79 | 379 | ||
80 | static struct thread_trace *thread__trace(struct thread *thread) | 380 | static struct thread_trace *thread__trace(struct thread *thread, FILE *fp) |
81 | { | 381 | { |
82 | struct thread_trace *ttrace; | 382 | struct thread_trace *ttrace; |
83 | 383 | ||
@@ -95,12 +395,13 @@ static struct thread_trace *thread__trace(struct thread *thread) | |||
95 | 395 | ||
96 | return ttrace; | 396 | return ttrace; |
97 | fail: | 397 | fail: |
98 | color_fprintf(stdout, PERF_COLOR_RED, | 398 | color_fprintf(fp, PERF_COLOR_RED, |
99 | "WARNING: not enough memory, dropping samples!\n"); | 399 | "WARNING: not enough memory, dropping samples!\n"); |
100 | return NULL; | 400 | return NULL; |
101 | } | 401 | } |
102 | 402 | ||
103 | struct trace { | 403 | struct trace { |
404 | struct perf_tool tool; | ||
104 | int audit_machine; | 405 | int audit_machine; |
105 | struct { | 406 | struct { |
106 | int max; | 407 | int max; |
@@ -109,7 +410,12 @@ struct trace { | |||
109 | struct perf_record_opts opts; | 410 | struct perf_record_opts opts; |
110 | struct machine host; | 411 | struct machine host; |
111 | u64 base_time; | 412 | u64 base_time; |
413 | FILE *output; | ||
112 | unsigned long nr_events; | 414 | unsigned long nr_events; |
415 | struct strlist *ev_qualifier; | ||
416 | bool not_ev_qualifier; | ||
417 | struct intlist *tid_list; | ||
418 | struct intlist *pid_list; | ||
113 | bool sched; | 419 | bool sched; |
114 | bool multiple_threads; | 420 | bool multiple_threads; |
115 | double duration_filter; | 421 | double duration_filter; |
@@ -142,18 +448,19 @@ static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thre | |||
142 | printed += fprintf_duration(duration, fp); | 448 | printed += fprintf_duration(duration, fp); |
143 | 449 | ||
144 | if (trace->multiple_threads) | 450 | if (trace->multiple_threads) |
145 | printed += fprintf(fp, "%d ", thread->pid); | 451 | printed += fprintf(fp, "%d ", thread->tid); |
146 | 452 | ||
147 | return printed; | 453 | return printed; |
148 | } | 454 | } |
149 | 455 | ||
150 | static int trace__process_event(struct machine *machine, union perf_event *event) | 456 | static int trace__process_event(struct trace *trace, struct machine *machine, |
457 | union perf_event *event) | ||
151 | { | 458 | { |
152 | int ret = 0; | 459 | int ret = 0; |
153 | 460 | ||
154 | switch (event->header.type) { | 461 | switch (event->header.type) { |
155 | case PERF_RECORD_LOST: | 462 | case PERF_RECORD_LOST: |
156 | color_fprintf(stdout, PERF_COLOR_RED, | 463 | color_fprintf(trace->output, PERF_COLOR_RED, |
157 | "LOST %" PRIu64 " events!\n", event->lost.lost); | 464 | "LOST %" PRIu64 " events!\n", event->lost.lost); |
158 | ret = machine__process_lost_event(machine, event); | 465 | ret = machine__process_lost_event(machine, event); |
159 | default: | 466 | default: |
@@ -164,12 +471,13 @@ static int trace__process_event(struct machine *machine, union perf_event *event | |||
164 | return ret; | 471 | return ret; |
165 | } | 472 | } |
166 | 473 | ||
167 | static int trace__tool_process(struct perf_tool *tool __maybe_unused, | 474 | static int trace__tool_process(struct perf_tool *tool, |
168 | union perf_event *event, | 475 | union perf_event *event, |
169 | struct perf_sample *sample __maybe_unused, | 476 | struct perf_sample *sample __maybe_unused, |
170 | struct machine *machine) | 477 | struct machine *machine) |
171 | { | 478 | { |
172 | return trace__process_event(machine, event); | 479 | struct trace *trace = container_of(tool, struct trace, tool); |
480 | return trace__process_event(trace, machine, event); | ||
173 | } | 481 | } |
174 | 482 | ||
175 | static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist) | 483 | static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist) |
@@ -183,11 +491,11 @@ static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist) | |||
183 | machine__create_kernel_maps(&trace->host); | 491 | machine__create_kernel_maps(&trace->host); |
184 | 492 | ||
185 | if (perf_target__has_task(&trace->opts.target)) { | 493 | if (perf_target__has_task(&trace->opts.target)) { |
186 | err = perf_event__synthesize_thread_map(NULL, evlist->threads, | 494 | err = perf_event__synthesize_thread_map(&trace->tool, evlist->threads, |
187 | trace__tool_process, | 495 | trace__tool_process, |
188 | &trace->host); | 496 | &trace->host); |
189 | } else { | 497 | } else { |
190 | err = perf_event__synthesize_threads(NULL, trace__tool_process, | 498 | err = perf_event__synthesize_threads(&trace->tool, trace__tool_process, |
191 | &trace->host); | 499 | &trace->host); |
192 | } | 500 | } |
193 | 501 | ||
@@ -197,6 +505,26 @@ static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist) | |||
197 | return err; | 505 | return err; |
198 | } | 506 | } |
199 | 507 | ||
508 | static int syscall__set_arg_fmts(struct syscall *sc) | ||
509 | { | ||
510 | struct format_field *field; | ||
511 | int idx = 0; | ||
512 | |||
513 | sc->arg_scnprintf = calloc(sc->tp_format->format.nr_fields - 1, sizeof(void *)); | ||
514 | if (sc->arg_scnprintf == NULL) | ||
515 | return -1; | ||
516 | |||
517 | for (field = sc->tp_format->format.fields->next; field; field = field->next) { | ||
518 | if (sc->fmt && sc->fmt->arg_scnprintf[idx]) | ||
519 | sc->arg_scnprintf[idx] = sc->fmt->arg_scnprintf[idx]; | ||
520 | else if (field->flags & FIELD_IS_POINTER) | ||
521 | sc->arg_scnprintf[idx] = syscall_arg__scnprintf_hex; | ||
522 | ++idx; | ||
523 | } | ||
524 | |||
525 | return 0; | ||
526 | } | ||
527 | |||
200 | static int trace__read_syscall_info(struct trace *trace, int id) | 528 | static int trace__read_syscall_info(struct trace *trace, int id) |
201 | { | 529 | { |
202 | char tp_name[128]; | 530 | char tp_name[128]; |
@@ -225,6 +553,20 @@ static int trace__read_syscall_info(struct trace *trace, int id) | |||
225 | 553 | ||
226 | sc = trace->syscalls.table + id; | 554 | sc = trace->syscalls.table + id; |
227 | sc->name = name; | 555 | sc->name = name; |
556 | |||
557 | if (trace->ev_qualifier) { | ||
558 | bool in = strlist__find(trace->ev_qualifier, name) != NULL; | ||
559 | |||
560 | if (!(in ^ trace->not_ev_qualifier)) { | ||
561 | sc->filtered = true; | ||
562 | /* | ||
563 | * No need to do read tracepoint information since this will be | ||
564 | * filtered out. | ||
565 | */ | ||
566 | return 0; | ||
567 | } | ||
568 | } | ||
569 | |||
228 | sc->fmt = syscall_fmt__find(sc->name); | 570 | sc->fmt = syscall_fmt__find(sc->name); |
229 | 571 | ||
230 | snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name); | 572 | snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name); |
@@ -235,7 +577,10 @@ static int trace__read_syscall_info(struct trace *trace, int id) | |||
235 | sc->tp_format = event_format__new("syscalls", tp_name); | 577 | sc->tp_format = event_format__new("syscalls", tp_name); |
236 | } | 578 | } |
237 | 579 | ||
238 | return sc->tp_format != NULL ? 0 : -1; | 580 | if (sc->tp_format == NULL) |
581 | return -1; | ||
582 | |||
583 | return syscall__set_arg_fmts(sc); | ||
239 | } | 584 | } |
240 | 585 | ||
241 | static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size, | 586 | static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size, |
@@ -246,11 +591,23 @@ static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size, | |||
246 | 591 | ||
247 | if (sc->tp_format != NULL) { | 592 | if (sc->tp_format != NULL) { |
248 | struct format_field *field; | 593 | struct format_field *field; |
594 | u8 mask = 0, bit = 1; | ||
595 | |||
596 | for (field = sc->tp_format->format.fields->next; field; | ||
597 | field = field->next, ++i, bit <<= 1) { | ||
598 | if (mask & bit) | ||
599 | continue; | ||
249 | 600 | ||
250 | for (field = sc->tp_format->format.fields->next; field; field = field->next) { | ||
251 | printed += scnprintf(bf + printed, size - printed, | 601 | printed += scnprintf(bf + printed, size - printed, |
252 | "%s%s: %ld", printed ? ", " : "", | 602 | "%s%s: ", printed ? ", " : "", field->name); |
253 | field->name, args[i++]); | 603 | |
604 | if (sc->arg_scnprintf && sc->arg_scnprintf[i]) { | ||
605 | printed += sc->arg_scnprintf[i](bf + printed, size - printed, | ||
606 | args[i], i, &mask); | ||
607 | } else { | ||
608 | printed += scnprintf(bf + printed, size - printed, | ||
609 | "%ld", args[i]); | ||
610 | } | ||
254 | } | 611 | } |
255 | } else { | 612 | } else { |
256 | while (i < 6) { | 613 | while (i < 6) { |
@@ -274,7 +631,22 @@ static struct syscall *trace__syscall_info(struct trace *trace, | |||
274 | int id = perf_evsel__intval(evsel, sample, "id"); | 631 | int id = perf_evsel__intval(evsel, sample, "id"); |
275 | 632 | ||
276 | if (id < 0) { | 633 | if (id < 0) { |
277 | printf("Invalid syscall %d id, skipping...\n", id); | 634 | |
635 | /* | ||
636 | * XXX: Noticed on x86_64, reproduced as far back as 3.0.36, haven't tried | ||
637 | * before that, leaving at a higher verbosity level till that is | ||
638 | * explained. Reproduced with plain ftrace with: | ||
639 | * | ||
640 | * echo 1 > /t/events/raw_syscalls/sys_exit/enable | ||
641 | * grep "NR -1 " /t/trace_pipe | ||
642 | * | ||
643 | * After generating some load on the machine. | ||
644 | */ | ||
645 | if (verbose > 1) { | ||
646 | static u64 n; | ||
647 | fprintf(trace->output, "Invalid syscall %d id, skipping (%s, %" PRIu64 ") ...\n", | ||
648 | id, perf_evsel__name(evsel), ++n); | ||
649 | } | ||
278 | return NULL; | 650 | return NULL; |
279 | } | 651 | } |
280 | 652 | ||
@@ -288,10 +660,12 @@ static struct syscall *trace__syscall_info(struct trace *trace, | |||
288 | return &trace->syscalls.table[id]; | 660 | return &trace->syscalls.table[id]; |
289 | 661 | ||
290 | out_cant_read: | 662 | out_cant_read: |
291 | printf("Problems reading syscall %d", id); | 663 | if (verbose) { |
292 | if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL) | 664 | fprintf(trace->output, "Problems reading syscall %d", id); |
293 | printf("(%s)", trace->syscalls.table[id].name); | 665 | if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL) |
294 | puts(" information"); | 666 | fprintf(trace->output, "(%s)", trace->syscalls.table[id].name); |
667 | fputs(" information\n", trace->output); | ||
668 | } | ||
295 | return NULL; | 669 | return NULL; |
296 | } | 670 | } |
297 | 671 | ||
@@ -301,16 +675,25 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, | |||
301 | char *msg; | 675 | char *msg; |
302 | void *args; | 676 | void *args; |
303 | size_t printed = 0; | 677 | size_t printed = 0; |
304 | struct thread *thread = machine__findnew_thread(&trace->host, sample->tid); | 678 | struct thread *thread; |
305 | struct syscall *sc = trace__syscall_info(trace, evsel, sample); | 679 | struct syscall *sc = trace__syscall_info(trace, evsel, sample); |
306 | struct thread_trace *ttrace = thread__trace(thread); | 680 | struct thread_trace *ttrace; |
681 | |||
682 | if (sc == NULL) | ||
683 | return -1; | ||
307 | 684 | ||
308 | if (ttrace == NULL || sc == NULL) | 685 | if (sc->filtered) |
686 | return 0; | ||
687 | |||
688 | thread = machine__findnew_thread(&trace->host, sample->pid, | ||
689 | sample->tid); | ||
690 | ttrace = thread__trace(thread, trace->output); | ||
691 | if (ttrace == NULL) | ||
309 | return -1; | 692 | return -1; |
310 | 693 | ||
311 | args = perf_evsel__rawptr(evsel, sample, "args"); | 694 | args = perf_evsel__rawptr(evsel, sample, "args"); |
312 | if (args == NULL) { | 695 | if (args == NULL) { |
313 | printf("Problems reading syscall arguments\n"); | 696 | fprintf(trace->output, "Problems reading syscall arguments\n"); |
314 | return -1; | 697 | return -1; |
315 | } | 698 | } |
316 | 699 | ||
@@ -330,8 +713,8 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, | |||
330 | 713 | ||
331 | if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) { | 714 | if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) { |
332 | if (!trace->duration_filter) { | 715 | if (!trace->duration_filter) { |
333 | trace__fprintf_entry_head(trace, thread, 1, sample->time, stdout); | 716 | trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output); |
334 | printf("%-70s\n", ttrace->entry_str); | 717 | fprintf(trace->output, "%-70s\n", ttrace->entry_str); |
335 | } | 718 | } |
336 | } else | 719 | } else |
337 | ttrace->entry_pending = true; | 720 | ttrace->entry_pending = true; |
@@ -344,11 +727,20 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, | |||
344 | { | 727 | { |
345 | int ret; | 728 | int ret; |
346 | u64 duration = 0; | 729 | u64 duration = 0; |
347 | struct thread *thread = machine__findnew_thread(&trace->host, sample->tid); | 730 | struct thread *thread; |
348 | struct thread_trace *ttrace = thread__trace(thread); | ||
349 | struct syscall *sc = trace__syscall_info(trace, evsel, sample); | 731 | struct syscall *sc = trace__syscall_info(trace, evsel, sample); |
732 | struct thread_trace *ttrace; | ||
733 | |||
734 | if (sc == NULL) | ||
735 | return -1; | ||
350 | 736 | ||
351 | if (ttrace == NULL || sc == NULL) | 737 | if (sc->filtered) |
738 | return 0; | ||
739 | |||
740 | thread = machine__findnew_thread(&trace->host, sample->pid, | ||
741 | sample->tid); | ||
742 | ttrace = thread__trace(thread, trace->output); | ||
743 | if (ttrace == NULL) | ||
352 | return -1; | 744 | return -1; |
353 | 745 | ||
354 | ret = perf_evsel__intval(evsel, sample, "ret"); | 746 | ret = perf_evsel__intval(evsel, sample, "ret"); |
@@ -364,28 +756,33 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, | |||
364 | } else if (trace->duration_filter) | 756 | } else if (trace->duration_filter) |
365 | goto out; | 757 | goto out; |
366 | 758 | ||
367 | trace__fprintf_entry_head(trace, thread, duration, sample->time, stdout); | 759 | trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output); |
368 | 760 | ||
369 | if (ttrace->entry_pending) { | 761 | if (ttrace->entry_pending) { |
370 | printf("%-70s", ttrace->entry_str); | 762 | fprintf(trace->output, "%-70s", ttrace->entry_str); |
371 | } else { | 763 | } else { |
372 | printf(" ... ["); | 764 | fprintf(trace->output, " ... ["); |
373 | color_fprintf(stdout, PERF_COLOR_YELLOW, "continued"); | 765 | color_fprintf(trace->output, PERF_COLOR_YELLOW, "continued"); |
374 | printf("]: %s()", sc->name); | 766 | fprintf(trace->output, "]: %s()", sc->name); |
375 | } | 767 | } |
376 | 768 | ||
377 | if (ret < 0 && sc->fmt && sc->fmt->errmsg) { | 769 | if (sc->fmt == NULL) { |
770 | signed_print: | ||
771 | fprintf(trace->output, ") = %d", ret); | ||
772 | } else if (ret < 0 && sc->fmt->errmsg) { | ||
378 | char bf[256]; | 773 | char bf[256]; |
379 | const char *emsg = strerror_r(-ret, bf, sizeof(bf)), | 774 | const char *emsg = strerror_r(-ret, bf, sizeof(bf)), |
380 | *e = audit_errno_to_name(-ret); | 775 | *e = audit_errno_to_name(-ret); |
381 | 776 | ||
382 | printf(") = -1 %s %s", e, emsg); | 777 | fprintf(trace->output, ") = -1 %s %s", e, emsg); |
383 | } else if (ret == 0 && sc->fmt && sc->fmt->timeout) | 778 | } else if (ret == 0 && sc->fmt->timeout) |
384 | printf(") = 0 Timeout"); | 779 | fprintf(trace->output, ") = 0 Timeout"); |
780 | else if (sc->fmt->hexret) | ||
781 | fprintf(trace->output, ") = %#x", ret); | ||
385 | else | 782 | else |
386 | printf(") = %d", ret); | 783 | goto signed_print; |
387 | 784 | ||
388 | putchar('\n'); | 785 | fputc('\n', trace->output); |
389 | out: | 786 | out: |
390 | ttrace->entry_pending = false; | 787 | ttrace->entry_pending = false; |
391 | 788 | ||
@@ -397,8 +794,10 @@ static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evs | |||
397 | { | 794 | { |
398 | u64 runtime = perf_evsel__intval(evsel, sample, "runtime"); | 795 | u64 runtime = perf_evsel__intval(evsel, sample, "runtime"); |
399 | double runtime_ms = (double)runtime / NSEC_PER_MSEC; | 796 | double runtime_ms = (double)runtime / NSEC_PER_MSEC; |
400 | struct thread *thread = machine__findnew_thread(&trace->host, sample->tid); | 797 | struct thread *thread = machine__findnew_thread(&trace->host, |
401 | struct thread_trace *ttrace = thread__trace(thread); | 798 | sample->pid, |
799 | sample->tid); | ||
800 | struct thread_trace *ttrace = thread__trace(thread, trace->output); | ||
402 | 801 | ||
403 | if (ttrace == NULL) | 802 | if (ttrace == NULL) |
404 | goto out_dump; | 803 | goto out_dump; |
@@ -408,7 +807,7 @@ static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evs | |||
408 | return 0; | 807 | return 0; |
409 | 808 | ||
410 | out_dump: | 809 | out_dump: |
411 | printf("%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n", | 810 | fprintf(trace->output, "%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n", |
412 | evsel->name, | 811 | evsel->name, |
413 | perf_evsel__strval(evsel, sample, "comm"), | 812 | perf_evsel__strval(evsel, sample, "comm"), |
414 | (pid_t)perf_evsel__intval(evsel, sample, "pid"), | 813 | (pid_t)perf_evsel__intval(evsel, sample, "pid"), |
@@ -417,6 +816,72 @@ out_dump: | |||
417 | return 0; | 816 | return 0; |
418 | } | 817 | } |
419 | 818 | ||
819 | static bool skip_sample(struct trace *trace, struct perf_sample *sample) | ||
820 | { | ||
821 | if ((trace->pid_list && intlist__find(trace->pid_list, sample->pid)) || | ||
822 | (trace->tid_list && intlist__find(trace->tid_list, sample->tid))) | ||
823 | return false; | ||
824 | |||
825 | if (trace->pid_list || trace->tid_list) | ||
826 | return true; | ||
827 | |||
828 | return false; | ||
829 | } | ||
830 | |||
831 | static int trace__process_sample(struct perf_tool *tool, | ||
832 | union perf_event *event __maybe_unused, | ||
833 | struct perf_sample *sample, | ||
834 | struct perf_evsel *evsel, | ||
835 | struct machine *machine __maybe_unused) | ||
836 | { | ||
837 | struct trace *trace = container_of(tool, struct trace, tool); | ||
838 | int err = 0; | ||
839 | |||
840 | tracepoint_handler handler = evsel->handler.func; | ||
841 | |||
842 | if (skip_sample(trace, sample)) | ||
843 | return 0; | ||
844 | |||
845 | if (trace->base_time == 0) | ||
846 | trace->base_time = sample->time; | ||
847 | |||
848 | if (handler) | ||
849 | handler(trace, evsel, sample); | ||
850 | |||
851 | return err; | ||
852 | } | ||
853 | |||
854 | static bool | ||
855 | perf_session__has_tp(struct perf_session *session, const char *name) | ||
856 | { | ||
857 | struct perf_evsel *evsel; | ||
858 | |||
859 | evsel = perf_evlist__find_tracepoint_by_name(session->evlist, name); | ||
860 | |||
861 | return evsel != NULL; | ||
862 | } | ||
863 | |||
864 | static int parse_target_str(struct trace *trace) | ||
865 | { | ||
866 | if (trace->opts.target.pid) { | ||
867 | trace->pid_list = intlist__new(trace->opts.target.pid); | ||
868 | if (trace->pid_list == NULL) { | ||
869 | pr_err("Error parsing process id string\n"); | ||
870 | return -EINVAL; | ||
871 | } | ||
872 | } | ||
873 | |||
874 | if (trace->opts.target.tid) { | ||
875 | trace->tid_list = intlist__new(trace->opts.target.tid); | ||
876 | if (trace->tid_list == NULL) { | ||
877 | pr_err("Error parsing thread id string\n"); | ||
878 | return -EINVAL; | ||
879 | } | ||
880 | } | ||
881 | |||
882 | return 0; | ||
883 | } | ||
884 | |||
420 | static int trace__run(struct trace *trace, int argc, const char **argv) | 885 | static int trace__run(struct trace *trace, int argc, const char **argv) |
421 | { | 886 | { |
422 | struct perf_evlist *evlist = perf_evlist__new(); | 887 | struct perf_evlist *evlist = perf_evlist__new(); |
@@ -426,32 +891,32 @@ static int trace__run(struct trace *trace, int argc, const char **argv) | |||
426 | const bool forks = argc > 0; | 891 | const bool forks = argc > 0; |
427 | 892 | ||
428 | if (evlist == NULL) { | 893 | if (evlist == NULL) { |
429 | printf("Not enough memory to run!\n"); | 894 | fprintf(trace->output, "Not enough memory to run!\n"); |
430 | goto out; | 895 | goto out; |
431 | } | 896 | } |
432 | 897 | ||
433 | if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) || | 898 | if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) || |
434 | perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) { | 899 | perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) { |
435 | printf("Couldn't read the raw_syscalls tracepoints information!\n"); | 900 | fprintf(trace->output, "Couldn't read the raw_syscalls tracepoints information!\n"); |
436 | goto out_delete_evlist; | 901 | goto out_delete_evlist; |
437 | } | 902 | } |
438 | 903 | ||
439 | if (trace->sched && | 904 | if (trace->sched && |
440 | perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime", | 905 | perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime", |
441 | trace__sched_stat_runtime)) { | 906 | trace__sched_stat_runtime)) { |
442 | printf("Couldn't read the sched_stat_runtime tracepoint information!\n"); | 907 | fprintf(trace->output, "Couldn't read the sched_stat_runtime tracepoint information!\n"); |
443 | goto out_delete_evlist; | 908 | goto out_delete_evlist; |
444 | } | 909 | } |
445 | 910 | ||
446 | err = perf_evlist__create_maps(evlist, &trace->opts.target); | 911 | err = perf_evlist__create_maps(evlist, &trace->opts.target); |
447 | if (err < 0) { | 912 | if (err < 0) { |
448 | printf("Problems parsing the target to trace, check your options!\n"); | 913 | fprintf(trace->output, "Problems parsing the target to trace, check your options!\n"); |
449 | goto out_delete_evlist; | 914 | goto out_delete_evlist; |
450 | } | 915 | } |
451 | 916 | ||
452 | err = trace__symbols_init(trace, evlist); | 917 | err = trace__symbols_init(trace, evlist); |
453 | if (err < 0) { | 918 | if (err < 0) { |
454 | printf("Problems initializing symbol libraries!\n"); | 919 | fprintf(trace->output, "Problems initializing symbol libraries!\n"); |
455 | goto out_delete_maps; | 920 | goto out_delete_maps; |
456 | } | 921 | } |
457 | 922 | ||
@@ -464,20 +929,20 @@ static int trace__run(struct trace *trace, int argc, const char **argv) | |||
464 | err = perf_evlist__prepare_workload(evlist, &trace->opts.target, | 929 | err = perf_evlist__prepare_workload(evlist, &trace->opts.target, |
465 | argv, false, false); | 930 | argv, false, false); |
466 | if (err < 0) { | 931 | if (err < 0) { |
467 | printf("Couldn't run the workload!\n"); | 932 | fprintf(trace->output, "Couldn't run the workload!\n"); |
468 | goto out_delete_maps; | 933 | goto out_delete_maps; |
469 | } | 934 | } |
470 | } | 935 | } |
471 | 936 | ||
472 | err = perf_evlist__open(evlist); | 937 | err = perf_evlist__open(evlist); |
473 | if (err < 0) { | 938 | if (err < 0) { |
474 | printf("Couldn't create the events: %s\n", strerror(errno)); | 939 | fprintf(trace->output, "Couldn't create the events: %s\n", strerror(errno)); |
475 | goto out_delete_maps; | 940 | goto out_delete_maps; |
476 | } | 941 | } |
477 | 942 | ||
478 | err = perf_evlist__mmap(evlist, UINT_MAX, false); | 943 | err = perf_evlist__mmap(evlist, UINT_MAX, false); |
479 | if (err < 0) { | 944 | if (err < 0) { |
480 | printf("Couldn't mmap the events: %s\n", strerror(errno)); | 945 | fprintf(trace->output, "Couldn't mmap the events: %s\n", strerror(errno)); |
481 | goto out_close_evlist; | 946 | goto out_close_evlist; |
482 | } | 947 | } |
483 | 948 | ||
@@ -502,7 +967,7 @@ again: | |||
502 | 967 | ||
503 | err = perf_evlist__parse_sample(evlist, event, &sample); | 968 | err = perf_evlist__parse_sample(evlist, event, &sample); |
504 | if (err) { | 969 | if (err) { |
505 | printf("Can't parse sample, err = %d, skipping...\n", err); | 970 | fprintf(trace->output, "Can't parse sample, err = %d, skipping...\n", err); |
506 | continue; | 971 | continue; |
507 | } | 972 | } |
508 | 973 | ||
@@ -510,18 +975,18 @@ again: | |||
510 | trace->base_time = sample.time; | 975 | trace->base_time = sample.time; |
511 | 976 | ||
512 | if (type != PERF_RECORD_SAMPLE) { | 977 | if (type != PERF_RECORD_SAMPLE) { |
513 | trace__process_event(&trace->host, event); | 978 | trace__process_event(trace, &trace->host, event); |
514 | continue; | 979 | continue; |
515 | } | 980 | } |
516 | 981 | ||
517 | evsel = perf_evlist__id2evsel(evlist, sample.id); | 982 | evsel = perf_evlist__id2evsel(evlist, sample.id); |
518 | if (evsel == NULL) { | 983 | if (evsel == NULL) { |
519 | printf("Unknown tp ID %" PRIu64 ", skipping...\n", sample.id); | 984 | fprintf(trace->output, "Unknown tp ID %" PRIu64 ", skipping...\n", sample.id); |
520 | continue; | 985 | continue; |
521 | } | 986 | } |
522 | 987 | ||
523 | if (sample.raw_data == NULL) { | 988 | if (sample.raw_data == NULL) { |
524 | printf("%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n", | 989 | fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n", |
525 | perf_evsel__name(evsel), sample.tid, | 990 | perf_evsel__name(evsel), sample.tid, |
526 | sample.cpu, sample.raw_size); | 991 | sample.cpu, sample.raw_size); |
527 | continue; | 992 | continue; |
@@ -556,6 +1021,69 @@ out: | |||
556 | return err; | 1021 | return err; |
557 | } | 1022 | } |
558 | 1023 | ||
1024 | static int trace__replay(struct trace *trace) | ||
1025 | { | ||
1026 | const struct perf_evsel_str_handler handlers[] = { | ||
1027 | { "raw_syscalls:sys_enter", trace__sys_enter, }, | ||
1028 | { "raw_syscalls:sys_exit", trace__sys_exit, }, | ||
1029 | }; | ||
1030 | |||
1031 | struct perf_session *session; | ||
1032 | int err = -1; | ||
1033 | |||
1034 | trace->tool.sample = trace__process_sample; | ||
1035 | trace->tool.mmap = perf_event__process_mmap; | ||
1036 | trace->tool.comm = perf_event__process_comm; | ||
1037 | trace->tool.exit = perf_event__process_exit; | ||
1038 | trace->tool.fork = perf_event__process_fork; | ||
1039 | trace->tool.attr = perf_event__process_attr; | ||
1040 | trace->tool.tracing_data = perf_event__process_tracing_data; | ||
1041 | trace->tool.build_id = perf_event__process_build_id; | ||
1042 | |||
1043 | trace->tool.ordered_samples = true; | ||
1044 | trace->tool.ordering_requires_timestamps = true; | ||
1045 | |||
1046 | /* add tid to output */ | ||
1047 | trace->multiple_threads = true; | ||
1048 | |||
1049 | if (symbol__init() < 0) | ||
1050 | return -1; | ||
1051 | |||
1052 | session = perf_session__new(input_name, O_RDONLY, 0, false, | ||
1053 | &trace->tool); | ||
1054 | if (session == NULL) | ||
1055 | return -ENOMEM; | ||
1056 | |||
1057 | err = perf_session__set_tracepoints_handlers(session, handlers); | ||
1058 | if (err) | ||
1059 | goto out; | ||
1060 | |||
1061 | if (!perf_session__has_tp(session, "raw_syscalls:sys_enter")) { | ||
1062 | pr_err("Data file does not have raw_syscalls:sys_enter events\n"); | ||
1063 | goto out; | ||
1064 | } | ||
1065 | |||
1066 | if (!perf_session__has_tp(session, "raw_syscalls:sys_exit")) { | ||
1067 | pr_err("Data file does not have raw_syscalls:sys_exit events\n"); | ||
1068 | goto out; | ||
1069 | } | ||
1070 | |||
1071 | err = parse_target_str(trace); | ||
1072 | if (err != 0) | ||
1073 | goto out; | ||
1074 | |||
1075 | setup_pager(); | ||
1076 | |||
1077 | err = perf_session__process_events(session, &trace->tool); | ||
1078 | if (err) | ||
1079 | pr_err("Failed to process events, error %d", err); | ||
1080 | |||
1081 | out: | ||
1082 | perf_session__delete(session); | ||
1083 | |||
1084 | return err; | ||
1085 | } | ||
1086 | |||
559 | static size_t trace__fprintf_threads_header(FILE *fp) | 1087 | static size_t trace__fprintf_threads_header(FILE *fp) |
560 | { | 1088 | { |
561 | size_t printed; | 1089 | size_t printed; |
@@ -593,7 +1121,7 @@ static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp) | |||
593 | color = PERF_COLOR_YELLOW; | 1121 | color = PERF_COLOR_YELLOW; |
594 | 1122 | ||
595 | printed += color_fprintf(fp, color, "%20s", thread->comm); | 1123 | printed += color_fprintf(fp, color, "%20s", thread->comm); |
596 | printed += fprintf(fp, " - %-5d :%11lu [", thread->pid, ttrace->nr_events); | 1124 | printed += fprintf(fp, " - %-5d :%11lu [", thread->tid, ttrace->nr_events); |
597 | printed += color_fprintf(fp, color, "%5.1f%%", ratio); | 1125 | printed += color_fprintf(fp, color, "%5.1f%%", ratio); |
598 | printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms); | 1126 | printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms); |
599 | } | 1127 | } |
@@ -610,6 +1138,23 @@ static int trace__set_duration(const struct option *opt, const char *str, | |||
610 | return 0; | 1138 | return 0; |
611 | } | 1139 | } |
612 | 1140 | ||
1141 | static int trace__open_output(struct trace *trace, const char *filename) | ||
1142 | { | ||
1143 | struct stat st; | ||
1144 | |||
1145 | if (!stat(filename, &st) && st.st_size) { | ||
1146 | char oldname[PATH_MAX]; | ||
1147 | |||
1148 | scnprintf(oldname, sizeof(oldname), "%s.old", filename); | ||
1149 | unlink(oldname); | ||
1150 | rename(filename, oldname); | ||
1151 | } | ||
1152 | |||
1153 | trace->output = fopen(filename, "w"); | ||
1154 | |||
1155 | return trace->output == NULL ? -errno : 0; | ||
1156 | } | ||
1157 | |||
613 | int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) | 1158 | int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) |
614 | { | 1159 | { |
615 | const char * const trace_usage[] = { | 1160 | const char * const trace_usage[] = { |
@@ -632,26 +1177,34 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) | |||
632 | .no_delay = true, | 1177 | .no_delay = true, |
633 | .mmap_pages = 1024, | 1178 | .mmap_pages = 1024, |
634 | }, | 1179 | }, |
1180 | .output = stdout, | ||
635 | }; | 1181 | }; |
1182 | const char *output_name = NULL; | ||
1183 | const char *ev_qualifier_str = NULL; | ||
636 | const struct option trace_options[] = { | 1184 | const struct option trace_options[] = { |
1185 | OPT_STRING('e', "expr", &ev_qualifier_str, "expr", | ||
1186 | "list of events to trace"), | ||
1187 | OPT_STRING('o', "output", &output_name, "file", "output file name"), | ||
1188 | OPT_STRING('i', "input", &input_name, "file", "Analyze events in file"), | ||
637 | OPT_STRING('p', "pid", &trace.opts.target.pid, "pid", | 1189 | OPT_STRING('p', "pid", &trace.opts.target.pid, "pid", |
638 | "trace events on existing process id"), | 1190 | "trace events on existing process id"), |
639 | OPT_STRING(0, "tid", &trace.opts.target.tid, "tid", | 1191 | OPT_STRING('t', "tid", &trace.opts.target.tid, "tid", |
640 | "trace events on existing thread id"), | 1192 | "trace events on existing thread id"), |
641 | OPT_BOOLEAN(0, "all-cpus", &trace.opts.target.system_wide, | 1193 | OPT_BOOLEAN('a', "all-cpus", &trace.opts.target.system_wide, |
642 | "system-wide collection from all CPUs"), | 1194 | "system-wide collection from all CPUs"), |
643 | OPT_STRING(0, "cpu", &trace.opts.target.cpu_list, "cpu", | 1195 | OPT_STRING('C', "cpu", &trace.opts.target.cpu_list, "cpu", |
644 | "list of cpus to monitor"), | 1196 | "list of cpus to monitor"), |
645 | OPT_BOOLEAN(0, "no-inherit", &trace.opts.no_inherit, | 1197 | OPT_BOOLEAN(0, "no-inherit", &trace.opts.no_inherit, |
646 | "child tasks do not inherit counters"), | 1198 | "child tasks do not inherit counters"), |
647 | OPT_UINTEGER(0, "mmap-pages", &trace.opts.mmap_pages, | 1199 | OPT_UINTEGER('m', "mmap-pages", &trace.opts.mmap_pages, |
648 | "number of mmap data pages"), | 1200 | "number of mmap data pages"), |
649 | OPT_STRING(0, "uid", &trace.opts.target.uid_str, "user", | 1201 | OPT_STRING('u', "uid", &trace.opts.target.uid_str, "user", |
650 | "user to profile"), | 1202 | "user to profile"), |
651 | OPT_CALLBACK(0, "duration", &trace, "float", | 1203 | OPT_CALLBACK(0, "duration", &trace, "float", |
652 | "show only events with duration > N.M ms", | 1204 | "show only events with duration > N.M ms", |
653 | trace__set_duration), | 1205 | trace__set_duration), |
654 | OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"), | 1206 | OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"), |
1207 | OPT_INCR('v', "verbose", &verbose, "be more verbose"), | ||
655 | OPT_END() | 1208 | OPT_END() |
656 | }; | 1209 | }; |
657 | int err; | 1210 | int err; |
@@ -659,27 +1212,57 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) | |||
659 | 1212 | ||
660 | argc = parse_options(argc, argv, trace_options, trace_usage, 0); | 1213 | argc = parse_options(argc, argv, trace_options, trace_usage, 0); |
661 | 1214 | ||
1215 | if (output_name != NULL) { | ||
1216 | err = trace__open_output(&trace, output_name); | ||
1217 | if (err < 0) { | ||
1218 | perror("failed to create output file"); | ||
1219 | goto out; | ||
1220 | } | ||
1221 | } | ||
1222 | |||
1223 | if (ev_qualifier_str != NULL) { | ||
1224 | const char *s = ev_qualifier_str; | ||
1225 | |||
1226 | trace.not_ev_qualifier = *s == '!'; | ||
1227 | if (trace.not_ev_qualifier) | ||
1228 | ++s; | ||
1229 | trace.ev_qualifier = strlist__new(true, s); | ||
1230 | if (trace.ev_qualifier == NULL) { | ||
1231 | fputs("Not enough memory to parse event qualifier", | ||
1232 | trace.output); | ||
1233 | err = -ENOMEM; | ||
1234 | goto out_close; | ||
1235 | } | ||
1236 | } | ||
1237 | |||
662 | err = perf_target__validate(&trace.opts.target); | 1238 | err = perf_target__validate(&trace.opts.target); |
663 | if (err) { | 1239 | if (err) { |
664 | perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf)); | 1240 | perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf)); |
665 | printf("%s", bf); | 1241 | fprintf(trace.output, "%s", bf); |
666 | return err; | 1242 | goto out_close; |
667 | } | 1243 | } |
668 | 1244 | ||
669 | err = perf_target__parse_uid(&trace.opts.target); | 1245 | err = perf_target__parse_uid(&trace.opts.target); |
670 | if (err) { | 1246 | if (err) { |
671 | perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf)); | 1247 | perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf)); |
672 | printf("%s", bf); | 1248 | fprintf(trace.output, "%s", bf); |
673 | return err; | 1249 | goto out_close; |
674 | } | 1250 | } |
675 | 1251 | ||
676 | if (!argc && perf_target__none(&trace.opts.target)) | 1252 | if (!argc && perf_target__none(&trace.opts.target)) |
677 | trace.opts.target.system_wide = true; | 1253 | trace.opts.target.system_wide = true; |
678 | 1254 | ||
679 | err = trace__run(&trace, argc, argv); | 1255 | if (input_name) |
1256 | err = trace__replay(&trace); | ||
1257 | else | ||
1258 | err = trace__run(&trace, argc, argv); | ||
680 | 1259 | ||
681 | if (trace.sched && !err) | 1260 | if (trace.sched && !err) |
682 | trace__fprintf_thread_summary(&trace, stdout); | 1261 | trace__fprintf_thread_summary(&trace, trace.output); |
683 | 1262 | ||
1263 | out_close: | ||
1264 | if (output_name != NULL) | ||
1265 | fclose(trace.output); | ||
1266 | out: | ||
684 | return err; | 1267 | return err; |
685 | } | 1268 | } |