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