diff options
-rw-r--r-- | tools/perf/builtin-sched.c | 60 | ||||
-rw-r--r-- | tools/perf/util/event.h | 2 |
2 files changed, 42 insertions, 20 deletions
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index adcb563ec4d2..1f0f9be34faa 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c | |||
@@ -117,7 +117,11 @@ static u64 run_avg; | |||
117 | 117 | ||
118 | static unsigned long replay_repeat = 10; | 118 | static unsigned long replay_repeat = 10; |
119 | static unsigned long nr_timestamps; | 119 | static unsigned long nr_timestamps; |
120 | static unsigned long unordered_timestamps; | 120 | static unsigned long nr_unordered_timestamps; |
121 | static unsigned long nr_state_machine_bugs; | ||
122 | static unsigned long nr_events; | ||
123 | static unsigned long nr_lost_chunks; | ||
124 | static unsigned long nr_lost_events; | ||
121 | 125 | ||
122 | #define TASK_STATE_TO_CHAR_STR "RSDTtZX" | 126 | #define TASK_STATE_TO_CHAR_STR "RSDTtZX" |
123 | 127 | ||
@@ -668,14 +672,14 @@ process_comm_event(event_t *event, unsigned long offset, unsigned long head) | |||
668 | 672 | ||
669 | thread = threads__findnew(event->comm.pid, &threads, &last_match); | 673 | thread = threads__findnew(event->comm.pid, &threads, &last_match); |
670 | 674 | ||
671 | dump_printf("%p [%p]: PERF_EVENT_COMM: %s:%d\n", | 675 | dump_printf("%p [%p]: perf_event_comm: %s:%d\n", |
672 | (void *)(offset + head), | 676 | (void *)(offset + head), |
673 | (void *)(long)(event->header.size), | 677 | (void *)(long)(event->header.size), |
674 | event->comm.comm, event->comm.pid); | 678 | event->comm.comm, event->comm.pid); |
675 | 679 | ||
676 | if (thread == NULL || | 680 | if (thread == NULL || |
677 | thread__set_comm(thread, event->comm.comm)) { | 681 | thread__set_comm(thread, event->comm.comm)) { |
678 | dump_printf("problem processing PERF_EVENT_COMM, skipping event.\n"); | 682 | dump_printf("problem processing perf_event_comm, skipping event.\n"); |
679 | return -1; | 683 | return -1; |
680 | } | 684 | } |
681 | total_comm++; | 685 | total_comm++; |
@@ -1168,14 +1172,12 @@ latency_wakeup_event(struct trace_wakeup_event *wakeup_event, | |||
1168 | 1172 | ||
1169 | atom = list_entry(atoms->work_list.prev, struct work_atom, list); | 1173 | atom = list_entry(atoms->work_list.prev, struct work_atom, list); |
1170 | 1174 | ||
1171 | if (atom->state != THREAD_SLEEPING) { | 1175 | if (atom->state != THREAD_SLEEPING) |
1172 | printf("boo2\n"); | 1176 | nr_state_machine_bugs++; |
1173 | return; | ||
1174 | } | ||
1175 | 1177 | ||
1176 | nr_timestamps++; | 1178 | nr_timestamps++; |
1177 | if (atom->sched_out_time > timestamp) { | 1179 | if (atom->sched_out_time > timestamp) { |
1178 | unordered_timestamps++; | 1180 | nr_unordered_timestamps++; |
1179 | return; | 1181 | return; |
1180 | } | 1182 | } |
1181 | 1183 | ||
@@ -1214,7 +1216,7 @@ static void output_lat_thread(struct work_atoms *work_list) | |||
1214 | 1216 | ||
1215 | avg = work_list->total_lat / work_list->nb_atoms; | 1217 | avg = work_list->total_lat / work_list->nb_atoms; |
1216 | 1218 | ||
1217 | printf("|%9.3f ms |%9llu | avg:%9.3f ms | max:%9.3f ms |\n", | 1219 | printf("|%11.3f ms |%9llu | avg:%9.3f ms | max:%9.3f ms |\n", |
1218 | (double)work_list->total_runtime / 1e6, | 1220 | (double)work_list->total_runtime / 1e6, |
1219 | work_list->nb_atoms, (double)avg / 1e6, | 1221 | work_list->nb_atoms, (double)avg / 1e6, |
1220 | (double)work_list->max_lat / 1e6); | 1222 | (double)work_list->max_lat / 1e6); |
@@ -1359,9 +1361,9 @@ static void __cmd_lat(void) | |||
1359 | read_events(); | 1361 | read_events(); |
1360 | sort_lat(); | 1362 | sort_lat(); |
1361 | 1363 | ||
1362 | printf("\n ---------------------------------------------------------------------------------------\n"); | 1364 | printf("\n -----------------------------------------------------------------------------------------\n"); |
1363 | printf(" Task | Runtime ms | Switches | Average delay ms | Maximum delay ms |\n"); | 1365 | printf(" Task | Runtime ms | Switches | Average delay ms | Maximum delay ms |\n"); |
1364 | printf(" ---------------------------------------------------------------------------------------\n"); | 1366 | printf(" -----------------------------------------------------------------------------------------\n"); |
1365 | 1367 | ||
1366 | next = rb_first(&sorted_atom_root); | 1368 | next = rb_first(&sorted_atom_root); |
1367 | 1369 | ||
@@ -1373,18 +1375,32 @@ static void __cmd_lat(void) | |||
1373 | next = rb_next(next); | 1375 | next = rb_next(next); |
1374 | } | 1376 | } |
1375 | 1377 | ||
1376 | printf(" ---------------------------------------------------------------------------------------\n"); | 1378 | printf(" -----------------------------------------------------------------------------------------\n"); |
1377 | printf(" TOTAL: |%9.3f ms |%9Ld |", | 1379 | printf(" TOTAL: |%11.3f ms |%9Ld |\n", |
1378 | (double)all_runtime/1e6, all_count); | 1380 | (double)all_runtime/1e6, all_count); |
1379 | 1381 | ||
1380 | if (unordered_timestamps && nr_timestamps) { | 1382 | printf(" ---------------------------------------------------\n"); |
1381 | printf(" INFO: %.2f%% unordered events.\n", | 1383 | if (nr_unordered_timestamps && nr_timestamps) { |
1382 | (double)unordered_timestamps/(double)nr_timestamps*100.0); | 1384 | printf(" INFO: %.3f%% unordered timestamps (%ld out of %ld)\n", |
1385 | (double)nr_unordered_timestamps/(double)nr_timestamps*100.0, | ||
1386 | nr_unordered_timestamps, nr_timestamps); | ||
1383 | } else { | 1387 | } else { |
1388 | } | ||
1389 | if (nr_lost_events && nr_events) { | ||
1390 | printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", | ||
1391 | (double)nr_lost_events/(double)nr_events*100.0, | ||
1392 | nr_lost_events, nr_events, nr_lost_chunks); | ||
1393 | } | ||
1394 | if (nr_state_machine_bugs && nr_timestamps) { | ||
1395 | printf(" INFO: %.3f%% state machine bugs (%ld out of %ld)", | ||
1396 | (double)nr_state_machine_bugs/(double)nr_timestamps*100.0, | ||
1397 | nr_state_machine_bugs, nr_timestamps); | ||
1398 | if (nr_lost_events) | ||
1399 | printf(" (due to lost events?)"); | ||
1384 | printf("\n"); | 1400 | printf("\n"); |
1385 | } | 1401 | } |
1402 | printf("\n"); | ||
1386 | 1403 | ||
1387 | printf(" -------------------------------------------------\n\n"); | ||
1388 | } | 1404 | } |
1389 | 1405 | ||
1390 | static struct trace_sched_handler *trace_handler; | 1406 | static struct trace_sched_handler *trace_handler; |
@@ -1585,8 +1601,13 @@ process_event(event_t *event, unsigned long offset, unsigned long head) | |||
1585 | { | 1601 | { |
1586 | trace_event(event); | 1602 | trace_event(event); |
1587 | 1603 | ||
1604 | nr_events++; | ||
1588 | switch (event->header.type) { | 1605 | switch (event->header.type) { |
1589 | case PERF_EVENT_MMAP ... PERF_EVENT_LOST: | 1606 | case PERF_EVENT_MMAP: |
1607 | return 0; | ||
1608 | case PERF_EVENT_LOST: | ||
1609 | nr_lost_chunks++; | ||
1610 | nr_lost_events += event->lost.lost; | ||
1590 | return 0; | 1611 | return 0; |
1591 | 1612 | ||
1592 | case PERF_EVENT_COMM: | 1613 | case PERF_EVENT_COMM: |
@@ -1768,6 +1789,7 @@ static const char *record_args[] = { | |||
1768 | "-R", | 1789 | "-R", |
1769 | "-M", | 1790 | "-M", |
1770 | "-f", | 1791 | "-f", |
1792 | "-m", "1024", | ||
1771 | "-c", "1", | 1793 | "-c", "1", |
1772 | "-e", "sched:sched_switch:r", | 1794 | "-e", "sched:sched_switch:r", |
1773 | "-e", "sched:sched_stat_wait:r", | 1795 | "-e", "sched:sched_stat_wait:r", |
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h index fa2d4e91d329..2495529cae7d 100644 --- a/tools/perf/util/event.h +++ b/tools/perf/util/event.h | |||
@@ -52,7 +52,7 @@ struct lost_event { | |||
52 | */ | 52 | */ |
53 | struct read_event { | 53 | struct read_event { |
54 | struct perf_event_header header; | 54 | struct perf_event_header header; |
55 | u32 pid,tid; | 55 | u32 pid, tid; |
56 | u64 value; | 56 | u64 value; |
57 | u64 time_enabled; | 57 | u64 time_enabled; |
58 | u64 time_running; | 58 | u64 time_running; |