aboutsummaryrefslogtreecommitdiffstats
path: root/tools/perf/builtin-sched.c
diff options
context:
space:
mode:
Diffstat (limited to 'tools/perf/builtin-sched.c')
-rw-r--r--tools/perf/builtin-sched.c565
1 files changed, 245 insertions, 320 deletions
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index ce2d5be4f30e..4f5a03e43444 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -6,13 +6,13 @@
6#include "util/symbol.h" 6#include "util/symbol.h"
7#include "util/thread.h" 7#include "util/thread.h"
8#include "util/header.h" 8#include "util/header.h"
9#include "util/session.h"
9 10
10#include "util/parse-options.h" 11#include "util/parse-options.h"
11#include "util/trace-event.h" 12#include "util/trace-event.h"
12 13
13#include "util/debug.h" 14#include "util/debug.h"
14 15
15#include <sys/types.h>
16#include <sys/prctl.h> 16#include <sys/prctl.h>
17 17
18#include <semaphore.h> 18#include <semaphore.h>
@@ -20,26 +20,15 @@
20#include <math.h> 20#include <math.h>
21 21
22static char const *input_name = "perf.data"; 22static char const *input_name = "perf.data";
23static int input;
24static unsigned long page_size;
25static unsigned long mmap_window = 32;
26
27static unsigned long total_comm = 0;
28
29static struct rb_root threads;
30static struct thread *last_match;
31
32static struct perf_header *header;
33static u64 sample_type;
34 23
35static char default_sort_order[] = "avg, max, switch, runtime"; 24static char default_sort_order[] = "avg, max, switch, runtime";
36static char *sort_order = default_sort_order; 25static char *sort_order = default_sort_order;
37 26
27static int profile_cpu = -1;
28
38#define PR_SET_NAME 15 /* Set process name */ 29#define PR_SET_NAME 15 /* Set process name */
39#define MAX_CPUS 4096 30#define MAX_CPUS 4096
40 31
41#define BUG_ON(x) assert(!(x))
42
43static u64 run_measurement_overhead; 32static u64 run_measurement_overhead;
44static u64 sleep_measurement_overhead; 33static u64 sleep_measurement_overhead;
45 34
@@ -74,6 +63,7 @@ enum sched_event_type {
74 SCHED_EVENT_RUN, 63 SCHED_EVENT_RUN,
75 SCHED_EVENT_SLEEP, 64 SCHED_EVENT_SLEEP,
76 SCHED_EVENT_WAKEUP, 65 SCHED_EVENT_WAKEUP,
66 SCHED_EVENT_MIGRATION,
77}; 67};
78 68
79struct sched_atom { 69struct sched_atom {
@@ -147,6 +137,7 @@ struct work_atoms {
147 struct thread *thread; 137 struct thread *thread;
148 struct rb_node node; 138 struct rb_node node;
149 u64 max_lat; 139 u64 max_lat;
140 u64 max_lat_at;
150 u64 total_lat; 141 u64 total_lat;
151 u64 nb_atoms; 142 u64 nb_atoms;
152 u64 total_runtime; 143 u64 total_runtime;
@@ -226,7 +217,7 @@ static void calibrate_sleep_measurement_overhead(void)
226static struct sched_atom * 217static struct sched_atom *
227get_new_event(struct task_desc *task, u64 timestamp) 218get_new_event(struct task_desc *task, u64 timestamp)
228{ 219{
229 struct sched_atom *event = calloc(1, sizeof(*event)); 220 struct sched_atom *event = zalloc(sizeof(*event));
230 unsigned long idx = task->nr_events; 221 unsigned long idx = task->nr_events;
231 size_t size; 222 size_t size;
232 223
@@ -294,7 +285,7 @@ add_sched_event_wakeup(struct task_desc *task, u64 timestamp,
294 return; 285 return;
295 } 286 }
296 287
297 wakee_event->wait_sem = calloc(1, sizeof(*wakee_event->wait_sem)); 288 wakee_event->wait_sem = zalloc(sizeof(*wakee_event->wait_sem));
298 sem_init(wakee_event->wait_sem, 0, 0); 289 sem_init(wakee_event->wait_sem, 0, 0);
299 wakee_event->specific_wait = 1; 290 wakee_event->specific_wait = 1;
300 event->wait_sem = wakee_event->wait_sem; 291 event->wait_sem = wakee_event->wait_sem;
@@ -324,7 +315,7 @@ static struct task_desc *register_pid(unsigned long pid, const char *comm)
324 if (task) 315 if (task)
325 return task; 316 return task;
326 317
327 task = calloc(1, sizeof(*task)); 318 task = zalloc(sizeof(*task));
328 task->pid = pid; 319 task->pid = pid;
329 task->nr = nr_tasks; 320 task->nr = nr_tasks;
330 strcpy(task->comm, comm); 321 strcpy(task->comm, comm);
@@ -398,6 +389,8 @@ process_sched_event(struct task_desc *this_task __used, struct sched_atom *atom)
398 ret = sem_post(atom->wait_sem); 389 ret = sem_post(atom->wait_sem);
399 BUG_ON(ret); 390 BUG_ON(ret);
400 break; 391 break;
392 case SCHED_EVENT_MIGRATION:
393 break;
401 default: 394 default:
402 BUG_ON(1); 395 BUG_ON(1);
403 } 396 }
@@ -418,34 +411,33 @@ static u64 get_cpu_usage_nsec_parent(void)
418 return sum; 411 return sum;
419} 412}
420 413
421static u64 get_cpu_usage_nsec_self(void) 414static int self_open_counters(void)
422{ 415{
423 char filename [] = "/proc/1234567890/sched"; 416 struct perf_event_attr attr;
424 unsigned long msecs, nsecs; 417 int fd;
425 char *line = NULL;
426 u64 total = 0;
427 size_t len = 0;
428 ssize_t chars;
429 FILE *file;
430 int ret;
431 418
432 sprintf(filename, "/proc/%d/sched", getpid()); 419 memset(&attr, 0, sizeof(attr));
433 file = fopen(filename, "r");
434 BUG_ON(!file);
435 420
436 while ((chars = getline(&line, &len, file)) != -1) { 421 attr.type = PERF_TYPE_SOFTWARE;
437 ret = sscanf(line, "se.sum_exec_runtime : %ld.%06ld\n", 422 attr.config = PERF_COUNT_SW_TASK_CLOCK;
438 &msecs, &nsecs); 423
439 if (ret == 2) { 424 fd = sys_perf_event_open(&attr, 0, -1, -1, 0);
440 total = msecs*1e6 + nsecs;
441 break;
442 }
443 }
444 if (line)
445 free(line);
446 fclose(file);
447 425
448 return total; 426 if (fd < 0)
427 die("Error: sys_perf_event_open() syscall returned"
428 "with %d (%s)\n", fd, strerror(errno));
429 return fd;
430}
431
432static u64 get_cpu_usage_nsec_self(int fd)
433{
434 u64 runtime;
435 int ret;
436
437 ret = read(fd, &runtime, sizeof(runtime));
438 BUG_ON(ret != sizeof(runtime));
439
440 return runtime;
449} 441}
450 442
451static void *thread_func(void *ctx) 443static void *thread_func(void *ctx)
@@ -454,9 +446,11 @@ static void *thread_func(void *ctx)
454 u64 cpu_usage_0, cpu_usage_1; 446 u64 cpu_usage_0, cpu_usage_1;
455 unsigned long i, ret; 447 unsigned long i, ret;
456 char comm2[22]; 448 char comm2[22];
449 int fd;
457 450
458 sprintf(comm2, ":%s", this_task->comm); 451 sprintf(comm2, ":%s", this_task->comm);
459 prctl(PR_SET_NAME, comm2); 452 prctl(PR_SET_NAME, comm2);
453 fd = self_open_counters();
460 454
461again: 455again:
462 ret = sem_post(&this_task->ready_for_work); 456 ret = sem_post(&this_task->ready_for_work);
@@ -466,16 +460,15 @@ again:
466 ret = pthread_mutex_unlock(&start_work_mutex); 460 ret = pthread_mutex_unlock(&start_work_mutex);
467 BUG_ON(ret); 461 BUG_ON(ret);
468 462
469 cpu_usage_0 = get_cpu_usage_nsec_self(); 463 cpu_usage_0 = get_cpu_usage_nsec_self(fd);
470 464
471 for (i = 0; i < this_task->nr_events; i++) { 465 for (i = 0; i < this_task->nr_events; i++) {
472 this_task->curr_event = i; 466 this_task->curr_event = i;
473 process_sched_event(this_task, this_task->atoms[i]); 467 process_sched_event(this_task, this_task->atoms[i]);
474 } 468 }
475 469
476 cpu_usage_1 = get_cpu_usage_nsec_self(); 470 cpu_usage_1 = get_cpu_usage_nsec_self(fd);
477 this_task->cpu_usage = cpu_usage_1 - cpu_usage_0; 471 this_task->cpu_usage = cpu_usage_1 - cpu_usage_0;
478
479 ret = sem_post(&this_task->work_done_sem); 472 ret = sem_post(&this_task->work_done_sem);
480 BUG_ON(ret); 473 BUG_ON(ret);
481 474
@@ -632,34 +625,6 @@ static void test_calibrations(void)
632 printf("the sleep test took %Ld nsecs\n", T1-T0); 625 printf("the sleep test took %Ld nsecs\n", T1-T0);
633} 626}
634 627
635static int
636process_comm_event(event_t *event, unsigned long offset, unsigned long head)
637{
638 struct thread *thread;
639
640 thread = threads__findnew(event->comm.pid, &threads, &last_match);
641
642 dump_printf("%p [%p]: perf_event_comm: %s:%d\n",
643 (void *)(offset + head),
644 (void *)(long)(event->header.size),
645 event->comm.comm, event->comm.pid);
646
647 if (thread == NULL ||
648 thread__set_comm(thread, event->comm.comm)) {
649 dump_printf("problem processing perf_event_comm, skipping event.\n");
650 return -1;
651 }
652 total_comm++;
653
654 return 0;
655}
656
657
658struct raw_event_sample {
659 u32 size;
660 char data[0];
661};
662
663#define FILL_FIELD(ptr, field, event, data) \ 628#define FILL_FIELD(ptr, field, event, data) \
664 ptr.field = (typeof(ptr.field)) raw_field_value(event, #field, data) 629 ptr.field = (typeof(ptr.field)) raw_field_value(event, #field, data)
665 630
@@ -745,20 +710,39 @@ struct trace_fork_event {
745 u32 child_pid; 710 u32 child_pid;
746}; 711};
747 712
713struct trace_migrate_task_event {
714 u32 size;
715
716 u16 common_type;
717 u8 common_flags;
718 u8 common_preempt_count;
719 u32 common_pid;
720 u32 common_tgid;
721
722 char comm[16];
723 u32 pid;
724
725 u32 prio;
726 u32 cpu;
727};
728
748struct trace_sched_handler { 729struct trace_sched_handler {
749 void (*switch_event)(struct trace_switch_event *, 730 void (*switch_event)(struct trace_switch_event *,
731 struct perf_session *,
750 struct event *, 732 struct event *,
751 int cpu, 733 int cpu,
752 u64 timestamp, 734 u64 timestamp,
753 struct thread *thread); 735 struct thread *thread);
754 736
755 void (*runtime_event)(struct trace_runtime_event *, 737 void (*runtime_event)(struct trace_runtime_event *,
738 struct perf_session *,
756 struct event *, 739 struct event *,
757 int cpu, 740 int cpu,
758 u64 timestamp, 741 u64 timestamp,
759 struct thread *thread); 742 struct thread *thread);
760 743
761 void (*wakeup_event)(struct trace_wakeup_event *, 744 void (*wakeup_event)(struct trace_wakeup_event *,
745 struct perf_session *,
762 struct event *, 746 struct event *,
763 int cpu, 747 int cpu,
764 u64 timestamp, 748 u64 timestamp,
@@ -769,11 +753,19 @@ struct trace_sched_handler {
769 int cpu, 753 int cpu,
770 u64 timestamp, 754 u64 timestamp,
771 struct thread *thread); 755 struct thread *thread);
756
757 void (*migrate_task_event)(struct trace_migrate_task_event *,
758 struct perf_session *session,
759 struct event *,
760 int cpu,
761 u64 timestamp,
762 struct thread *thread);
772}; 763};
773 764
774 765
775static void 766static void
776replay_wakeup_event(struct trace_wakeup_event *wakeup_event, 767replay_wakeup_event(struct trace_wakeup_event *wakeup_event,
768 struct perf_session *session __used,
777 struct event *event, 769 struct event *event,
778 int cpu __used, 770 int cpu __used,
779 u64 timestamp __used, 771 u64 timestamp __used,
@@ -800,6 +792,7 @@ static u64 cpu_last_switched[MAX_CPUS];
800 792
801static void 793static void
802replay_switch_event(struct trace_switch_event *switch_event, 794replay_switch_event(struct trace_switch_event *switch_event,
795 struct perf_session *session __used,
803 struct event *event, 796 struct event *event,
804 int cpu, 797 int cpu,
805 u64 timestamp, 798 u64 timestamp,
@@ -941,9 +934,7 @@ __thread_latency_insert(struct rb_root *root, struct work_atoms *data,
941 934
942static void thread_atoms_insert(struct thread *thread) 935static void thread_atoms_insert(struct thread *thread)
943{ 936{
944 struct work_atoms *atoms; 937 struct work_atoms *atoms = zalloc(sizeof(*atoms));
945
946 atoms = calloc(sizeof(*atoms), 1);
947 if (!atoms) 938 if (!atoms)
948 die("No memory"); 939 die("No memory");
949 940
@@ -975,9 +966,7 @@ add_sched_out_event(struct work_atoms *atoms,
975 char run_state, 966 char run_state,
976 u64 timestamp) 967 u64 timestamp)
977{ 968{
978 struct work_atom *atom; 969 struct work_atom *atom = zalloc(sizeof(*atom));
979
980 atom = calloc(sizeof(*atom), 1);
981 if (!atom) 970 if (!atom)
982 die("Non memory"); 971 die("Non memory");
983 972
@@ -1028,13 +1017,16 @@ add_sched_in_event(struct work_atoms *atoms, u64 timestamp)
1028 1017
1029 delta = atom->sched_in_time - atom->wake_up_time; 1018 delta = atom->sched_in_time - atom->wake_up_time;
1030 atoms->total_lat += delta; 1019 atoms->total_lat += delta;
1031 if (delta > atoms->max_lat) 1020 if (delta > atoms->max_lat) {
1032 atoms->max_lat = delta; 1021 atoms->max_lat = delta;
1022 atoms->max_lat_at = timestamp;
1023 }
1033 atoms->nb_atoms++; 1024 atoms->nb_atoms++;
1034} 1025}
1035 1026
1036static void 1027static void
1037latency_switch_event(struct trace_switch_event *switch_event, 1028latency_switch_event(struct trace_switch_event *switch_event,
1029 struct perf_session *session,
1038 struct event *event __used, 1030 struct event *event __used,
1039 int cpu, 1031 int cpu,
1040 u64 timestamp, 1032 u64 timestamp,
@@ -1058,8 +1050,8 @@ latency_switch_event(struct trace_switch_event *switch_event,
1058 die("hm, delta: %Ld < 0 ?\n", delta); 1050 die("hm, delta: %Ld < 0 ?\n", delta);
1059 1051
1060 1052
1061 sched_out = threads__findnew(switch_event->prev_pid, &threads, &last_match); 1053 sched_out = perf_session__findnew(session, switch_event->prev_pid);
1062 sched_in = threads__findnew(switch_event->next_pid, &threads, &last_match); 1054 sched_in = perf_session__findnew(session, switch_event->next_pid);
1063 1055
1064 out_events = thread_atoms_search(&atom_root, sched_out, &cmp_pid); 1056 out_events = thread_atoms_search(&atom_root, sched_out, &cmp_pid);
1065 if (!out_events) { 1057 if (!out_events) {
@@ -1087,18 +1079,16 @@ latency_switch_event(struct trace_switch_event *switch_event,
1087 1079
1088static void 1080static void
1089latency_runtime_event(struct trace_runtime_event *runtime_event, 1081latency_runtime_event(struct trace_runtime_event *runtime_event,
1082 struct perf_session *session,
1090 struct event *event __used, 1083 struct event *event __used,
1091 int cpu, 1084 int cpu,
1092 u64 timestamp, 1085 u64 timestamp,
1093 struct thread *this_thread __used) 1086 struct thread *this_thread __used)
1094{ 1087{
1095 struct work_atoms *atoms; 1088 struct thread *thread = perf_session__findnew(session, runtime_event->pid);
1096 struct thread *thread; 1089 struct work_atoms *atoms = thread_atoms_search(&atom_root, thread, &cmp_pid);
1097 1090
1098 BUG_ON(cpu >= MAX_CPUS || cpu < 0); 1091 BUG_ON(cpu >= MAX_CPUS || cpu < 0);
1099
1100 thread = threads__findnew(runtime_event->pid, &threads, &last_match);
1101 atoms = thread_atoms_search(&atom_root, thread, &cmp_pid);
1102 if (!atoms) { 1092 if (!atoms) {
1103 thread_atoms_insert(thread); 1093 thread_atoms_insert(thread);
1104 atoms = thread_atoms_search(&atom_root, thread, &cmp_pid); 1094 atoms = thread_atoms_search(&atom_root, thread, &cmp_pid);
@@ -1112,6 +1102,7 @@ latency_runtime_event(struct trace_runtime_event *runtime_event,
1112 1102
1113static void 1103static void
1114latency_wakeup_event(struct trace_wakeup_event *wakeup_event, 1104latency_wakeup_event(struct trace_wakeup_event *wakeup_event,
1105 struct perf_session *session,
1115 struct event *__event __used, 1106 struct event *__event __used,
1116 int cpu __used, 1107 int cpu __used,
1117 u64 timestamp, 1108 u64 timestamp,
@@ -1125,7 +1116,7 @@ latency_wakeup_event(struct trace_wakeup_event *wakeup_event,
1125 if (!wakeup_event->success) 1116 if (!wakeup_event->success)
1126 return; 1117 return;
1127 1118
1128 wakee = threads__findnew(wakeup_event->pid, &threads, &last_match); 1119 wakee = perf_session__findnew(session, wakeup_event->pid);
1129 atoms = thread_atoms_search(&atom_root, wakee, &cmp_pid); 1120 atoms = thread_atoms_search(&atom_root, wakee, &cmp_pid);
1130 if (!atoms) { 1121 if (!atoms) {
1131 thread_atoms_insert(wakee); 1122 thread_atoms_insert(wakee);
@@ -1139,7 +1130,12 @@ latency_wakeup_event(struct trace_wakeup_event *wakeup_event,
1139 1130
1140 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1131 atom = list_entry(atoms->work_list.prev, struct work_atom, list);
1141 1132
1142 if (atom->state != THREAD_SLEEPING) 1133 /*
1134 * You WILL be missing events if you've recorded only
1135 * one CPU, or are only looking at only one, so don't
1136 * make useless noise.
1137 */
1138 if (profile_cpu == -1 && atom->state != THREAD_SLEEPING)
1143 nr_state_machine_bugs++; 1139 nr_state_machine_bugs++;
1144 1140
1145 nr_timestamps++; 1141 nr_timestamps++;
@@ -1152,11 +1148,52 @@ latency_wakeup_event(struct trace_wakeup_event *wakeup_event,
1152 atom->wake_up_time = timestamp; 1148 atom->wake_up_time = timestamp;
1153} 1149}
1154 1150
1151static void
1152latency_migrate_task_event(struct trace_migrate_task_event *migrate_task_event,
1153 struct perf_session *session,
1154 struct event *__event __used,
1155 int cpu __used,
1156 u64 timestamp,
1157 struct thread *thread __used)
1158{
1159 struct work_atoms *atoms;
1160 struct work_atom *atom;
1161 struct thread *migrant;
1162
1163 /*
1164 * Only need to worry about migration when profiling one CPU.
1165 */
1166 if (profile_cpu == -1)
1167 return;
1168
1169 migrant = perf_session__findnew(session, migrate_task_event->pid);
1170 atoms = thread_atoms_search(&atom_root, migrant, &cmp_pid);
1171 if (!atoms) {
1172 thread_atoms_insert(migrant);
1173 register_pid(migrant->pid, migrant->comm);
1174 atoms = thread_atoms_search(&atom_root, migrant, &cmp_pid);
1175 if (!atoms)
1176 die("migration-event: Internal tree error");
1177 add_sched_out_event(atoms, 'R', timestamp);
1178 }
1179
1180 BUG_ON(list_empty(&atoms->work_list));
1181
1182 atom = list_entry(atoms->work_list.prev, struct work_atom, list);
1183 atom->sched_in_time = atom->sched_out_time = atom->wake_up_time = timestamp;
1184
1185 nr_timestamps++;
1186
1187 if (atom->sched_out_time > timestamp)
1188 nr_unordered_timestamps++;
1189}
1190
1155static struct trace_sched_handler lat_ops = { 1191static struct trace_sched_handler lat_ops = {
1156 .wakeup_event = latency_wakeup_event, 1192 .wakeup_event = latency_wakeup_event,
1157 .switch_event = latency_switch_event, 1193 .switch_event = latency_switch_event,
1158 .runtime_event = latency_runtime_event, 1194 .runtime_event = latency_runtime_event,
1159 .fork_event = latency_fork_event, 1195 .fork_event = latency_fork_event,
1196 .migrate_task_event = latency_migrate_task_event,
1160}; 1197};
1161 1198
1162static void output_lat_thread(struct work_atoms *work_list) 1199static void output_lat_thread(struct work_atoms *work_list)
@@ -1183,10 +1220,11 @@ static void output_lat_thread(struct work_atoms *work_list)
1183 1220
1184 avg = work_list->total_lat / work_list->nb_atoms; 1221 avg = work_list->total_lat / work_list->nb_atoms;
1185 1222
1186 printf("|%11.3f ms |%9llu | avg:%9.3f ms | max:%9.3f ms |\n", 1223 printf("|%11.3f ms |%9llu | avg:%9.3f ms | max:%9.3f ms | max at: %9.6f s\n",
1187 (double)work_list->total_runtime / 1e6, 1224 (double)work_list->total_runtime / 1e6,
1188 work_list->nb_atoms, (double)avg / 1e6, 1225 work_list->nb_atoms, (double)avg / 1e6,
1189 (double)work_list->max_lat / 1e6); 1226 (double)work_list->max_lat / 1e6,
1227 (double)work_list->max_lat_at / 1e9);
1190} 1228}
1191 1229
1192static int pid_cmp(struct work_atoms *l, struct work_atoms *r) 1230static int pid_cmp(struct work_atoms *l, struct work_atoms *r)
@@ -1323,7 +1361,7 @@ static void sort_lat(void)
1323static struct trace_sched_handler *trace_handler; 1361static struct trace_sched_handler *trace_handler;
1324 1362
1325static void 1363static void
1326process_sched_wakeup_event(struct raw_event_sample *raw, 1364process_sched_wakeup_event(void *data, struct perf_session *session,
1327 struct event *event, 1365 struct event *event,
1328 int cpu __used, 1366 int cpu __used,
1329 u64 timestamp __used, 1367 u64 timestamp __used,
@@ -1331,16 +1369,17 @@ process_sched_wakeup_event(struct raw_event_sample *raw,
1331{ 1369{
1332 struct trace_wakeup_event wakeup_event; 1370 struct trace_wakeup_event wakeup_event;
1333 1371
1334 FILL_COMMON_FIELDS(wakeup_event, event, raw->data); 1372 FILL_COMMON_FIELDS(wakeup_event, event, data);
1335 1373
1336 FILL_ARRAY(wakeup_event, comm, event, raw->data); 1374 FILL_ARRAY(wakeup_event, comm, event, data);
1337 FILL_FIELD(wakeup_event, pid, event, raw->data); 1375 FILL_FIELD(wakeup_event, pid, event, data);
1338 FILL_FIELD(wakeup_event, prio, event, raw->data); 1376 FILL_FIELD(wakeup_event, prio, event, data);
1339 FILL_FIELD(wakeup_event, success, event, raw->data); 1377 FILL_FIELD(wakeup_event, success, event, data);
1340 FILL_FIELD(wakeup_event, cpu, event, raw->data); 1378 FILL_FIELD(wakeup_event, cpu, event, data);
1341 1379
1342 if (trace_handler->wakeup_event) 1380 if (trace_handler->wakeup_event)
1343 trace_handler->wakeup_event(&wakeup_event, event, cpu, timestamp, thread); 1381 trace_handler->wakeup_event(&wakeup_event, session, event,
1382 cpu, timestamp, thread);
1344} 1383}
1345 1384
1346/* 1385/*
@@ -1358,6 +1397,7 @@ static char next_shortname2 = '0';
1358 1397
1359static void 1398static void
1360map_switch_event(struct trace_switch_event *switch_event, 1399map_switch_event(struct trace_switch_event *switch_event,
1400 struct perf_session *session,
1361 struct event *event __used, 1401 struct event *event __used,
1362 int this_cpu, 1402 int this_cpu,
1363 u64 timestamp, 1403 u64 timestamp,
@@ -1385,8 +1425,8 @@ map_switch_event(struct trace_switch_event *switch_event,
1385 die("hm, delta: %Ld < 0 ?\n", delta); 1425 die("hm, delta: %Ld < 0 ?\n", delta);
1386 1426
1387 1427
1388 sched_out = threads__findnew(switch_event->prev_pid, &threads, &last_match); 1428 sched_out = perf_session__findnew(session, switch_event->prev_pid);
1389 sched_in = threads__findnew(switch_event->next_pid, &threads, &last_match); 1429 sched_in = perf_session__findnew(session, switch_event->next_pid);
1390 1430
1391 curr_thread[this_cpu] = sched_in; 1431 curr_thread[this_cpu] = sched_in;
1392 1432
@@ -1436,7 +1476,7 @@ map_switch_event(struct trace_switch_event *switch_event,
1436 1476
1437 1477
1438static void 1478static void
1439process_sched_switch_event(struct raw_event_sample *raw, 1479process_sched_switch_event(void *data, struct perf_session *session,
1440 struct event *event, 1480 struct event *event,
1441 int this_cpu, 1481 int this_cpu,
1442 u64 timestamp __used, 1482 u64 timestamp __used,
@@ -1444,15 +1484,15 @@ process_sched_switch_event(struct raw_event_sample *raw,
1444{ 1484{
1445 struct trace_switch_event switch_event; 1485 struct trace_switch_event switch_event;
1446 1486
1447 FILL_COMMON_FIELDS(switch_event, event, raw->data); 1487 FILL_COMMON_FIELDS(switch_event, event, data);
1448 1488
1449 FILL_ARRAY(switch_event, prev_comm, event, raw->data); 1489 FILL_ARRAY(switch_event, prev_comm, event, data);
1450 FILL_FIELD(switch_event, prev_pid, event, raw->data); 1490 FILL_FIELD(switch_event, prev_pid, event, data);
1451 FILL_FIELD(switch_event, prev_prio, event, raw->data); 1491 FILL_FIELD(switch_event, prev_prio, event, data);
1452 FILL_FIELD(switch_event, prev_state, event, raw->data); 1492 FILL_FIELD(switch_event, prev_state, event, data);
1453 FILL_ARRAY(switch_event, next_comm, event, raw->data); 1493 FILL_ARRAY(switch_event, next_comm, event, data);
1454 FILL_FIELD(switch_event, next_pid, event, raw->data); 1494 FILL_FIELD(switch_event, next_pid, event, data);
1455 FILL_FIELD(switch_event, next_prio, event, raw->data); 1495 FILL_FIELD(switch_event, next_prio, event, data);
1456 1496
1457 if (curr_pid[this_cpu] != (u32)-1) { 1497 if (curr_pid[this_cpu] != (u32)-1) {
1458 /* 1498 /*
@@ -1463,13 +1503,14 @@ process_sched_switch_event(struct raw_event_sample *raw,
1463 nr_context_switch_bugs++; 1503 nr_context_switch_bugs++;
1464 } 1504 }
1465 if (trace_handler->switch_event) 1505 if (trace_handler->switch_event)
1466 trace_handler->switch_event(&switch_event, event, this_cpu, timestamp, thread); 1506 trace_handler->switch_event(&switch_event, session, event,
1507 this_cpu, timestamp, thread);
1467 1508
1468 curr_pid[this_cpu] = switch_event.next_pid; 1509 curr_pid[this_cpu] = switch_event.next_pid;
1469} 1510}
1470 1511
1471static void 1512static void
1472process_sched_runtime_event(struct raw_event_sample *raw, 1513process_sched_runtime_event(void *data, struct perf_session *session,
1473 struct event *event, 1514 struct event *event,
1474 int cpu __used, 1515 int cpu __used,
1475 u64 timestamp __used, 1516 u64 timestamp __used,
@@ -1477,17 +1518,17 @@ process_sched_runtime_event(struct raw_event_sample *raw,
1477{ 1518{
1478 struct trace_runtime_event runtime_event; 1519 struct trace_runtime_event runtime_event;
1479 1520
1480 FILL_ARRAY(runtime_event, comm, event, raw->data); 1521 FILL_ARRAY(runtime_event, comm, event, data);
1481 FILL_FIELD(runtime_event, pid, event, raw->data); 1522 FILL_FIELD(runtime_event, pid, event, data);
1482 FILL_FIELD(runtime_event, runtime, event, raw->data); 1523 FILL_FIELD(runtime_event, runtime, event, data);
1483 FILL_FIELD(runtime_event, vruntime, event, raw->data); 1524 FILL_FIELD(runtime_event, vruntime, event, data);
1484 1525
1485 if (trace_handler->runtime_event) 1526 if (trace_handler->runtime_event)
1486 trace_handler->runtime_event(&runtime_event, event, cpu, timestamp, thread); 1527 trace_handler->runtime_event(&runtime_event, session, event, cpu, timestamp, thread);
1487} 1528}
1488 1529
1489static void 1530static void
1490process_sched_fork_event(struct raw_event_sample *raw, 1531process_sched_fork_event(void *data,
1491 struct event *event, 1532 struct event *event,
1492 int cpu __used, 1533 int cpu __used,
1493 u64 timestamp __used, 1534 u64 timestamp __used,
@@ -1495,15 +1536,16 @@ process_sched_fork_event(struct raw_event_sample *raw,
1495{ 1536{
1496 struct trace_fork_event fork_event; 1537 struct trace_fork_event fork_event;
1497 1538
1498 FILL_COMMON_FIELDS(fork_event, event, raw->data); 1539 FILL_COMMON_FIELDS(fork_event, event, data);
1499 1540
1500 FILL_ARRAY(fork_event, parent_comm, event, raw->data); 1541 FILL_ARRAY(fork_event, parent_comm, event, data);
1501 FILL_FIELD(fork_event, parent_pid, event, raw->data); 1542 FILL_FIELD(fork_event, parent_pid, event, data);
1502 FILL_ARRAY(fork_event, child_comm, event, raw->data); 1543 FILL_ARRAY(fork_event, child_comm, event, data);
1503 FILL_FIELD(fork_event, child_pid, event, raw->data); 1544 FILL_FIELD(fork_event, child_pid, event, data);
1504 1545
1505 if (trace_handler->fork_event) 1546 if (trace_handler->fork_event)
1506 trace_handler->fork_event(&fork_event, event, cpu, timestamp, thread); 1547 trace_handler->fork_event(&fork_event, event,
1548 cpu, timestamp, thread);
1507} 1549}
1508 1550
1509static void 1551static void
@@ -1517,233 +1559,115 @@ process_sched_exit_event(struct event *event,
1517} 1559}
1518 1560
1519static void 1561static void
1520process_raw_event(event_t *raw_event __used, void *more_data, 1562process_sched_migrate_task_event(void *data, struct perf_session *session,
1521 int cpu, u64 timestamp, struct thread *thread) 1563 struct event *event,
1564 int cpu __used,
1565 u64 timestamp __used,
1566 struct thread *thread __used)
1567{
1568 struct trace_migrate_task_event migrate_task_event;
1569
1570 FILL_COMMON_FIELDS(migrate_task_event, event, data);
1571
1572 FILL_ARRAY(migrate_task_event, comm, event, data);
1573 FILL_FIELD(migrate_task_event, pid, event, data);
1574 FILL_FIELD(migrate_task_event, prio, event, data);
1575 FILL_FIELD(migrate_task_event, cpu, event, data);
1576
1577 if (trace_handler->migrate_task_event)
1578 trace_handler->migrate_task_event(&migrate_task_event, session,
1579 event, cpu, timestamp, thread);
1580}
1581
1582static void
1583process_raw_event(event_t *raw_event __used, struct perf_session *session,
1584 void *data, int cpu, u64 timestamp, struct thread *thread)
1522{ 1585{
1523 struct raw_event_sample *raw = more_data;
1524 struct event *event; 1586 struct event *event;
1525 int type; 1587 int type;
1526 1588
1527 type = trace_parse_common_type(raw->data); 1589
1590 type = trace_parse_common_type(data);
1528 event = trace_find_event(type); 1591 event = trace_find_event(type);
1529 1592
1530 if (!strcmp(event->name, "sched_switch")) 1593 if (!strcmp(event->name, "sched_switch"))
1531 process_sched_switch_event(raw, event, cpu, timestamp, thread); 1594 process_sched_switch_event(data, session, event, cpu, timestamp, thread);
1532 if (!strcmp(event->name, "sched_stat_runtime")) 1595 if (!strcmp(event->name, "sched_stat_runtime"))
1533 process_sched_runtime_event(raw, event, cpu, timestamp, thread); 1596 process_sched_runtime_event(data, session, event, cpu, timestamp, thread);
1534 if (!strcmp(event->name, "sched_wakeup")) 1597 if (!strcmp(event->name, "sched_wakeup"))
1535 process_sched_wakeup_event(raw, event, cpu, timestamp, thread); 1598 process_sched_wakeup_event(data, session, event, cpu, timestamp, thread);
1536 if (!strcmp(event->name, "sched_wakeup_new")) 1599 if (!strcmp(event->name, "sched_wakeup_new"))
1537 process_sched_wakeup_event(raw, event, cpu, timestamp, thread); 1600 process_sched_wakeup_event(data, session, event, cpu, timestamp, thread);
1538 if (!strcmp(event->name, "sched_process_fork")) 1601 if (!strcmp(event->name, "sched_process_fork"))
1539 process_sched_fork_event(raw, event, cpu, timestamp, thread); 1602 process_sched_fork_event(data, event, cpu, timestamp, thread);
1540 if (!strcmp(event->name, "sched_process_exit")) 1603 if (!strcmp(event->name, "sched_process_exit"))
1541 process_sched_exit_event(event, cpu, timestamp, thread); 1604 process_sched_exit_event(event, cpu, timestamp, thread);
1605 if (!strcmp(event->name, "sched_migrate_task"))
1606 process_sched_migrate_task_event(data, session, event, cpu, timestamp, thread);
1542} 1607}
1543 1608
1544static int 1609static int process_sample_event(event_t *event, struct perf_session *session)
1545process_sample_event(event_t *event, unsigned long offset, unsigned long head)
1546{ 1610{
1547 char level; 1611 struct sample_data data;
1548 int show = 0;
1549 struct dso *dso = NULL;
1550 struct thread *thread; 1612 struct thread *thread;
1551 u64 ip = event->ip.ip;
1552 u64 timestamp = -1;
1553 u32 cpu = -1;
1554 u64 period = 1;
1555 void *more_data = event->ip.__more_data;
1556 int cpumode;
1557
1558 thread = threads__findnew(event->ip.pid, &threads, &last_match);
1559
1560 if (sample_type & PERF_SAMPLE_TIME) {
1561 timestamp = *(u64 *)more_data;
1562 more_data += sizeof(u64);
1563 }
1564 1613
1565 if (sample_type & PERF_SAMPLE_CPU) { 1614 if (!(session->sample_type & PERF_SAMPLE_RAW))
1566 cpu = *(u32 *)more_data; 1615 return 0;
1567 more_data += sizeof(u32);
1568 more_data += sizeof(u32); /* reserved */
1569 }
1570 1616
1571 if (sample_type & PERF_SAMPLE_PERIOD) { 1617 memset(&data, 0, sizeof(data));
1572 period = *(u64 *)more_data; 1618 data.time = -1;
1573 more_data += sizeof(u64); 1619 data.cpu = -1;
1574 } 1620 data.period = -1;
1575 1621
1576 dump_printf("%p [%p]: PERF_RECORD_SAMPLE (IP, %d): %d/%d: %p period: %Ld\n", 1622 event__parse_sample(event, session->sample_type, &data);
1577 (void *)(offset + head),
1578 (void *)(long)(event->header.size),
1579 event->header.misc,
1580 event->ip.pid, event->ip.tid,
1581 (void *)(long)ip,
1582 (long long)period);
1583 1623
1584 dump_printf(" ... thread: %s:%d\n", thread->comm, thread->pid); 1624 dump_printf("(IP, %d): %d/%d: %#Lx period: %Ld\n", event->header.misc,
1625 data.pid, data.tid, data.ip, data.period);
1585 1626
1627 thread = perf_session__findnew(session, data.pid);
1586 if (thread == NULL) { 1628 if (thread == NULL) {
1587 eprintf("problem processing %d event, skipping it.\n", 1629 pr_debug("problem processing %d event, skipping it.\n",
1588 event->header.type); 1630 event->header.type);
1589 return -1; 1631 return -1;
1590 } 1632 }
1591 1633
1592 cpumode = event->header.misc & PERF_RECORD_MISC_CPUMODE_MASK; 1634 dump_printf(" ... thread: %s:%d\n", thread->comm, thread->pid);
1593
1594 if (cpumode == PERF_RECORD_MISC_KERNEL) {
1595 show = SHOW_KERNEL;
1596 level = 'k';
1597
1598 dso = kernel_dso;
1599
1600 dump_printf(" ...... dso: %s\n", dso->name);
1601
1602 } else if (cpumode == PERF_RECORD_MISC_USER) {
1603
1604 show = SHOW_USER;
1605 level = '.';
1606
1607 } else {
1608 show = SHOW_HV;
1609 level = 'H';
1610
1611 dso = hypervisor_dso;
1612 1635
1613 dump_printf(" ...... dso: [hypervisor]\n"); 1636 if (profile_cpu != -1 && profile_cpu != (int)data.cpu)
1614 } 1637 return 0;
1615 1638
1616 if (sample_type & PERF_SAMPLE_RAW) 1639 process_raw_event(event, session, data.raw_data, data.cpu, data.time, thread);
1617 process_raw_event(event, more_data, cpu, timestamp, thread);
1618 1640
1619 return 0; 1641 return 0;
1620} 1642}
1621 1643
1622static int 1644static int process_lost_event(event_t *event __used,
1623process_event(event_t *event, unsigned long offset, unsigned long head) 1645 struct perf_session *session __used)
1624{ 1646{
1625 trace_event(event); 1647 nr_lost_chunks++;
1626 1648 nr_lost_events += event->lost.lost;
1627 nr_events++;
1628 switch (event->header.type) {
1629 case PERF_RECORD_MMAP:
1630 return 0;
1631 case PERF_RECORD_LOST:
1632 nr_lost_chunks++;
1633 nr_lost_events += event->lost.lost;
1634 return 0;
1635
1636 case PERF_RECORD_COMM:
1637 return process_comm_event(event, offset, head);
1638
1639 case PERF_RECORD_EXIT ... PERF_RECORD_READ:
1640 return 0;
1641
1642 case PERF_RECORD_SAMPLE:
1643 return process_sample_event(event, offset, head);
1644
1645 case PERF_RECORD_MAX:
1646 default:
1647 return -1;
1648 }
1649 1649
1650 return 0; 1650 return 0;
1651} 1651}
1652 1652
1653static struct perf_event_ops event_ops = {
1654 .sample = process_sample_event,
1655 .comm = event__process_comm,
1656 .lost = process_lost_event,
1657};
1658
1653static int read_events(void) 1659static int read_events(void)
1654{ 1660{
1655 int ret, rc = EXIT_FAILURE; 1661 int err = -EINVAL;
1656 unsigned long offset = 0; 1662 struct perf_session *session = perf_session__new(input_name, O_RDONLY, 0);
1657 unsigned long head = 0; 1663 if (session == NULL)
1658 struct stat perf_stat; 1664 return -ENOMEM;
1659 event_t *event;
1660 uint32_t size;
1661 char *buf;
1662
1663 trace_report();
1664 register_idle_thread(&threads, &last_match);
1665
1666 input = open(input_name, O_RDONLY);
1667 if (input < 0) {
1668 perror("failed to open file");
1669 exit(-1);
1670 }
1671
1672 ret = fstat(input, &perf_stat);
1673 if (ret < 0) {
1674 perror("failed to stat file");
1675 exit(-1);
1676 }
1677
1678 if (!perf_stat.st_size) {
1679 fprintf(stderr, "zero-sized file, nothing to do!\n");
1680 exit(0);
1681 }
1682 header = perf_header__read(input);
1683 head = header->data_offset;
1684 sample_type = perf_header__sample_type(header);
1685
1686 if (!(sample_type & PERF_SAMPLE_RAW))
1687 die("No trace sample to read. Did you call perf record "
1688 "without -R?");
1689
1690 if (load_kernel() < 0) {
1691 perror("failed to load kernel symbols");
1692 return EXIT_FAILURE;
1693 }
1694
1695remap:
1696 buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
1697 MAP_SHARED, input, offset);
1698 if (buf == MAP_FAILED) {
1699 perror("failed to mmap file");
1700 exit(-1);
1701 }
1702
1703more:
1704 event = (event_t *)(buf + head);
1705
1706 size = event->header.size;
1707 if (!size)
1708 size = 8;
1709
1710 if (head + event->header.size >= page_size * mmap_window) {
1711 unsigned long shift = page_size * (head / page_size);
1712 int res;
1713
1714 res = munmap(buf, page_size * mmap_window);
1715 assert(res == 0);
1716
1717 offset += shift;
1718 head -= shift;
1719 goto remap;
1720 }
1721
1722 size = event->header.size;
1723 1665
1666 if (perf_session__has_traces(session, "record -R"))
1667 err = perf_session__process_events(session, &event_ops);
1724 1668
1725 if (!size || process_event(event, offset, head) < 0) { 1669 perf_session__delete(session);
1726 1670 return err;
1727 /*
1728 * assume we lost track of the stream, check alignment, and
1729 * increment a single u64 in the hope to catch on again 'soon'.
1730 */
1731
1732 if (unlikely(head & 7))
1733 head &= ~7ULL;
1734
1735 size = 8;
1736 }
1737
1738 head += size;
1739
1740 if (offset + head < (unsigned long)perf_stat.st_size)
1741 goto more;
1742
1743 rc = EXIT_SUCCESS;
1744 close(input);
1745
1746 return rc;
1747} 1671}
1748 1672
1749static void print_bad_events(void) 1673static void print_bad_events(void)
@@ -1784,9 +1708,9 @@ static void __cmd_lat(void)
1784 read_events(); 1708 read_events();
1785 sort_lat(); 1709 sort_lat();
1786 1710
1787 printf("\n -----------------------------------------------------------------------------------------\n"); 1711 printf("\n ---------------------------------------------------------------------------------------------------------------\n");
1788 printf(" Task | Runtime ms | Switches | Average delay ms | Maximum delay ms |\n"); 1712 printf(" Task | Runtime ms | Switches | Average delay ms | Maximum delay ms | Maximum delay at |\n");
1789 printf(" -----------------------------------------------------------------------------------------\n"); 1713 printf(" ---------------------------------------------------------------------------------------------------------------\n");
1790 1714
1791 next = rb_first(&sorted_atom_root); 1715 next = rb_first(&sorted_atom_root);
1792 1716
@@ -1883,6 +1807,8 @@ static const struct option latency_options[] = {
1883 "sort by key(s): runtime, switch, avg, max"), 1807 "sort by key(s): runtime, switch, avg, max"),
1884 OPT_BOOLEAN('v', "verbose", &verbose, 1808 OPT_BOOLEAN('v', "verbose", &verbose,
1885 "be more verbose (show symbol address, etc)"), 1809 "be more verbose (show symbol address, etc)"),
1810 OPT_INTEGER('C', "CPU", &profile_cpu,
1811 "CPU to profile on"),
1886 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 1812 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
1887 "dump raw trace in ASCII"), 1813 "dump raw trace in ASCII"),
1888 OPT_END() 1814 OPT_END()
@@ -1960,14 +1886,18 @@ static int __cmd_record(int argc, const char **argv)
1960 1886
1961int cmd_sched(int argc, const char **argv, const char *prefix __used) 1887int cmd_sched(int argc, const char **argv, const char *prefix __used)
1962{ 1888{
1963 symbol__init();
1964 page_size = getpagesize();
1965
1966 argc = parse_options(argc, argv, sched_options, sched_usage, 1889 argc = parse_options(argc, argv, sched_options, sched_usage,
1967 PARSE_OPT_STOP_AT_NON_OPTION); 1890 PARSE_OPT_STOP_AT_NON_OPTION);
1968 if (!argc) 1891 if (!argc)
1969 usage_with_options(sched_usage, sched_options); 1892 usage_with_options(sched_usage, sched_options);
1970 1893
1894 /*
1895 * Aliased to 'perf trace' for now:
1896 */
1897 if (!strcmp(argv[0], "trace"))
1898 return cmd_trace(argc, argv, prefix);
1899
1900 symbol__init();
1971 if (!strncmp(argv[0], "rec", 3)) { 1901 if (!strncmp(argv[0], "rec", 3)) {
1972 return __cmd_record(argc, argv); 1902 return __cmd_record(argc, argv);
1973 } else if (!strncmp(argv[0], "lat", 3)) { 1903 } else if (!strncmp(argv[0], "lat", 3)) {
@@ -1991,11 +1921,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __used)
1991 usage_with_options(replay_usage, replay_options); 1921 usage_with_options(replay_usage, replay_options);
1992 } 1922 }
1993 __cmd_replay(); 1923 __cmd_replay();
1994 } else if (!strcmp(argv[0], "trace")) {
1995 /*
1996 * Aliased to 'perf trace' for now:
1997 */
1998 return cmd_trace(argc, argv, prefix);
1999 } else { 1924 } else {
2000 usage_with_options(sched_usage, sched_options); 1925 usage_with_options(sched_usage, sched_options);
2001 } 1926 }