perf tools: Unify perf.data mapping and events handling
[linux-2.6-block.git] / tools / perf / builtin-sched.c
index 1f0f9be34faa0666c3ed29ef62d99d8888d269d2..e1df7055ab823f718b02669037ff0b08251e244b 100644 (file)
@@ -11,6 +11,7 @@
 #include "util/trace-event.h"
 
 #include "util/debug.h"
+#include "util/data_map.h"
 
 #include <sys/types.h>
 #include <sys/prctl.h>
@@ -20,9 +21,6 @@
 #include <math.h>
 
 static char                    const *input_name = "perf.data";
-static int                     input;
-static unsigned long           page_size;
-static unsigned long           mmap_window = 32;
 
 static unsigned long           total_comm = 0;
 
@@ -35,6 +33,9 @@ static u64                    sample_type;
 static char                    default_sort_order[] = "avg, max, switch, runtime";
 static char                    *sort_order = default_sort_order;
 
+static char                    *cwd;
+static int                     cwdlen;
+
 #define PR_SET_NAME            15               /* Set process name */
 #define MAX_CPUS               4096
 
@@ -119,6 +120,7 @@ static unsigned long                replay_repeat = 10;
 static unsigned long           nr_timestamps;
 static unsigned long           nr_unordered_timestamps;
 static unsigned long           nr_state_machine_bugs;
+static unsigned long           nr_context_switch_bugs;
 static unsigned long           nr_events;
 static unsigned long           nr_lost_chunks;
 static unsigned long           nr_lost_events;
@@ -158,8 +160,6 @@ static struct rb_root               atom_root, sorted_atom_root;
 static u64                     all_runtime;
 static u64                     all_count;
 
-static int read_events(void);
-
 
 static u64 get_nsecs(void)
 {
@@ -633,38 +633,6 @@ static void test_calibrations(void)
        printf("the sleep test took %Ld nsecs\n", T1-T0);
 }
 
-static void __cmd_replay(void)
-{
-       unsigned long i;
-
-       calibrate_run_measurement_overhead();
-       calibrate_sleep_measurement_overhead();
-
-       test_calibrations();
-
-       read_events();
-
-       printf("nr_run_events:        %ld\n", nr_run_events);
-       printf("nr_sleep_events:      %ld\n", nr_sleep_events);
-       printf("nr_wakeup_events:     %ld\n", nr_wakeup_events);
-
-       if (targetless_wakeups)
-               printf("target-less wakeups:  %ld\n", targetless_wakeups);
-       if (multitarget_wakeups)
-               printf("multi-target wakeups: %ld\n", multitarget_wakeups);
-       if (nr_run_events_optimized)
-               printf("run atoms optimized: %ld\n",
-                       nr_run_events_optimized);
-
-       print_task_traces();
-       add_cross_task_wakeups();
-
-       create_tasks();
-       printf("------------------------------------------------------------\n");
-       for (i = 0; i < replay_repeat; i++)
-               run_one_test();
-}
-
 static int
 process_comm_event(event_t *event, unsigned long offset, unsigned long head)
 {
@@ -1203,13 +1171,13 @@ static void output_lat_thread(struct work_atoms *work_list)
        /*
         * Ignore idle threads:
         */
-       if (!work_list->thread->pid)
+       if (!strcmp(work_list->thread->comm, "swapper"))
                return;
 
        all_runtime += work_list->total_runtime;
        all_count += work_list->nb_atoms;
 
-       ret = printf("  %s-%d ", work_list->thread->comm, work_list->thread->pid);
+       ret = printf("  %s:%d ", work_list->thread->comm, work_list->thread->pid);
 
        for (i = 0; i < 24 - ret; i++)
                printf(" ");
@@ -1353,56 +1321,6 @@ static void sort_lat(void)
        }
 }
 
