1 // SPDX-License-Identifier: GPL-2.0
2 /*
3 * Copyright (C) 2009, 2010 Red Hat Inc, Steven Rostedt <srostedt@redhat.com>
4 *
5 */
6 #include <dirent.h>
7 #include <stdio.h>
8 #include <stdlib.h>
9 #include <string.h>
10 #include <getopt.h>
11 #include <stdarg.h>
12 #include <sys/types.h>
13 #include <sys/stat.h>
14 #include <sys/wait.h>
15 #include <sys/mman.h>
16 #include <fcntl.h>
17 #include <signal.h>
18 #include <unistd.h>
19 #include <ctype.h>
20 #include <errno.h>
21
22 #include "trace-local.h"
23 #include "trace-hash.h"
24 #include "trace-hash-local.h"
25 #include "kbuffer.h"
26 #include "list.h"
27
28 /*
29 * tep_func_repeat_format is defined as a weak variable in the
30 * libtraceevent library function plugin, to allow applications
31 * to override the format of the timestamp it prints for the
32 * last function that repeated.
33 */
34 const char *tep_func_repeat_format;
35
36 static struct filter_str {
37 struct filter_str *next;
38 char *filter;
39 int neg;
40 } *filter_strings;
41 static struct filter_str **filter_next = &filter_strings;
42
43 struct event_str {
44 struct event_str *next;
45 const char *event;
46 };
47
48 struct input_files;
49
50 struct handle_list {
51 struct list_head list;
52 struct tracecmd_input *handle;
53 struct input_files *input_file;
54 const char *file;
55 int cpus;
56 };
57 static struct list_head handle_list;
58
59 struct input_files {
60 struct list_head list;
61 const char *file;
62 struct filter_str *filter_str;
63 struct filter_str **filter_str_next;
64 long long tsoffset;
65 unsigned long long ts2secs;
66 };
67 static struct list_head input_files;
68 static struct input_files *last_input_file;
69
70 struct pid_list {
71 struct pid_list *next;
72 char *pid;
73 int free;
74 } *pid_list;
75
76 struct pid_list *comm_list;
77
78 static unsigned int page_size;
79 static int input_fd;
80 static const char *default_input_file = DEFAULT_INPUT_FILE;
81 static const char *input_file;
82 static int multi_inputs;
83 static int max_file_size;
84
85 static int instances;
86
87 static int *filter_cpus;
88 static int nr_filter_cpus;
89 static int test_filters_mode;
90
91 static int show_wakeup;
92 static int wakeup_id;
93 static int wakeup_new_id;
94 static int sched_id;
95
96 static int profile;
97
98 static int buffer_breaks = 0;
99
100 static int no_irqs;
101 static int no_softirqs;
102
103 static int tsdiff;
104 static int tscheck;
105
106 static int latency_format;
107 static bool raw_format;
108 static const char *format_type = TEP_PRINT_INFO;
109
110 static struct tep_format_field *wakeup_task;
111 static struct tep_format_field *wakeup_success;
112 static struct tep_format_field *wakeup_new_task;
113 static struct tep_format_field *wakeup_new_success;
114 static struct tep_format_field *sched_task;
115 static struct tep_format_field *sched_prio;
116
117 static unsigned long long total_wakeup_lat;
118 static unsigned long wakeup_lat_count;
119
120 static unsigned long long total_wakeup_rt_lat;
121 static unsigned long wakeup_rt_lat_count;
122
123 struct wakeup_info {
124 struct trace_hash_item hash;
125 unsigned long long start;
126 int pid;
127 };
128
129 static struct hook_list *hooks;
130 static struct hook_list *last_hook;
131
132 #define WAKEUP_HASH_SIZE 1024
133 static struct trace_hash wakeup_hash;
134
print_event_name(struct trace_seq * s,struct tep_event * event)135 static void print_event_name(struct trace_seq *s, struct tep_event *event)
136 {
137 static const char *spaces = " "; /* 20 spaces */
138 const char *name;
139 int len;
140
141 name = event ? event->name : "(NULL)";
142
143 trace_seq_printf(s, " %s: ", name);
144
145 /* Space out the event names evenly. */
146 len = strlen(name);
147 if (len < 20)
148 trace_seq_printf(s, "%.*s", 20 - len, spaces);
149 }
150
151 enum time_fmt {
152 TIME_FMT_LAT = 1,
153 TIME_FMT_NORMAL,
154 TIME_FMT_TS,
155 };
156
time_format(struct tracecmd_input * handle,enum time_fmt tf)157 static const char *time_format(struct tracecmd_input *handle, enum time_fmt tf)
158 {
159 struct tep_handle *tep = tracecmd_get_tep(handle);
160
161 switch (tf) {
162 case TIME_FMT_LAT:
163 if (latency_format)
164 return "%8.8s-%-5d %3d";
165 return "%16s-%-5d [%03d]";
166 default:
167 if (tracecmd_get_flags(handle) & TRACECMD_FL_IN_USECS) {
168 if (tep_test_flag(tep, TEP_NSEC_OUTPUT))
169 return tf == TIME_FMT_NORMAL ? " %9.1d:" : "%9.1d";
170 else
171 return tf == TIME_FMT_NORMAL ? " %6.1000d:" : "%6.1000d";
172 } else
173 return tf == TIME_FMT_NORMAL ? "%12d:" : "%12d";
174 }
175 }
176
print_event(struct trace_seq * s,struct tracecmd_input * handle,struct tep_record * record)177 static void print_event(struct trace_seq *s, struct tracecmd_input *handle,
178 struct tep_record *record)
179 {
180 struct tep_handle *tep = tracecmd_get_tep(handle);
181 struct tep_event *event;
182 const char *lfmt = time_format(handle, TIME_FMT_LAT);
183 const char *tfmt = time_format(handle, TIME_FMT_NORMAL);
184
185 event = tep_find_event_by_record(tep, record);
186 tep_print_event(tep, s, record, lfmt, TEP_PRINT_COMM,
187 TEP_PRINT_PID, TEP_PRINT_CPU);
188 tep_print_event(tep, s, record, tfmt, TEP_PRINT_TIME);
189 print_event_name(s, event);
190 tep_print_event(tep, s, record, "%s", format_type);
191 }
192
193 /* Debug variables for testing tracecmd_read_at */
194 #define TEST_READ_AT 0
195 #if TEST_READ_AT
196 #define DO_TEST
197 static off_t test_read_at_offset;
198 static int test_read_at_copy = 100;
199 static int test_read_at_index;
show_test(struct tracecmd_input * handle)200 static void show_test(struct tracecmd_input *handle)
201 {
202 struct tep_record *record;
203 struct trace_seq s;
204
205 if (!test_read_at_offset) {
206 printf("\nNO RECORD COPIED\n");
207 return;
208 }
209
210 record = tracecmd_read_at(handle, test_read_at_offset, NULL);
211 printf("\nHERE'S THE COPY RECORD\n");
212 trace_seq_init(&s);
213 print_event(&s, handle, record);
214 trace_seq_do_printf(&s);
215 trace_seq_destroy(&s);
216 printf("\n");
217
218 tracecmd_free_record(record);
219 }
220
test_save(struct tep_record * record,int cpu)221 static void test_save(struct tep_record *record, int cpu)
222 {
223 if (test_read_at_index++ == test_read_at_copy) {
224 test_read_at_offset = record->offset;
225 printf("\nUSING THIS RECORD\n");
226 }
227 }
228 #endif /* TEST_READ_AT */
229
230 /* Debug variables for testing tracecmd_set_cpu_at_timestamp */
231 #define TEST_AT_TIMESTAMP 0
232 #if TEST_AT_TIMESTAMP
233 #define DO_TEST
234 static unsigned long long test_at_timestamp_ts;
235 static int test_at_timestamp_copy = 100;
236 static int test_at_timestamp_cpu = -1;
237 static int test_at_timestamp_index;
show_test(struct tracecmd_input * handle)238 static void show_test(struct tracecmd_input *handle)
239 {
240 struct tep_record *record;
241 struct trace_seq s;
242 int cpu = test_at_timestamp_cpu;
243
244 if (!test_at_timestamp_ts) {
245 printf("\nNO RECORD COPIED\n");
246 return;
247 }
248
249 if (tracecmd_set_cpu_to_timestamp(handle, cpu, test_at_timestamp_ts))
250 return;
251
252 record = tracecmd_read_data(handle, cpu);
253 printf("\nHERE'S THE COPY RECORD with page %p offset=%p\n",
254 (void *)(record->offset & ~(page_size - 1)),
255 (void *)record->offset);
256 trace_seq_init(&s);
257 print_event(&s, handle, record);
258 trace_seq_do_printf(&s);
259 trace_seq_destroy(&s);
260 printf("\n");
261
262 tracecmd_free_record(record);
263 }
264
test_save(struct tep_record * record,int cpu)265 static void test_save(struct tep_record *record, int cpu)
266 {
267 if (test_at_timestamp_index++ == test_at_timestamp_copy) {
268 test_at_timestamp_ts = record->ts;
269 test_at_timestamp_cpu = cpu;
270 printf("\nUSING THIS RECORD page=%p offset=%p\n",
271 (void *)(record->offset & ~(page_size - 1)),
272 (void *)record->offset);
273 }
274 }
275 #endif /* TEST_AT_TIMESTAMP */
276
277 #define TEST_FIRST_LAST 0
278 #if TEST_FIRST_LAST
279 #define DO_TEST
show_test(struct tracecmd_input * handle)280 static void show_test(struct tracecmd_input *handle)
281 {
282 struct tep_record *record;
283 struct trace_seq s;
284 int cpu = 0;
285
286 record = tracecmd_read_cpu_first(handle, cpu);
287 if (!record) {
288 printf("No first record?\n");
289 return;
290 }
291
292 printf("\nHERE'S THE FIRST RECORD with offset %p\n",
293 (void *)record->offset);
294 trace_seq_init(&s);
295 print_event(&s, handle, record);
296 trace_seq_do_printf(&s);
297 trace_seq_destroy(&s);
298 printf("\n");
299
300 tracecmd_free_record(record);
301
302 record = tracecmd_read_cpu_last(handle, cpu);
303 if (!record) {
304 printf("No last record?\n");
305 return;
306 }
307
308 printf("\nHERE'S THE LAST RECORD with offset %p\n",
309 (void *)record->offset);
310 trace_seq_init(&s);
311 print_event(&s, handle, record);
312 trace_seq_do_printf(&s);
313 trace_seq_destroy(&s);
314 printf("\n");
315
316 tracecmd_free_record(record);
317 }
test_save(struct tep_record * record,int cpu)318 static void test_save(struct tep_record *record, int cpu)
319 {
320 }
321 #endif /* TEST_FIRST_LAST */
322
323 #ifndef DO_TEST
show_test(struct tracecmd_input * handle)324 static void show_test(struct tracecmd_input *handle)
325 {
326 /* quiet the compiler */
327 if (0)
328 print_event(NULL, NULL, NULL);
329 }
test_save(struct tep_record * record,int cpu)330 static void test_save(struct tep_record *record, int cpu)
331 {
332 }
333 #endif
334
free_filter_strings(struct filter_str * filter_str)335 static void free_filter_strings(struct filter_str *filter_str)
336 {
337 struct filter_str *filter;
338
339 while (filter_str) {
340 filter = filter_str;
341 filter_str = filter->next;
342 free(filter->filter);
343 free(filter);
344 }
345 }
346
add_input(const char * file)347 static struct input_files *add_input(const char *file)
348 {
349 struct input_files *item;
350
351 item = calloc(1, sizeof(*item));
352 if (!item)
353 die("Failed to allocate for %s", file);
354 item->file = file;
355 item->filter_str_next = &item->filter_str;
356 list_add_tail(&item->list, &input_files);
357 last_input_file = item;
358 return item;
359 }
360
add_handle(struct tracecmd_input * handle,struct input_files * input_files)361 static void add_handle(struct tracecmd_input *handle, struct input_files *input_files)
362 {
363 struct handle_list *item;
364 const char *file = input_files ? input_files->file : input_file;
365
366 item = calloc(1, sizeof(*item));
367 if (!item)
368 die("Failed ot allocate for %s", file);
369 item->handle = handle;
370 if (input_files) {
371 item->file = file + strlen(file);
372 /* we want just the base name */
373 while (item->file >= file && *item->file != '/')
374 item->file--;
375 item->file++;
376 if (strlen(item->file) > max_file_size)
377 max_file_size = strlen(item->file);
378
379 item->input_file = input_files;
380 }
381 list_add_tail(&item->list, &handle_list);
382 }
383
free_inputs(void)384 static void free_inputs(void)
385 {
386 struct input_files *item;
387
388 while (!list_empty(&input_files)) {
389 item = container_of(input_files.next, struct input_files, list);
390 list_del(&item->list);
391 free_filter_strings(item->filter_str);
392 free(item);
393 }
394 }
395
free_handles(void)396 static void free_handles(void)
397 {
398 struct handle_list *item;
399
400 while (!list_empty(&handle_list)) {
401 item = container_of(handle_list.next, struct handle_list, list);
402 list_del(&item->list);
403 free(item);
404 }
405 }
406
add_filter(struct input_files * input_file,const char * filter,int neg)407 static void add_filter(struct input_files *input_file, const char *filter, int neg)
408 {
409 struct filter_str *ftr;
410
411 ftr = malloc(sizeof(*ftr));
412 if (!ftr)
413 die("Failed to allocate for filter %s", filter);
414 ftr->filter = strdup(filter);
415 if (!ftr->filter)
416 die("malloc");
417 ftr->next = NULL;
418 ftr->neg = neg;
419
420 /* must maintain order of command line */
421 if (input_file) {
422 *input_file->filter_str_next = ftr;
423 input_file->filter_str_next = &ftr->next;
424 } else {
425 *filter_next = ftr;
426 filter_next = &ftr->next;
427 }
428 }
429
__add_filter(struct pid_list ** head,const char * arg)430 static void __add_filter(struct pid_list **head, const char *arg)
431 {
432 struct pid_list *list;
433 char *pids = strdup(arg);
434 char *pid;
435 char *sav;
436 int free = 1;
437
438 if (!pids)
439 die("malloc");
440
441 pid = strtok_r(pids, ",", &sav);
442 while (pid) {
443 list = malloc(sizeof(*list));
444 if (!list)
445 die("Failed to allocate for arg %s", arg);
446 list->pid = pid;
447 list->free = free;
448 list->next = *head;
449 *head = list;
450 /* The first pid needs to be freed */
451 free = 0;
452 pid = strtok_r(NULL, ",", &sav);
453 }
454 }
455
add_comm_filter(const char * arg)456 static void add_comm_filter(const char *arg)
457 {
458 __add_filter(&comm_list, arg);
459 }
460
add_pid_filter(const char * arg)461 static void add_pid_filter(const char *arg)
462 {
463 __add_filter(&pid_list, arg);
464 }
465
append_pid_filter(char * curr_filter,char * pid)466 static char *append_pid_filter(char *curr_filter, char *pid)
467 {
468 char *filter;
469 int len, curr_len;
470
471 #define FILTER_FMT "(common_pid==" __STR ")||(pid==" __STR ")||(next_pid==" __STR ")"
472
473 #undef __STR
474 #define __STR ""
475
476 /* strlen(".*:") > strlen("||") */
477 len = strlen(".*:" FILTER_FMT) + strlen(pid) * 3 + 1;
478
479 #undef __STR
480 #define __STR "%s"
481
482 if (!curr_filter) {
483 filter = malloc(len);
484 if (!filter)
485 die("Failed to allocate pid filter");
486 sprintf(filter, ".*:" FILTER_FMT, pid, pid, pid);
487 } else {
488 curr_len = strlen(curr_filter);
489 len += curr_len;
490
491 filter = realloc(curr_filter, len);
492 if (!filter)
493 die("realloc");
494 sprintf(filter + curr_len, "||" FILTER_FMT, pid, pid, pid);
495 }
496
497 return filter;
498 }
499
convert_comm_filter(struct tracecmd_input * handle)500 static void convert_comm_filter(struct tracecmd_input *handle)
501 {
502 struct tep_cmdline *cmdline;
503 struct tep_handle *pevent;
504 struct pid_list *list;
505
506 char pidstr[100];
507
508 if (!comm_list)
509 return;
510
511 pevent = tracecmd_get_tep(handle);
512
513 /* Seach for comm names and get their pids */
514 for (list = comm_list; list; list = list->next) {
515 cmdline = tep_data_pid_from_comm(pevent, list->pid, NULL);
516 if (!cmdline) {
517 warning("comm: %s not in cmdline list", list->pid);
518 continue;
519 }
520 do {
521 sprintf(pidstr, "%d", tep_cmdline_pid(pevent, cmdline));
522 add_pid_filter(pidstr);
523 cmdline = tep_data_pid_from_comm(pevent, list->pid,
524 cmdline);
525 } while (cmdline);
526 }
527
528 while (comm_list) {
529 list = comm_list;
530 comm_list = comm_list->next;
531 if (list->free)
532 free(list->pid);
533 free(list);
534 }
535 }
536
make_pid_filter(struct tracecmd_input * handle,struct input_files * input_files)537 static void make_pid_filter(struct tracecmd_input *handle,
538 struct input_files *input_files)
539 {
540 struct pid_list *list;
541 char *str = NULL;
542
543 convert_comm_filter(handle);
544
545 if (!pid_list)
546 return;
547
548 /* First do all common pids */
549 for (list = pid_list; list; list = list->next) {
550 str = append_pid_filter(str, list->pid);
551 }
552
553 add_filter(input_files, str, 0);
554 free(str);
555
556 while (pid_list) {
557 list = pid_list;
558 pid_list = pid_list->next;
559 if (list->free)
560 free(list->pid);
561 free(list);
562 }
563 }
564
__process_filters(struct tracecmd_input * handle,struct filter_str * filters)565 static int __process_filters(struct tracecmd_input *handle,
566 struct filter_str *filters)
567 {
568 struct tracecmd_filter *trace_filter;
569
570 for (; filters; filters = filters->next) {
571 trace_filter = tracecmd_filter_add(handle,
572 filters->filter,
573 filters->neg);
574 if (!trace_filter)
575 die("Failed to create event filter: %s",
576 filters->filter);
577 }
578
579 return !!filters;
580 }
581
process_filters(struct handle_list * handles)582 static void process_filters(struct handle_list *handles)
583 {
584 struct input_files *input_file = handles->input_file ?: last_input_file;
585 int added = 0;
586
587 make_pid_filter(handles->handle, input_file);
588
589 /*
590 * Order of filter processing matters. Apply the global filters
591 * before file-specific ones.
592 */
593 added += __process_filters(handles->handle, filter_strings);
594 if (input_file)
595 added += __process_filters(handles->handle,
596 input_file->filter_str);
597
598 if (added && test_filters_mode)
599 exit(0);
600 }
601
init_wakeup(struct tracecmd_input * handle)602 static void init_wakeup(struct tracecmd_input *handle)
603 {
604 struct tep_handle *pevent;
605 struct tep_event *event;
606
607 if (!show_wakeup)
608 return;
609
610 pevent = tracecmd_get_tep(handle);
611
612 trace_hash_init(&wakeup_hash, WAKEUP_HASH_SIZE);
613
614 event = tep_find_event_by_name(pevent, "sched", "sched_wakeup");
615 if (!event)
616 goto fail;
617 wakeup_id = event->id;
618 wakeup_task = tep_find_field(event, "pid");
619 if (!wakeup_task)
620 goto fail;
621 wakeup_success = tep_find_field(event, "success");
622
623 event = tep_find_event_by_name(pevent, "sched", "sched_switch");
624 if (!event)
625 goto fail;
626 sched_id = event->id;
627 sched_task = tep_find_field(event, "next_pid");
628 if (!sched_task)
629 goto fail;
630
631 sched_prio = tep_find_field(event, "next_prio");
632 if (!sched_prio)
633 goto fail;
634
635
636 wakeup_new_id = -1;
637
638 event = tep_find_event_by_name(pevent, "sched", "sched_wakeup_new");
639 if (!event)
640 goto skip;
641 wakeup_new_id = event->id;
642 wakeup_new_task = tep_find_field(event, "pid");
643 if (!wakeup_new_task)
644 goto fail;
645 wakeup_new_success = tep_find_field(event, "success");
646
647 skip:
648 return;
649
650 fail:
651 show_wakeup = 0;
652 }
653
add_wakeup(unsigned int val,unsigned long long start)654 static void add_wakeup(unsigned int val, unsigned long long start)
655 {
656 unsigned int key = trace_hash(val);
657 struct wakeup_info *info;
658 struct trace_hash_item *item;
659
660 item = trace_hash_find(&wakeup_hash, key, NULL, NULL);
661 if (item) {
662 info = container_of(item, struct wakeup_info, hash);
663 /* Hmm, double wakeup? */
664 info->start = start;
665 return;
666 }
667
668 info = malloc(sizeof(*info));
669 if (!info)
670 die("Failed to allocate wakeup info");
671 info->hash.key = key;
672 info->start = start;
673 trace_hash_add(&wakeup_hash, &info->hash);
674 }
675
676 static unsigned long long max_lat = 0;
677 static unsigned long long max_time;
678 static unsigned long long min_lat = -1;
679 static unsigned long long min_time;
680
681 static unsigned long long max_rt_lat = 0;
682 static unsigned long long max_rt_time;
683 static unsigned long long min_rt_lat = -1;
684 static unsigned long long min_rt_time;
685
add_sched(unsigned int val,unsigned long long end,int rt)686 static void add_sched(unsigned int val, unsigned long long end, int rt)
687 {
688 struct trace_hash_item *item;
689 unsigned int key = trace_hash(val);
690 struct wakeup_info *info;
691 unsigned long long cal;
692
693 item = trace_hash_find(&wakeup_hash, key, NULL, NULL);
694 if (!item)
695 return;
696
697 info = container_of(item, struct wakeup_info, hash);
698
699 cal = end - info->start;
700
701 if (cal > max_lat) {
702 max_lat = cal;
703 max_time = end;
704 }
705 if (cal < min_lat) {
706 min_lat = cal;
707 min_time = end;
708 }
709
710 if (rt) {
711 if (cal > max_rt_lat) {
712 max_rt_lat = cal;
713 max_rt_time = end;
714 }
715 if (cal < min_rt_lat) {
716 min_rt_lat = cal;
717 min_rt_time = end;
718 }
719 }
720
721 printf(" Latency: %llu.%03llu usecs", cal / 1000, cal % 1000);
722
723 total_wakeup_lat += cal;
724 wakeup_lat_count++;
725
726 if (rt) {
727 total_wakeup_rt_lat += cal;
728 wakeup_rt_lat_count++;
729 }
730
731 trace_hash_del(item);
732 free(info);
733 }
734
process_wakeup(struct tep_handle * pevent,struct tep_record * record)735 static void process_wakeup(struct tep_handle *pevent, struct tep_record *record)
736 {
737 unsigned long long val;
738 int id;
739
740 if (!show_wakeup)
741 return;
742
743 id = tep_data_type(pevent, record);
744 if (id == wakeup_id) {
745 if (tep_read_number_field(wakeup_success, record->data, &val) == 0) {
746 if (!val)
747 return;
748 }
749 if (tep_read_number_field(wakeup_task, record->data, &val))
750 return;
751 add_wakeup(val, record->ts);
752 } else if (id == wakeup_new_id) {
753 if (tep_read_number_field(wakeup_new_success, record->data, &val) == 0) {
754 if (!val)
755 return;
756 }
757 if (tep_read_number_field(wakeup_new_task, record->data, &val))
758 return;
759 add_wakeup(val, record->ts);
760 } else if (id == sched_id) {
761 int rt = 1;
762 if (tep_read_number_field(sched_prio, record->data, &val))
763 return;
764 if (val > 99)
765 rt = 0;
766 if (tep_read_number_field(sched_task, record->data, &val))
767 return;
768 add_sched(val, record->ts, rt);
769 }
770 }
771
772 static void
show_wakeup_timings(unsigned long long total,unsigned long count,unsigned long long lat_max,unsigned long long time_max,unsigned long long lat_min,unsigned long long time_min)773 show_wakeup_timings(unsigned long long total, unsigned long count,
774 unsigned long long lat_max, unsigned long long time_max,
775 unsigned long long lat_min, unsigned long long time_min)
776 {
777
778 total /= count;
779
780 printf("\nAverage wakeup latency: %llu.%03llu usecs\n",
781 total / 1000,
782 total % 1000);
783 printf("Maximum Latency: %llu.%03llu usecs at ", lat_max / 1000, lat_max % 1000);
784 printf("timestamp: %llu.%06llu\n",
785 time_max / 1000000000, ((time_max + 500) % 1000000000) / 1000);
786 printf("Minimum Latency: %llu.%03llu usecs at ", lat_min / 1000, lat_min % 1000);
787 printf("timestamp: %llu.%06llu\n\n", time_min / 1000000000,
788 ((time_min + 500) % 1000000000) / 1000);
789 }
790
finish_wakeup(void)791 static void finish_wakeup(void)
792 {
793 struct wakeup_info *info;
794 struct trace_hash_item **bucket;
795 struct trace_hash_item *item;
796
797 if (!show_wakeup || !wakeup_lat_count)
798 return;
799
800 show_wakeup_timings(total_wakeup_lat, wakeup_lat_count,
801 max_lat, max_time,
802 min_lat, min_time);
803
804
805 if (wakeup_rt_lat_count) {
806 printf("RT task timings:\n");
807 show_wakeup_timings(total_wakeup_rt_lat, wakeup_rt_lat_count,
808 max_rt_lat, max_rt_time,
809 min_rt_lat, min_rt_time);
810 }
811
812 trace_hash_for_each_bucket(bucket, &wakeup_hash) {
813 trace_hash_while_item(item, bucket) {
814 trace_hash_del(item);
815 info = container_of(item, struct wakeup_info, hash);
816 free(info);
817 }
818 }
819
820 trace_hash_free(&wakeup_hash);
821 }
822
trace_show_data(struct tracecmd_input * handle,struct tep_record * record)823 void trace_show_data(struct tracecmd_input *handle, struct tep_record *record)
824 {
825 tracecmd_show_data_func func = tracecmd_get_show_data_func(handle);
826 const char *tfmt = time_format(handle, TIME_FMT_NORMAL);
827 const char *cfmt = latency_format ? "%8.8s-%-5d %3d" : "%16s-%-5d [%03d]";
828 struct tep_handle *pevent;
829 struct tep_event *event;
830 struct trace_seq s;
831 int cpu = record->cpu;
832 bool use_trace_clock;
833 static unsigned long long last_ts;
834 unsigned long long diff_ts;
835 unsigned long page_size;
836 char buf[50];
837
838 page_size = tracecmd_page_size(handle);
839
840 test_save(record, cpu);
841
842 if (func) {
843 func(handle, record);
844 return;
845 }
846
847 pevent = tracecmd_get_tep(handle);
848 event = tep_find_event_by_record(pevent, record);
849 use_trace_clock = tracecmd_get_use_trace_clock(handle);
850
851 trace_seq_init(&s);
852 if (record->missed_events > 0)
853 trace_seq_printf(&s, "CPU:%d [%lld EVENTS DROPPED]\n",
854 cpu, record->missed_events);
855 else if (record->missed_events < 0)
856 trace_seq_printf(&s, "CPU:%d [EVENTS DROPPED]\n", cpu);
857 if (buffer_breaks || tracecmd_get_debug()) {
858 if (tracecmd_record_at_buffer_start(handle, record)) {
859 trace_seq_printf(&s, "CPU:%d [SUBBUFFER START]", cpu);
860 if (tracecmd_get_debug())
861 trace_seq_printf(&s, " [%lld:0x%llx]",
862 tracecmd_page_ts(handle, record),
863 record->offset & ~(page_size - 1));
864 trace_seq_putc(&s, '\n');
865 }
866 }
867
868 tep_print_event(pevent, &s, record, cfmt,
869 TEP_PRINT_COMM,
870 TEP_PRINT_PID,
871 TEP_PRINT_CPU);
872
873 if (raw_format)
874 trace_seq_printf(&s, "-0x%x",
875 tep_data_flags(pevent, record));
876 else
877 tep_print_event(pevent, &s, record,
878 latency_format ? "%s" : " %s",
879 TEP_PRINT_LATENCY);
880
881 tep_print_event(pevent, &s, record, tfmt, TEP_PRINT_TIME);
882
883 if (tsdiff) {
884 unsigned long long rec_ts = record->ts;
885
886 buf[0] = 0;
887 if (use_trace_clock && !tep_test_flag(pevent, TEP_NSEC_OUTPUT))
888 rec_ts = (rec_ts + 500) / 1000;
889 if (last_ts) {
890 diff_ts = rec_ts - last_ts;
891 snprintf(buf, 50, "(+%lld)", diff_ts);
892 buf[49] = 0;
893 }
894 last_ts = rec_ts;
895 trace_seq_printf(&s, " %-8s", buf);
896 }
897
898 print_event_name(&s, event);
899 tep_print_event(pevent, &s, record, "%s", format_type);
900
901 if (s.len && *(s.buffer + s.len - 1) == '\n')
902 s.len--;
903 if (tracecmd_get_debug()) {
904 struct kbuffer *kbuf;
905 struct kbuffer_raw_info info;
906 void *page;
907 void *offset;
908
909 trace_seq_printf(&s, " [%d:0x%llx:%d]",
910 tracecmd_record_ts_delta(handle, record),
911 record->offset & (page_size - 1), record->size);
912 kbuf = tracecmd_record_kbuf(handle, record);
913 page = tracecmd_record_page(handle, record);
914 offset = tracecmd_record_offset(handle, record);
915
916 if (kbuf && page && offset) {
917 struct kbuffer_raw_info *pi = &info;
918
919 /* We need to get the record raw data to get next */
920 pi->next = offset;
921 pi = kbuffer_raw_get(kbuf, page, pi);
922 while ((pi = kbuffer_raw_get(kbuf, page, pi))) {
923 if (pi->type < KBUFFER_TYPE_PADDING)
924 break;
925 switch (pi->type) {
926 case KBUFFER_TYPE_PADDING:
927 trace_seq_printf(&s, "\n PADDING: ");
928 break;
929 case KBUFFER_TYPE_TIME_EXTEND:
930 trace_seq_printf(&s, "\n TIME EXTEND: ");
931 break;
932 case KBUFFER_TYPE_TIME_STAMP:
933 trace_seq_printf(&s, "\n TIME STAMP: ");
934 break;
935 }
936 if (pi->type == KBUFFER_TYPE_TIME_STAMP)
937 trace_seq_printf(&s, "timestamp:%lld length:%d",
938 pi->delta,
939 pi->length);
940 else
941 trace_seq_printf(&s, "delta:%lld length:%d",
942 pi->delta,
943 pi->length);
944 }
945 }
946 }
947
948 trace_seq_do_printf(&s);
949 trace_seq_destroy(&s);
950
951 process_wakeup(pevent, record);
952
953 printf("\n");
954 }
955
read_latency(struct tracecmd_input * handle)956 static void read_latency(struct tracecmd_input *handle)
957 {
958 char *buf = NULL;
959 size_t size = 0;
960 int r;
961
962 do {
963 r = tracecmd_latency_data_read(handle, &buf, &size);
964 if (r > 0)
965 printf("%.*s", r, buf);
966 } while (r > 0);
967
968 printf("\n");
969 free(buf);
970 }
971
972 static int
test_filters(struct tep_handle * pevent,struct tep_record * record)973 test_filters(struct tep_handle *pevent, struct tep_record *record)
974 {
975 int ret = FILTER_NONE;
976 int flags;
977
978 if (no_irqs || no_softirqs) {
979 flags = tep_data_flags(pevent, record);
980 if (no_irqs && (flags & TRACE_FLAG_HARDIRQ))
981 return FILTER_MISS;
982 if (no_softirqs && (flags & TRACE_FLAG_SOFTIRQ))
983 return FILTER_MISS;
984 }
985
986 return ret;
987 }
988
989 struct stack_info_cpu {
990 int cpu;
991 int last_printed;
992 };
993
994 struct stack_info {
995 struct stack_info *next;
996 struct handle_list *handles;
997 struct stack_info_cpu *cpus;
998 int nr_cpus;
999 };
1000
print_handle_file(struct handle_list * handles)1001 static void print_handle_file(struct handle_list *handles)
1002 {
1003 /* Only print file names if more than one file is read */
1004 if (!multi_inputs && !instances)
1005 return;
1006 if (handles->file && *handles->file != '\0')
1007 printf("%*s: ", max_file_size, handles->file);
1008 else
1009 printf("%*s ", max_file_size, "");
1010 }
1011
skip_record(struct handle_list * handles,struct tep_record * record,int cpu)1012 static bool skip_record(struct handle_list *handles, struct tep_record *record, int cpu)
1013 {
1014 struct tep_handle *tep;
1015 bool found = false;
1016 int ret;
1017
1018 tep = tracecmd_get_tep(handles->handle);
1019
1020 if (filter_cpus) {
1021 int i;
1022
1023 for (i = 0; filter_cpus[i] >= 0; i++) {
1024 if (filter_cpus[i] == cpu) {
1025 found = true;
1026 break;
1027 }
1028 }
1029
1030 if (!found)
1031 return true;
1032 found = false;
1033 }
1034
1035 ret = test_filters(tep, record);
1036 switch (ret) {
1037 case FILTER_NOEXIST:
1038 break;
1039 case FILTER_NONE:
1040 case FILTER_MATCH:
1041 /* Test the negative filters (-v) */
1042 ret = test_filters(tep, record);
1043 if (ret != FILTER_MATCH) {
1044 found = true;
1045 break;
1046 }
1047 }
1048
1049 return !found;
1050 }
1051
1052 struct kvm_cpu_map {
1053 struct tracecmd_input *guest_handle;
1054 int guest_vcpu;
1055 int host_pid;
1056 };
1057
1058 static struct kvm_cpu_map *vcpu_maps;
1059 static int nr_vcpu_maps;
1060
cmp_map(const void * A,const void * B)1061 static int cmp_map(const void *A, const void *B)
1062 {
1063 const struct kvm_cpu_map *a = A;
1064 const struct kvm_cpu_map *b = B;
1065
1066 if (a->host_pid < b->host_pid)
1067 return -1;
1068 return a->host_pid > b->host_pid;
1069 }
1070
map_vcpus(struct tracecmd_input ** handles,int nr_handles)1071 static void map_vcpus(struct tracecmd_input **handles, int nr_handles)
1072 {
1073 struct tracecmd_input *host_handle = handles[0];
1074 unsigned long long traceid;
1075 struct kvm_cpu_map *map;
1076 const int *cpu_pids;
1077 const char *name;
1078 int vcpu_count;
1079 int ret;
1080 int i, k;
1081
1082 for (i = 1; i < nr_handles; i++) {
1083 traceid = tracecmd_get_traceid(handles[i]);
1084 ret = tracecmd_get_guest_cpumap(host_handle, traceid,
1085 &name, &vcpu_count, &cpu_pids);
1086 if (ret)
1087 continue;
1088 map = realloc(vcpu_maps, sizeof(*map) * (nr_vcpu_maps + vcpu_count));
1089 if (!map)
1090 die("Could not allocate vcpu maps");
1091
1092 vcpu_maps = map;
1093 map += nr_vcpu_maps;
1094 nr_vcpu_maps += vcpu_count;
1095
1096 for (k = 0; k < vcpu_count; k++) {
1097 map[k].guest_handle = handles[i];
1098 map[k].guest_vcpu = k;
1099 map[k].host_pid = cpu_pids[k];
1100 }
1101 }
1102 if (!vcpu_maps)
1103 return;
1104
1105 qsort(vcpu_maps, nr_vcpu_maps, sizeof(*map), cmp_map);
1106 }
1107
1108
tep_plugin_kvm_get_func(struct tep_event * event,struct tep_record * record,unsigned long long * val)1109 const char *tep_plugin_kvm_get_func(struct tep_event *event,
1110 struct tep_record *record,
1111 unsigned long long *val)
1112 {
1113 struct tep_handle *tep;
1114 struct kvm_cpu_map *map;
1115 struct kvm_cpu_map key;
1116 unsigned long long rip = *val;
1117 const char *func;
1118 int pid;
1119
1120 if (!vcpu_maps || !nr_vcpu_maps)
1121 return NULL;
1122
1123 /*
1124 * A kvm event is referencing an address of the guest.
1125 * get the PID of this event, and then find which guest
1126 * it belongs to. Then return the function name from that guest's
1127 * handle.
1128 */
1129 pid = tep_data_pid(event->tep, record);
1130
1131 key.host_pid = pid;
1132 map = bsearch(&key, vcpu_maps, nr_vcpu_maps, sizeof(*vcpu_maps), cmp_map);
1133
1134 if (!map)
1135 return NULL;
1136
1137 tep = tracecmd_get_tep(map->guest_handle);
1138 func = tep_find_function(tep, rip);
1139 if (func)
1140 *val = tep_find_function_address(tep, rip);
1141 return func;
1142 }
1143
process_record(struct tracecmd_input * handle,struct tep_record * record,int cpu,void * data)1144 static int process_record(struct tracecmd_input *handle, struct tep_record *record,
1145 int cpu, void *data)
1146 {
1147 struct handle_list *handles = tracecmd_get_private(handle);
1148 unsigned long long *last_timestamp = data;
1149
1150 if (skip_record(handles, record, cpu))
1151 return 0;
1152
1153 if (tscheck && *last_timestamp > record->ts) {
1154 errno = 0;
1155 warning("WARNING: Record on cpu %d went backwards: %lld to %lld delta: -%lld\n",
1156 cpu, *last_timestamp, record->ts, *last_timestamp - record->ts);
1157 }
1158 *last_timestamp = record->ts;
1159
1160 print_handle_file(handles);
1161 trace_show_data(handle, record);
1162 return 0;
1163 }
1164
1165 enum output_type {
1166 OUTPUT_NORMAL,
1167 OUTPUT_STAT_ONLY,
1168 OUTPUT_UNAME_ONLY,
1169 OUTPUT_VERSION_ONLY,
1170 };
1171
read_data_info(struct list_head * handle_list,enum output_type otype,int global,int align_ts)1172 static void read_data_info(struct list_head *handle_list, enum output_type otype,
1173 int global, int align_ts)
1174 {
1175 unsigned long long ts, first_ts;
1176 struct handle_list *handles;
1177 struct tracecmd_input **handle_array;
1178 unsigned long long last_timestamp = 0;
1179 int nr_handles = 0;
1180 int first = 1;
1181 int ret;
1182
1183 list_for_each_entry(handles, handle_list, list) {
1184 int cpus;
1185
1186 nr_handles++;
1187
1188 if (!tracecmd_is_buffer_instance(handles->handle)) {
1189 ret = tracecmd_init_data(handles->handle);
1190 if (ret < 0)
1191 die("failed to init data");
1192 }
1193 cpus = tracecmd_cpus(handles->handle);
1194 handles->cpus = cpus;
1195
1196 process_filters(handles);
1197
1198 /* Don't process instances that we added here */
1199 if (tracecmd_is_buffer_instance(handles->handle))
1200 continue;
1201
1202 if (align_ts) {
1203 ts = tracecmd_get_first_ts(handles->handle);
1204 if (first || first_ts > ts)
1205 first_ts = ts;
1206 first = 0;
1207 }
1208 print_handle_file(handles);
1209 printf("cpus=%d\n", cpus);
1210
1211 /* Latency trace is just all ASCII */
1212 if (ret > 0) {
1213 if (multi_inputs)
1214 die("latency traces do not work with multiple inputs");
1215 read_latency(handles->handle);
1216 return;
1217 }
1218
1219 switch (otype) {
1220 case OUTPUT_NORMAL:
1221 break;
1222 case OUTPUT_STAT_ONLY:
1223 printf("\nKernel buffer statistics:\n"
1224 " Note: \"entries\" are the entries left in the kernel ring buffer and are not\n"
1225 " recorded in the trace data. They should all be zero.\n\n");
1226 tracecmd_print_stats(handles->handle);
1227 continue;
1228 case OUTPUT_UNAME_ONLY:
1229 tracecmd_print_uname(handles->handle);
1230 case OUTPUT_VERSION_ONLY:
1231 tracecmd_print_version(handles->handle);
1232 continue;
1233 }
1234
1235 init_wakeup(handles->handle);
1236 if (last_hook)
1237 last_hook->next = tracecmd_hooks(handles->handle);
1238 else
1239 hooks = tracecmd_hooks(handles->handle);
1240 if (profile)
1241 trace_init_profile(handles->handle, hooks, global);
1242
1243 /* If this file has buffer instances, get the handles for them */
1244 instances = tracecmd_buffer_instances(handles->handle);
1245 if (instances) {
1246 struct tracecmd_input *new_handle;
1247 struct input_files *file_input;
1248 const char *save_name;
1249 const char *name;
1250 int i;
1251
1252 file_input = handles->input_file;
1253
1254 for (i = 0; i < instances; i++) {
1255 name = tracecmd_buffer_instance_name(handles->handle, i);
1256 if (!name)
1257 die("error in reading buffer instance");
1258 new_handle = tracecmd_buffer_instance_handle(handles->handle, i);
1259 if (!new_handle) {
1260 warning("could not retrieve handle %s", name);
1261 continue;
1262 }
1263 if (file_input) {
1264 save_name = file_input->file;
1265 file_input->file = name;
1266 } else {
1267 save_name = NULL;
1268 file_input = add_input(name);
1269 }
1270 add_handle(new_handle, file_input);
1271 if (save_name)
1272 file_input->file = save_name;
1273 }
1274 }
1275 }
1276
1277 if (otype != OUTPUT_NORMAL)
1278 return;
1279
1280 if (align_ts) {
1281 list_for_each_entry(handles, handle_list, list) {
1282 tracecmd_add_ts_offset(handles->handle, -first_ts);
1283 }
1284 }
1285
1286 handle_array = calloc(nr_handles, sizeof(*handle_array));
1287 if (!handle_array)
1288 die("Could not allocate memory for handle list");
1289
1290 nr_handles = 0;
1291 list_for_each_entry(handles, handle_list, list) {
1292 tracecmd_set_private(handles->handle, handles);
1293 handle_array[nr_handles++] = handles->handle;
1294 }
1295
1296 map_vcpus(handle_array, nr_handles);
1297
1298 tracecmd_iterate_events_multi(handle_array, nr_handles,
1299 process_record, &last_timestamp);
1300
1301 free(handle_array);
1302
1303 if (profile)
1304 do_trace_profile();
1305
1306 list_for_each_entry(handles, handle_list, list) {
1307 show_test(handles->handle);
1308 }
1309 }
1310
read_trace_header(const char * file,int flags)1311 struct tracecmd_input *read_trace_header(const char *file, int flags)
1312 {
1313 input_fd = open(file, O_RDONLY);
1314 if (input_fd < 0)
1315 die("opening '%s'\n", file);
1316
1317 return tracecmd_alloc_fd(input_fd, flags);
1318 }
1319
sig_end(int sig)1320 static void sig_end(int sig)
1321 {
1322 struct handle_list *handles;
1323
1324 fprintf(stderr, "trace-cmd: Received SIGINT\n");
1325
1326 list_for_each_entry(handles, &handle_list, list) {
1327 tracecmd_close(handles->handle);
1328 }
1329
1330 exit(0);
1331 }
1332
skip_space_and_test_digit(const char * p,const char * cpu_str)1333 static const char *skip_space_and_test_digit(const char *p, const char *cpu_str)
1334 {
1335 while (isspace(*p))
1336 p++;
1337 if (!isdigit(*p))
1338 die("invalid character '%c' in cpu string '%s'",
1339 *p, cpu_str);
1340 return p;
1341 }
1342
__add_cpu(int cpu)1343 static void __add_cpu(int cpu)
1344 {
1345 filter_cpus = tracecmd_add_id(filter_cpus, cpu, nr_filter_cpus++);
1346 }
1347
parse_cpulist(const char * cpu_str)1348 static void parse_cpulist(const char *cpu_str)
1349 {
1350 unsigned a, b;
1351 const char *s = cpu_str;
1352
1353 do {
1354 s = skip_space_and_test_digit(s, cpu_str);
1355 b = a = strtoul(s, (char **)&s, 10);
1356 if (*s == '-') {
1357 s = skip_space_and_test_digit(s + 1, cpu_str);
1358 b = strtoul(s, (char **)&s, 10);
1359 }
1360 if (!(a <= b))
1361 die("range of cpu numbers must be lower to greater");
1362 while (a <= b) {
1363 __add_cpu(a);
1364 a++;
1365 }
1366 if (*s == ',' || *s == ':')
1367 s++;
1368 } while (*s != '\0');
1369 }
1370
read_file_fd(int fd,char * dst,int len)1371 static void read_file_fd(int fd, char *dst, int len)
1372 {
1373 size_t size = 0;
1374 int r;
1375
1376 do {
1377 r = read(fd, dst+size, len);
1378 if (r > 0) {
1379 size += r;
1380 len -= r;
1381 }
1382 } while (r > 0);
1383 }
1384
add_functions(struct tep_handle * pevent,const char * file)1385 static void add_functions(struct tep_handle *pevent, const char *file)
1386 {
1387 struct stat st;
1388 char *buf;
1389 int ret;
1390 int fd;
1391
1392 fd = open(file, O_RDONLY);
1393 if (fd < 0)
1394 die("Can't read file %s", file);
1395
1396 ret = fstat(fd, &st);
1397 if (ret < 0)
1398 die("Can't stat file %s", file);
1399
1400 buf = malloc(st.st_size + 1);
1401 if (!buf)
1402 die("Failed to allocate for function buffer");
1403 read_file_fd(fd, buf, st.st_size);
1404 buf[st.st_size] = '\0';
1405 close(fd);
1406 tep_parse_kallsyms(pevent, buf);
1407 free(buf);
1408 }
1409
process_plugin_option(char * option)1410 static void process_plugin_option(char *option)
1411 {
1412 char *name = option;
1413 char *val = NULL;
1414 char *p;
1415
1416 if ((p = strstr(name, "="))) {
1417 *p = '\0';
1418 val = p+1;
1419 }
1420 tep_plugin_add_option(name, val);
1421 }
1422
set_event_flags(struct tep_handle * pevent,struct event_str * list,unsigned int flag)1423 static void set_event_flags(struct tep_handle *pevent, struct event_str *list,
1424 unsigned int flag)
1425 {
1426 struct tep_event **events;
1427 struct tep_event *event;
1428 struct event_str *str;
1429 regex_t regex;
1430 int ret;
1431 int i;
1432
1433 if (!list)
1434 return;
1435
1436 events = tep_list_events(pevent, 0);
1437
1438 for (str = list; str; str = str->next) {
1439 char *match;
1440
1441 match = malloc(strlen(str->event) + 3);
1442 if (!match)
1443 die("Failed to allocate for match string '%s'", str->event);
1444 sprintf(match, "^%s$", str->event);
1445
1446 ret = regcomp(®ex, match, REG_ICASE|REG_NOSUB);
1447 if (ret < 0)
1448 die("Can't parse '%s'", str->event);
1449 free(match);
1450 for (i = 0; events[i]; i++) {
1451 event = events[i];
1452 if (!regexec(®ex, event->name, 0, NULL, 0) ||
1453 !regexec(®ex, event->system, 0, NULL, 0))
1454 event->flags |= flag;
1455 }
1456 }
1457 }
1458
show_event_ts(struct tracecmd_input * handle,struct tep_record * record)1459 static void show_event_ts(struct tracecmd_input *handle,
1460 struct tep_record *record)
1461 {
1462 const char *tfmt = time_format(handle, TIME_FMT_TS);
1463 struct tep_handle *tep = tracecmd_get_tep(handle);
1464 struct trace_seq s;
1465
1466 trace_seq_init(&s);
1467 tep_print_event(tep, &s, record, tfmt, TEP_PRINT_TIME);
1468 printf("%s", s.buffer);
1469 trace_seq_destroy(&s);
1470 }
1471
add_hook(const char * arg)1472 static void add_hook(const char *arg)
1473 {
1474 struct hook_list *hook;
1475
1476 hook = tracecmd_create_event_hook(arg);
1477
1478 hook->next = hooks;
1479 hooks = hook;
1480 if (!last_hook)
1481 last_hook = hook;
1482 }
1483
add_first_input(const char * input_file,long long tsoffset)1484 static void add_first_input(const char *input_file, long long tsoffset)
1485 {
1486 struct input_files *item;
1487
1488 /* Copy filter strings to this input file */
1489 item = add_input(input_file);
1490 item->filter_str = filter_strings;
1491 if (filter_strings)
1492 item->filter_str_next = filter_next;
1493 else
1494 item->filter_str_next = &item->filter_str;
1495 /* Copy the tsoffset to this input file */
1496 item->tsoffset = tsoffset;
1497 }
1498
1499 enum {
1500 OPT_verbose = 234,
1501 OPT_align_ts = 235,
1502 OPT_raw_ts = 236,
1503 OPT_version = 237,
1504 OPT_tscheck = 238,
1505 OPT_tsdiff = 239,
1506 OPT_ts2secs = 240,
1507 OPT_tsoffset = 241,
1508 OPT_bycomm = 242,
1509 OPT_debug = 243,
1510 OPT_uname = 244,
1511 OPT_profile = 245,
1512 OPT_event = 246,
1513 OPT_comm = 247,
1514 OPT_boundary = 248,
1515 OPT_stat = 249,
1516 OPT_pid = 250,
1517 OPT_nodate = 251,
1518 OPT_check_event_parsing = 252,
1519 OPT_kallsyms = 253,
1520 OPT_events = 254,
1521 OPT_cpu = 255,
1522 OPT_cpus = 256,
1523 OPT_first = 257,
1524 OPT_last = 258,
1525 };
1526
trace_report(int argc,char ** argv)1527 void trace_report (int argc, char **argv)
1528 {
1529 struct tracecmd_input *handle;
1530 struct tep_handle *pevent;
1531 struct event_str *raw_events = NULL;
1532 struct event_str *nohandler_events = NULL;
1533 struct event_str **raw_ptr = &raw_events;
1534 struct event_str **nohandler_ptr = &nohandler_events;
1535 const char *functions = NULL;
1536 const char *print_event = NULL;
1537 struct input_files *inputs;
1538 struct handle_list *handles;
1539 enum output_type otype;
1540 long long tsoffset = 0;
1541 unsigned long long ts2secs = 0;
1542 unsigned long long ts2sc;
1543 int open_flags = 0;
1544 int show_stat = 0;
1545 int show_funcs = 0;
1546 int show_endian = 0;
1547 int show_page_size = 0;
1548 int show_printk = 0;
1549 int show_uname = 0;
1550 int show_version = 0;
1551 int show_events = 0;
1552 int show_cpus = 0;
1553 int show_first = 0;
1554 int show_last = 0;
1555 int print_events = 0;
1556 int nanosec = 0;
1557 int no_date = 0;
1558 int raw_ts = 0;
1559 int align_ts = 0;
1560 int global = 0;
1561 int neg = 0;
1562 int ret = 0;
1563 int check_event_parsing = 0;
1564 int c;
1565
1566 list_head_init(&handle_list);
1567 list_head_init(&input_files);
1568
1569 if (argc < 2)
1570 usage(argv);
1571
1572 if (strcmp(argv[1], "report") != 0)
1573 usage(argv);
1574
1575 signal(SIGINT, sig_end);
1576
1577 trace_set_loglevel(TEP_LOG_ERROR);
1578
1579 for (;;) {
1580 int option_index = 0;
1581 static struct option long_options[] = {
1582 {"cpu", required_argument, NULL, OPT_cpu},
1583 {"cpus", no_argument, NULL, OPT_cpus},
1584 {"events", no_argument, NULL, OPT_events},
1585 {"event", required_argument, NULL, OPT_event},
1586 {"filter-test", no_argument, NULL, 'T'},
1587 {"first-event", no_argument, NULL, OPT_first},
1588 {"kallsyms", required_argument, NULL, OPT_kallsyms},
1589 {"pid", required_argument, NULL, OPT_pid},
1590 {"comm", required_argument, NULL, OPT_comm},
1591 {"check-events", no_argument, NULL,
1592 OPT_check_event_parsing},
1593 {"nodate", no_argument, NULL, OPT_nodate},
1594 {"stat", no_argument, NULL, OPT_stat},
1595 {"boundary", no_argument, NULL, OPT_boundary},
1596 {"debug", no_argument, NULL, OPT_debug},
1597 {"last-event", no_argument, NULL, OPT_last},
1598 {"profile", no_argument, NULL, OPT_profile},
1599 {"uname", no_argument, NULL, OPT_uname},
1600 {"version", no_argument, NULL, OPT_version},
1601 {"by-comm", no_argument, NULL, OPT_bycomm},
1602 {"ts-offset", required_argument, NULL, OPT_tsoffset},
1603 {"ts2secs", required_argument, NULL, OPT_ts2secs},
1604 {"ts-diff", no_argument, NULL, OPT_tsdiff},
1605 {"ts-check", no_argument, NULL, OPT_tscheck},
1606 {"raw-ts", no_argument, NULL, OPT_raw_ts},
1607 {"align-ts", no_argument, NULL, OPT_align_ts},
1608 {"verbose", optional_argument, NULL, OPT_verbose},
1609 {"help", no_argument, NULL, '?'},
1610 {NULL, 0, NULL, 0}
1611 };
1612
1613 c = getopt_long (argc-1, argv+1, "+hSIi:H:feGpRr:tPNn:LlEwF:V::vTqO:",
1614 long_options, &option_index);
1615 if (c == -1)
1616 break;
1617 switch (c) {
1618 case 'h':
1619 usage(argv);
1620 break;
1621 case 'i':
1622 if (input_file) {
1623 multi_inputs++;
1624 add_input(optarg);
1625 } else {
1626 input_file = optarg;
1627 add_first_input(input_file, tsoffset);
1628 }
1629 break;
1630 case 'F':
1631 add_filter(last_input_file, optarg, neg);
1632 break;
1633 case 'H':
1634 add_hook(optarg);
1635 break;
1636 case 'T':
1637 test_filters_mode = 1;
1638 break;
1639 case 'f':
1640 show_funcs = 1;
1641 break;
1642 case 'I':
1643 no_irqs = 1;
1644 break;
1645 case 'S':
1646 no_softirqs = 1;
1647 break;
1648 case 'P':
1649 show_printk = 1;
1650 break;
1651 case 'L':
1652 open_flags |= TRACECMD_FL_LOAD_NO_SYSTEM_PLUGINS;
1653 break;
1654 case 'N':
1655 open_flags |= TRACECMD_FL_LOAD_NO_PLUGINS;
1656 break;
1657 case 'n':
1658 *nohandler_ptr = malloc(sizeof(struct event_str));
1659 if (!*nohandler_ptr)
1660 die("Failed to allocate for '-n %s'", optarg);
1661 (*nohandler_ptr)->event = optarg;
1662 (*nohandler_ptr)->next = NULL;
1663 nohandler_ptr = &(*nohandler_ptr)->next;
1664 break;
1665 case 'e':
1666 show_endian = 1;
1667 break;
1668 case 'p':
1669 show_page_size = 1;
1670 break;
1671 case 'E':
1672 show_events = 1;
1673 break;
1674 case 'G':
1675 global = 1;
1676 break;
1677 case 'R':
1678 raw_format = true;
1679 break;
1680 case 'r':
1681 *raw_ptr = malloc(sizeof(struct event_str));
1682 if (!*raw_ptr)
1683 die("Failed to allocate '-r %s'", optarg);
1684 (*raw_ptr)->event = optarg;
1685 (*raw_ptr)->next = NULL;
1686 raw_ptr = &(*raw_ptr)->next;
1687 break;
1688 case 't':
1689 nanosec = 1;
1690 break;
1691 case 'w':
1692 show_wakeup = 1;
1693 break;
1694 case 'l':
1695 latency_format = 1;
1696 break;
1697 case 'O':
1698 process_plugin_option(optarg);
1699 break;
1700 case 'v':
1701 if (neg)
1702 die("Only 1 -v can be used");
1703 neg = 1;
1704 break;
1705 case 'q':
1706 silence_warnings = 1;
1707 tracecmd_set_loglevel(TEP_LOG_NONE);
1708 break;
1709 case OPT_cpu:
1710 parse_cpulist(optarg);
1711 break;
1712 case OPT_cpus:
1713 show_cpus = 1;
1714 break;
1715 case OPT_events:
1716 print_events = 1;
1717 break;
1718 case OPT_event:
1719 print_event = optarg;
1720 break;
1721 case OPT_kallsyms:
1722 functions = optarg;
1723 break;
1724 case OPT_pid:
1725 add_pid_filter(optarg);
1726 break;
1727 case OPT_comm:
1728 add_comm_filter(optarg);
1729 break;
1730 case OPT_check_event_parsing:
1731 check_event_parsing = 1;
1732 break;
1733 case OPT_nodate:
1734 no_date = 1;
1735 break;
1736 case OPT_stat:
1737 show_stat = 1;
1738 break;
1739 case OPT_first:
1740 show_first = 1;
1741 show_cpus = 1;
1742 break;
1743 case OPT_last:
1744 show_last = 1;
1745 show_cpus = 1;
1746 break;
1747 case OPT_boundary:
1748 /* Debug to look at buffer breaks */
1749 buffer_breaks = 1;
1750 break;
1751 case OPT_debug:
1752 buffer_breaks = 1;
1753 tracecmd_set_debug(true);
1754 break;
1755 case OPT_profile:
1756 profile = 1;
1757 break;
1758 case OPT_uname:
1759 show_uname = 1;
1760 break;
1761 case OPT_version:
1762 show_version = 1;
1763 break;
1764 case OPT_bycomm:
1765 trace_profile_set_merge_like_comms();
1766 break;
1767 case OPT_ts2secs:
1768 ts2sc = atoll(optarg);
1769 if (multi_inputs)
1770 last_input_file->ts2secs = ts2sc;
1771 else
1772 ts2secs = ts2sc;
1773 break;
1774 case OPT_tsoffset:
1775 tsoffset = atoll(optarg);
1776 if (multi_inputs)
1777 last_input_file->tsoffset = tsoffset;
1778 if (!input_file)
1779 die("--ts-offset must come after -i");
1780 break;
1781 case OPT_tsdiff:
1782 tsdiff = 1;
1783 break;
1784 case OPT_tscheck:
1785 tscheck = 1;
1786 break;
1787 case OPT_raw_ts:
1788 raw_ts = 1;
1789 break;
1790 case OPT_align_ts:
1791 align_ts = 1;
1792 break;
1793 case 'V':
1794 case OPT_verbose:
1795 show_status = 1;
1796 if (trace_set_verbose(optarg) < 0)
1797 die("invalid verbose level %s", optarg);
1798 break;
1799 default:
1800 usage(argv);
1801 }
1802 }
1803
1804 if ((argc - optind) >= 2) {
1805 if (input_file)
1806 usage(argv);
1807 input_file = argv[optind + 1];
1808 add_first_input(input_file, tsoffset);
1809 for (int i = optind + 2; i < argc; i++) {
1810 multi_inputs++;
1811 add_input(argv[i]);
1812 }
1813 }
1814
1815 if (!multi_inputs) {
1816 if (!input_file) {
1817 input_file = default_input_file;
1818 add_first_input(input_file, tsoffset);
1819 }
1820 } else if (show_wakeup)
1821 die("Wakeup tracing can only be done on a single input file");
1822
1823 list_for_each_entry(inputs, &input_files, list) {
1824 handle = read_trace_header(inputs->file, open_flags);
1825 if (!handle)
1826 die("error reading header for %s", inputs->file);
1827
1828 /* If used with instances, top instance will have no tag */
1829 add_handle(handle, multi_inputs ? inputs : NULL);
1830
1831 if (no_date)
1832 tracecmd_set_flag(handle, TRACECMD_FL_IGNORE_DATE);
1833 if (raw_ts)
1834 tracecmd_set_flag(handle, TRACECMD_FL_RAW_TS);
1835 page_size = tracecmd_page_size(handle);
1836
1837 if (show_page_size) {
1838 printf("file page size is %d, and host page size is %d\n",
1839 page_size,
1840 getpagesize());
1841 return;
1842 }
1843
1844 if (inputs->tsoffset)
1845 tracecmd_set_ts_offset(handle, inputs->tsoffset);
1846
1847 if (inputs->ts2secs)
1848 tracecmd_set_ts2secs(handle, inputs->ts2secs);
1849 else if (ts2secs)
1850 tracecmd_set_ts2secs(handle, ts2secs);
1851
1852 pevent = tracecmd_get_tep(handle);
1853
1854 if (nanosec)
1855 tep_set_flag(pevent, TEP_NSEC_OUTPUT);
1856
1857 if (raw_format)
1858 format_type = TEP_PRINT_INFO_RAW;
1859
1860 if (test_filters_mode)
1861 tep_set_test_filters(pevent, 1);
1862
1863 if (functions)
1864 add_functions(pevent, functions);
1865
1866 if (show_endian) {
1867 printf("file is %s endian and host is %s endian\n",
1868 tep_is_file_bigendian(pevent) ? "big" : "little",
1869 tep_is_local_bigendian(pevent) ? "big" : "little");
1870 return;
1871 }
1872
1873 if (print_events) {
1874 tracecmd_print_events(handle, NULL);
1875 return;
1876 }
1877
1878 if (print_event) {
1879 tracecmd_print_events(handle, print_event);
1880 return;
1881 }
1882
1883 ret = tracecmd_read_headers(handle, 0);
1884 if (check_event_parsing) {
1885 if (ret || tracecmd_get_parsing_failures(handle))
1886 exit(EINVAL);
1887 else
1888 exit(0);
1889 } else {
1890 if (ret)
1891 return;
1892 }
1893
1894 if (show_funcs) {
1895 tep_print_funcs(pevent);
1896 return;
1897 }
1898 if (show_printk) {
1899 tep_print_printk(pevent);
1900 return;
1901 }
1902
1903 if (show_events) {
1904 struct tep_event **events;
1905 struct tep_event *event;
1906 int i;
1907
1908 events = tep_list_events(pevent, TEP_EVENT_SORT_SYSTEM);
1909 for (i = 0; events[i]; i++) {
1910 event = events[i];
1911 if (event->system)
1912 printf("%s:", event->system);
1913 printf("%s\n", event->name);
1914 }
1915 return;
1916 }
1917
1918 if (show_cpus) {
1919 struct tep_record *record;
1920 int cpus;
1921 int ret;
1922 int i;
1923
1924 if (!tracecmd_is_buffer_instance(handle)) {
1925 ret = tracecmd_init_data(handle);
1926 if (ret < 0)
1927 die("failed to init data");
1928 }
1929 cpus = tracecmd_cpus(handle);
1930 printf("List of CPUs in %s with data:\n", inputs->file);
1931 for (i = 0; i < cpus; i++) {
1932 if ((record = tracecmd_read_cpu_first(handle, i))) {
1933 printf(" %d", i);
1934 if (show_first) {
1935 printf("\tFirst event:");
1936 show_event_ts(handle, record);
1937 }
1938 if (show_last) {
1939 tracecmd_free_record(record);
1940 record = tracecmd_read_cpu_last(handle, i);
1941 if (record) {
1942 printf("\tLast event:");
1943 show_event_ts(handle, record);
1944 }
1945 }
1946 tracecmd_free_record(record);
1947 printf("\n");
1948 }
1949 }
1950 continue;
1951 }
1952
1953 set_event_flags(pevent, nohandler_events, TEP_EVENT_FL_NOHANDLE);
1954 set_event_flags(pevent, raw_events, TEP_EVENT_FL_PRINTRAW);
1955 }
1956
1957 if (show_cpus)
1958 return;
1959
1960 otype = OUTPUT_NORMAL;
1961
1962 if (tracecmd_get_flags(handle) & TRACECMD_FL_RAW_TS) {
1963 tep_func_repeat_format = "%d";
1964 } else if (tracecmd_get_flags(handle) & TRACECMD_FL_IN_USECS) {
1965 if (tep_test_flag(tracecmd_get_tep(handle), TEP_NSEC_OUTPUT))
1966 tep_func_repeat_format = "%9.1d";
1967 else
1968 tep_func_repeat_format = "%6.1000d";
1969 } else {
1970 tep_func_repeat_format = "%12d";
1971 }
1972
1973
1974 if (show_stat)
1975 otype = OUTPUT_STAT_ONLY;
1976 /* yeah yeah, uname overrides stat */
1977 if (show_uname)
1978 otype = OUTPUT_UNAME_ONLY;
1979 /* and version overrides uname! */
1980 if (show_version)
1981 otype = OUTPUT_VERSION_ONLY;
1982 read_data_info(&handle_list, otype, global, align_ts);
1983
1984 list_for_each_entry(handles, &handle_list, list) {
1985 tracecmd_close(handles->handle);
1986 }
1987 free_handles();
1988 free_inputs();
1989
1990 finish_wakeup();
1991
1992 return;
1993 }
1994