aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--tools/perf/builtin-sched.c60
-rw-r--r--tools/perf/util/event.h2
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
118static unsigned long replay_repeat = 10; 118static unsigned long replay_repeat = 10;
119static unsigned long nr_timestamps; 119static unsigned long nr_timestamps;
120static unsigned long unordered_timestamps; 120static unsigned long nr_unordered_timestamps;
121static unsigned long nr_state_machine_bugs;
122static unsigned long nr_events;
123static unsigned long nr_lost_chunks;
124static 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
1390static struct trace_sched_handler *trace_handler; 1406static 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 */
53struct read_event { 53struct 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;