-static void __cmd_lat(void)
-{
-       struct rb_node *next;
-
-       setup_pager();
-       read_events();
-       sort_lat();
-
-       printf("\n -----------------------------------------------------------------------------------------\n");
-       printf("  Task                  |   Runtime ms  | Switches | Average delay ms | Maximum delay ms |\n");
-       printf(" -----------------------------------------------------------------------------------------\n");
-
-       next = rb_first(&sorted_atom_root);
-
-       while (next) {
-               struct work_atoms *work_list;
-
-               work_list = rb_entry(next, struct work_atoms, node);
-               output_lat_thread(work_list);
-               next = rb_next(next);
-       }
-
-       printf(" -----------------------------------------------------------------------------------------\n");
-       printf("  TOTAL:                |%11.3f ms |%9Ld |\n",
-               (double)all_runtime/1e6, all_count);
-
-       printf(" ---------------------------------------------------\n");
-       if (nr_unordered_timestamps && nr_timestamps) {
-               printf("  INFO: %.3f%% unordered timestamps (%ld out of %ld)\n",
-                       (double)nr_unordered_timestamps/(double)nr_timestamps*100.0,
-                       nr_unordered_timestamps, nr_timestamps);
-       } else {
-       }
-       if (nr_lost_events && nr_events) {
-               printf("  INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n",
-                       (double)nr_lost_events/(double)nr_events*100.0,
-                       nr_lost_events, nr_events, nr_lost_chunks);
-       }
-       if (nr_state_machine_bugs && nr_timestamps) {
-               printf("  INFO: %.3f%% state machine bugs (%ld out of %ld)",
-                       (double)nr_state_machine_bugs/(double)nr_timestamps*100.0,
-                       nr_state_machine_bugs, nr_timestamps);
-               if (nr_lost_events)
-                       printf(" (due to lost events?)");
-               printf("\n");
-       }
-       printf("\n");
-
-}
-
 static struct trace_sched_handler *trace_handler;
 
 static void
@@ -1422,13 +1340,106 @@ process_sched_wakeup_event(struct raw_event_sample *raw,
        FILL_FIELD(wakeup_event, success, event, raw->data);
        FILL_FIELD(wakeup_event, cpu, event, raw->data);
 
-       trace_handler->wakeup_event(&wakeup_event, event, cpu, timestamp, thread);
+       if (trace_handler->wakeup_event)
+               trace_handler->wakeup_event(&wakeup_event, event, cpu, timestamp, thread);
 }
 
+/*
+ * Track the current task - that way we can know whether there's any
+ * weird events, such as a task being switched away that is not current.
+ */
+static int max_cpu;
+
+static u32 curr_pid[MAX_CPUS] = { [0 ... MAX_CPUS-1] = -1 };
+
+static struct thread *curr_thread[MAX_CPUS];
+
+static char next_shortname1 = 'A';
+static char next_shortname2 = '0';
+
+static void
+map_switch_event(struct trace_switch_event *switch_event,
+                struct event *event __used,
+                int this_cpu,
+                u64 timestamp,
+                struct thread *thread __used)
+{
+       struct thread *sched_out, *sched_in;
+       int new_shortname;
+       u64 timestamp0;
+       s64 delta;
+       int cpu;
+
+       BUG_ON(this_cpu >= MAX_CPUS || this_cpu < 0);
+
+       if (this_cpu > max_cpu)
+               max_cpu = this_cpu;
+
+       timestamp0 = cpu_last_switched[this_cpu];
+       cpu_last_switched[this_cpu] = timestamp;
+       if (timestamp0)
+               delta = timestamp - timestamp0;
+       else
+               delta = 0;
+
+       if (delta < 0)
+               die("hm, delta: %Ld < 0 ?\n", delta);
+
+
+       sched_out = threads__findnew(switch_event->prev_pid, &threads, &last_match);
+       sched_in = threads__findnew(switch_event->next_pid, &threads, &last_match);
+
+       curr_thread[this_cpu] = sched_in;
+
+       printf("  ");
+
+       new_shortname = 0;
+       if (!sched_in->shortname[0]) {
+               sched_in->shortname[0] = next_shortname1;
+               sched_in->shortname[1] = next_shortname2;
+
+               if (next_shortname1 < 'Z') {
+                       next_shortname1++;
+               } else {
+                       next_shortname1='A';
+                       if (next_shortname2 < '9') {
+                               next_shortname2++;
+                       } else {
+                               next_shortname2='0';
+                       }
+               }
+               new_shortname = 1;
+       }
+
+       for (cpu = 0; cpu <= max_cpu; cpu++) {
+               if (cpu != this_cpu)
+                       printf(" ");
+               else
+                       printf("*");
+
+               if (curr_thread[cpu]) {
+                       if (curr_thread[cpu]->pid)
+                               printf("%2s ", curr_thread[cpu]->shortname);
+                       else
+                               printf(".  ");
+               } else
+                       printf("   ");
+       }
+
+       printf("  %12.6f secs ", (double)timestamp/1e9);
+       if (new_shortname) {
+               printf("%s => %s:%d\n",
+                       sched_in->shortname, sched_in->comm, sched_in->pid);
+       } else {
+               printf("\n");
+       }
+}
+
+
 static void
 process_sched_switch_event(struct raw_event_sample *raw,
                           struct event *event,
-                          int cpu __used,
+                          int this_cpu,
                           u64 timestamp __used,
                           struct thread *thread __used)
 {
@@ -1444,7 +1455,18 @@ process_sched_switch_event(struct raw_event_sample *raw,
        FILL_FIELD(switch_event, next_pid, event, raw->data);
        FILL_FIELD(switch_event, next_prio, event, raw->data);
 
-       trace_handler->switch_event(&switch_event, event, cpu, timestamp, thread);
+       if (curr_pid[this_cpu] != (u32)-1) {
+               /*
+                * Are we trying to switch away a PID that is
+                * not current?
+                */
+               if (curr_pid[this_cpu] != switch_event.prev_pid)
+                       nr_context_switch_bugs++;
+       }
+       if (trace_handler->switch_event)
+               trace_handler->switch_event(&switch_event, event, this_cpu, timestamp, thread);
+
+       curr_pid[this_cpu] = switch_event.next_pid;
 }
 
 static void
@@ -1461,7 +1483,8 @@ process_sched_runtime_event(struct raw_event_sample *raw,
        FILL_FIELD(runtime_event, runtime, event, raw->data);
        FILL_FIELD(runtime_event, vruntime, event, raw->data);
 
-       trace_handler->runtime_event(&runtime_event, event, cpu, timestamp, thread);
+       if (trace_handler->runtime_event)
+               trace_handler->runtime_event(&runtime_event, event, cpu, timestamp, thread);
 }
 
 static void
@@ -1480,7 +1503,8 @@ process_sched_fork_event(struct raw_event_sample *raw,
        FILL_ARRAY(fork_event, child_comm, event, raw->data);
        FILL_FIELD(fork_event, child_pid, event, raw->data);
 
-       trace_handler->fork_event(&fork_event, event, cpu, timestamp, thread);
+       if (trace_handler->fork_event)
+               trace_handler->fork_event(&fork_event, event, cpu, timestamp, thread);
 }
 
 static void
@@ -1521,16 +1545,15 @@ process_raw_event(event_t *raw_event __used, void *more_data,
 static int
 process_sample_event(event_t *event, unsigned long offset, unsigned long head)
 {
-       char level;
-       int show = 0;
-       struct dso *dso = NULL;
        struct thread *thread;
        u64 ip = event->ip.ip;
        u64 timestamp = -1;
        u32 cpu = -1;
        u64 period = 1;
        void *more_data = event->ip.__more_data;
-       int cpumode;
+
+       if (!(sample_type & PERF_SAMPLE_RAW))
+               return 0;
 
        thread = threads__findnew(event->ip.pid, &threads, &last_match);
 
@@ -1550,7 +1573,7 @@ process_sample_event(event_t *event, unsigned long offset, unsigned long head)
                more_data += sizeof(u64);
        }
 
-       dump_printf("%p [%p]: PERF_EVENT_SAMPLE (IP, %d): %d/%d: %p period: %Ld\n",
+       dump_printf("%p [%p]: PERF_RECORD_SAMPLE (IP, %d): %d/%d: %p period: %Ld\n",
                (void *)(offset + head),
                (void *)(long)(event->header.size),
                event->header.misc,
@@ -1566,169 +1589,171 @@ process_sample_event(event_t *event, unsigned long offset, unsigned long head)
                return -1;
        }
 
-       cpumode = event->header.misc & PERF_EVENT_MISC_CPUMODE_MASK;
-
-       if (cpumode == PERF_EVENT_MISC_KERNEL) {
-               show = SHOW_KERNEL;
-               level = 'k';
-
-               dso = kernel_dso;
-
-               dump_printf(" ...... dso: %s\n", dso->name);
-
-       } else if (cpumode == PERF_EVENT_MISC_USER) {
-
-               show = SHOW_USER;
-               level = '.';
-
-       } else {
-               show = SHOW_HV;
-               level = 'H';
-
-               dso = hypervisor_dso;
-
-               dump_printf(" ...... dso: [hypervisor]\n");
-       }
-
-       if (sample_type & PERF_SAMPLE_RAW)
-               process_raw_event(event, more_data, cpu, timestamp, thread);
+       process_raw_event(event, more_data, cpu, timestamp, thread);
 
        return 0;
 }
 
 static int
-process_event(event_t *event, unsigned long offset, unsigned long head)
+process_lost_event(event_t *event __used,
+                  unsigned long offset __used,
+                  unsigned long head __used)
 {
-       trace_event(event);
+       nr_lost_chunks++;
+       nr_lost_events += event->lost.lost;
 
-       nr_events++;
-       switch (event->header.type) {
-       case PERF_EVENT_MMAP:
-               return 0;
-       case PERF_EVENT_LOST:
-               nr_lost_chunks++;
-               nr_lost_events += event->lost.lost;
-               return 0;
-
-       case PERF_EVENT_COMM:
-               return process_comm_event(event, offset, head);
-
-       case PERF_EVENT_EXIT ... PERF_EVENT_READ:
-               return 0;
+       return 0;
+}
 
-       case PERF_EVENT_SAMPLE:
-               return process_sample_event(event, offset, head);
+static int sample_type_check(u64 type)
+{
+       sample_type = type;
 
-       case PERF_EVENT_MAX:
-       default:
+       if (!(sample_type & PERF_SAMPLE_RAW)) {
+               fprintf(stderr,
+                       "No trace sample to read. Did you call perf record "
+                       "without -R?");
                return -1;
        }
 
        return 0;
 }
 
+static struct perf_file_handler file_handler = {
+       .process_sample_event   = process_sample_event,
+       .process_comm_event     = process_comm_event,
+       .process_lost_event     = process_lost_event,
+       .sample_type_check      = sample_type_check,
+};
+
 static int read_events(void)
 {
-       int ret, rc = EXIT_FAILURE;
-       unsigned long offset = 0;
-       unsigned long head = 0;
-       struct stat perf_stat;
-       event_t *event;
-       uint32_t size;
-       char *buf;
-
-       trace_report();
        register_idle_thread(&threads, &last_match);
+       register_perf_file_handler(&file_handler);
 
-       input = open(input_name, O_RDONLY);
-       if (input < 0) {
-               perror("failed to open file");
-               exit(-1);
-       }
+       return mmap_dispatch_perf_file(&header, input_name, 0, 0, &cwdlen, &cwd);
+}
 
-       ret = fstat(input, &perf_stat);
-       if (ret < 0) {
-               perror("failed to stat file");
-               exit(-1);
+static void print_bad_events(void)
+{
+       if (nr_unordered_timestamps && nr_timestamps) {
+               printf("  INFO: %.3f%% unordered timestamps (%ld out of %ld)\n",
+                       (double)nr_unordered_timestamps/(double)nr_timestamps*100.0,
+                       nr_unordered_timestamps, nr_timestamps);
        }
-
-       if (!perf_stat.st_size) {
-               fprintf(stderr, "zero-sized file, nothing to do!\n");
-               exit(0);
+       if (nr_lost_events && nr_events) {
+               printf("  INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n",
+                       (double)nr_lost_events/(double)nr_events*100.0,
+                       nr_lost_events, nr_events, nr_lost_chunks);
        }
-       header = perf_header__read(input);
-       head = header->data_offset;
-       sample_type = perf_header__sample_type(header);
+       if (nr_state_machine_bugs && nr_timestamps) {
+               printf("  INFO: %.3f%% state machine bugs (%ld out of %ld)",
+                       (double)nr_state_machine_bugs/(double)nr_timestamps*100.0,
+                       nr_state_machine_bugs, nr_timestamps);
+               if (nr_lost_events)
+                       printf(" (due to lost events?)");
+               printf("\n");
+       }
+       if (nr_context_switch_bugs && nr_timestamps) {
+               printf("  INFO: %.3f%% context switch bugs (%ld out of %ld)",
+                       (double)nr_context_switch_bugs/(double)nr_timestamps*100.0,
+                       nr_context_switch_bugs, nr_timestamps);
+               if (nr_lost_events)
+                       printf(" (due to lost events?)");
+               printf("\n");
+       }
+}
 
-       if (!(sample_type & PERF_SAMPLE_RAW))
-               die("No trace sample to read. Did you call perf record "
-                   "without -R?");
+static void __cmd_lat(void)
+{
+       struct rb_node *next;
 
-       if (load_kernel() < 0) {
-               perror("failed to load kernel symbols");
-               return EXIT_FAILURE;
-       }
+       setup_pager();
+       read_events();
+       sort_lat();
+
+       printf("\n -----------------------------------------------------------------------------------------\n");
+       printf("  Task                  |   Runtime ms  | Switches | Average delay ms | Maximum delay ms |\n");
+       printf(" -----------------------------------------------------------------------------------------\n");
+
+       next = rb_first(&sorted_atom_root);
+
+       while (next) {
+               struct work_atoms *work_list;
 
-remap:
-       buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
-                          MAP_SHARED, input, offset);
-       if (buf == MAP_FAILED) {
-               perror("failed to mmap file");
-               exit(-1);
+               work_list = rb_entry(next, struct work_atoms, node);
+               output_lat_thread(work_list);
+               next = rb_next(next);
        }
 
-more:
-       event = (event_t *)(buf + head);
+       printf(" -----------------------------------------------------------------------------------------\n");
+       printf("  TOTAL:                |%11.3f ms |%9Ld |\n",
+               (double)all_runtime/1e6, all_count);
 
-       size = event->header.size;
-       if (!size)
-               size = 8;
+       printf(" ---------------------------------------------------\n");
 
-       if (head + event->header.size >= page_size * mmap_window) {
-               unsigned long shift = page_size * (head / page_size);
-               int res;
+       print_bad_events();
+       printf("\n");
 
-               res = munmap(buf, page_size * mmap_window);
-               assert(res == 0);
+}
 
-               offset += shift;
-               head -= shift;
-               goto remap;
-       }
+static struct trace_sched_handler map_ops  = {
+       .wakeup_event           = NULL,
+       .switch_event           = map_switch_event,
+       .runtime_event          = NULL,
+       .fork_event             = NULL,
+};
 
-       size = event->header.size;
+static void __cmd_map(void)
+{
+       max_cpu = sysconf(_SC_NPROCESSORS_CONF);
 
+       setup_pager();
+       read_events();
+       print_bad_events();
+}
 
-       if (!size || process_event(event, offset, head) < 0) {
+static void __cmd_replay(void)
+{
+       unsigned long i;
 
-               /*
-                * assume we lost track of the stream, check alignment, and
-                * increment a single u64 in the hope to catch on again 'soon'.
-                */
+       calibrate_run_measurement_overhead();
+       calibrate_sleep_measurement_overhead();
 
-               if (unlikely(head & 7))
-                       head &= ~7ULL;
+       test_calibrations();
 
-               size = 8;
-       }
+       read_events();
 
-       head += size;
+       printf("nr_run_events:        %ld\n", nr_run_events);
+       printf("nr_sleep_events:      %ld\n", nr_sleep_events);
+       printf("nr_wakeup_events:     %ld\n", nr_wakeup_events);
 
-       if (offset + head < (unsigned long)perf_stat.st_size)
-               goto more;
+       if (targetless_wakeups)
+               printf("target-less wakeups:  %ld\n", targetless_wakeups);
+       if (multitarget_wakeups)
+               printf("multi-target wakeups: %ld\n", multitarget_wakeups);
+       if (nr_run_events_optimized)
+               printf("run atoms optimized: %ld\n",
+                       nr_run_events_optimized);
 
-       rc = EXIT_SUCCESS;
-       close(input);
+       print_task_traces();
+       add_cross_task_wakeups();
 
-       return rc;
+       create_tasks();
+       printf("------------------------------------------------------------\n");
+       for (i = 0; i < replay_repeat; i++)
+               run_one_test();
 }
 
+
 static const char * const sched_usage[] = {
-       "perf sched [<options>] {record|latency|replay|trace}",
+       "perf sched [<options>] {record|latency|map|replay|trace}",
        NULL
 };
 
 static const struct option sched_options[] = {
+       OPT_STRING('i', "input", &input_name, "file",
+                   "input file name"),
        OPT_BOOLEAN('v', "verbose", &verbose,
                    "be more verbose (show symbol address, etc)"),
        OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
@@ -1824,7 +1849,6 @@ static int __cmd_record(int argc, const char **argv)
 int cmd_sched(int argc, const char **argv, const char *prefix __used)
 {
        symbol__init();
-       page_size = getpagesize();
 
        argc = parse_options(argc, argv, sched_options, sched_usage,
                             PARSE_OPT_STOP_AT_NON_OPTION);
@@ -1842,6 +1866,10 @@ int cmd_sched(int argc, const char **argv, const char *prefix __used)
                }
                setup_sorting();
                __cmd_lat();
+       } else if (!strcmp(argv[0], "map")) {
+               trace_handler = &map_ops;
+               setup_sorting();
+               __cmd_map();
        } else if (!strncmp(argv[0], "rep", 3)) {
                trace_handler = &replay_ops;
                if (argc) {