aboutsummaryrefslogtreecommitdiffstats
path: root/tools/perf/builtin-sched.c
diff options
context:
space:
mode:
authorIngo Molnar <mingo@elte.hu>2009-09-11 06:12:54 -0400
committerIngo Molnar <mingo@elte.hu>2009-09-13 04:22:37 -0400
commitec156764d424dd67283c2cd5e9f6f1b8388364ac (patch)
treec7c4e20d64f70cfd2167c73963e2437dee4c3d53 /tools/perf/builtin-sched.c
parent0a02ad9331dd4db56c29c60db2e99c4daaad8a48 (diff)
perf sched: Import schedbench.c
Import the schedbench.c tool that i wrote some time ago to simulate scheduler behavior but never finished. It's a good basis for perf sched nevertheless. Most of its guts are not hooked up to the perf event loop yet - that will be done in the patches to come. Cc: Peter Zijlstra <a.p.zijlstra@chello.nl> Cc: Mike Galbraith <efault@gmx.de> Cc: Paul Mackerras <paulus@samba.org> Cc: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> LKML-Reference: <new-submission> Signed-off-by: Ingo Molnar <mingo@elte.hu>
Diffstat (limited to 'tools/perf/builtin-sched.c')
-rw-r--r--tools/perf/builtin-sched.c842
1 files changed, 817 insertions, 25 deletions
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 60228d9179ac..c66e6a321371 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -12,22 +12,770 @@
12#include "util/debug.h" 12#include "util/debug.h"
13 13
14#include "util/trace-event.h" 14#include "util/trace-event.h"
15#include <sys/types.h>
15 16
16static char const *input_name = "perf.data"; 17static char const *input_name = "perf.data";
17static int input; 18static int input;
18static unsigned long page_size; 19static unsigned long page_size;
19static unsigned long mmap_window = 32; 20static unsigned long mmap_window = 32;
20 21
21static unsigned long total = 0; 22static unsigned long total_comm = 0;
22static unsigned long total_comm = 0;
23 23
24static struct rb_root threads; 24static struct rb_root threads;
25static struct thread *last_match; 25static struct thread *last_match;
26 26
27static struct perf_header *header; 27static struct perf_header *header;
28static u64 sample_type; 28static u64 sample_type;
29 29
30 30
31/*
32 * Scheduler benchmarks
33 */
34#include <sys/resource.h>
35#include <sys/types.h>
36#include <sys/stat.h>
37#include <sys/time.h>
38#include <sys/prctl.h>
39
40#include <linux/unistd.h>
41
42#include <semaphore.h>
43#include <pthread.h>
44#include <signal.h>
45#include <values.h>
46#include <string.h>
47#include <unistd.h>
48#include <stdlib.h>
49#include <assert.h>
50#include <fcntl.h>
51#include <time.h>
52#include <math.h>
53
54#include <stdio.h>
55
56#define PR_SET_NAME 15 /* Set process name */
57
58#define BUG_ON(x) assert(!(x))
59
60#define DEBUG 1
61
62typedef unsigned long long nsec_t;
63
64#define printk(x...) do { printf(x); fflush(stdout); } while (0)
65
66nsec_t prev_printk;
67
68#define __dprintk(x,y...) do { \
69 nsec_t __now = get_nsecs(), __delta = __now - prev_printk; \
70 \
71 prev_printk = __now; \
72 \
73 printf("%.3f [%Ld] [%.3f]: " x, (double)__now/1e6, __now, (double)__delta/1e6, y);\
74} while (0)
75
76#if !DEBUG
77# define dprintk(x...) do { } while (0)
78#else
79# define dprintk(x...) __dprintk(x)
80#endif
81
82#define __DP() __dprintk("parent: line %d\n", __LINE__)
83#define DP() dprintk("parent: line %d\n", __LINE__)
84#define D() dprintk("task %ld: line %d\n", this_task->nr, __LINE__)
85
86
87static nsec_t run_measurement_overhead;
88static nsec_t sleep_measurement_overhead;
89
90static nsec_t get_nsecs(void)
91{
92 struct timespec ts;
93
94 clock_gettime(CLOCK_MONOTONIC, &ts);
95
96 return ts.tv_sec * 1000000000ULL + ts.tv_nsec;
97}
98
99static void burn_nsecs(nsec_t nsecs)
100{
101 nsec_t T0 = get_nsecs(), T1;
102
103 do {
104 T1 = get_nsecs();
105 } while (T1 + run_measurement_overhead < T0 + nsecs);
106}
107
108static void sleep_nsecs(nsec_t nsecs)
109{
110 struct timespec ts;
111
112 ts.tv_nsec = nsecs % 999999999;
113 ts.tv_sec = nsecs / 999999999;
114
115 nanosleep(&ts, NULL);
116}
117
118static void calibrate_run_measurement_overhead(void)
119{
120 nsec_t T0, T1, delta, min_delta = 1000000000ULL;
121 int i;
122
123 for (i = 0; i < 10; i++) {
124 T0 = get_nsecs();
125 burn_nsecs(0);
126 T1 = get_nsecs();
127 delta = T1-T0;
128 min_delta = min(min_delta, delta);
129 }
130 run_measurement_overhead = min_delta;
131
132 printk("run measurement overhead: %Ld nsecs\n", min_delta);
133}
134
135static void calibrate_sleep_measurement_overhead(void)
136{
137 nsec_t T0, T1, delta, min_delta = 1000000000ULL;
138 int i;
139
140 for (i = 0; i < 10; i++) {
141 T0 = get_nsecs();
142 sleep_nsecs(10000);
143 T1 = get_nsecs();
144 delta = T1-T0;
145 min_delta = min(min_delta, delta);
146 }
147 min_delta -= 10000;
148 sleep_measurement_overhead = min_delta;
149
150 printk("sleep measurement overhead: %Ld nsecs\n", min_delta);
151}
152
153#define COMM_LEN 20
154#define SYM_LEN 129
155
156#define MAX_PID 65536
157
158static unsigned long nr_tasks;
159
160struct sched_event;
161
162struct task_desc {
163 unsigned long nr;
164 unsigned long pid;
165 char comm[COMM_LEN];
166
167 unsigned long nr_events;
168 unsigned long curr_event;
169 struct sched_event **events;
170
171 pthread_t thread;
172 sem_t sleep_sem;
173
174 sem_t ready_for_work;
175 sem_t work_done_sem;
176
177 nsec_t cpu_usage;
178};
179
180enum sched_event_type {
181 SCHED_EVENT_RUN,
182 SCHED_EVENT_SLEEP,
183 SCHED_EVENT_WAKEUP,
184};
185
186struct sched_event {
187 enum sched_event_type type;
188 nsec_t timestamp;
189 nsec_t duration;
190 unsigned long nr;
191 int specific_wait;
192 sem_t *wait_sem;
193 struct task_desc *wakee;
194};
195
196static struct task_desc *pid_to_task[MAX_PID];
197
198static struct task_desc **tasks;
199
200static pthread_mutex_t start_work_mutex = PTHREAD_MUTEX_INITIALIZER;
201static nsec_t start_time;
202
203static pthread_mutex_t work_done_wait_mutex = PTHREAD_MUTEX_INITIALIZER;
204
205static unsigned long nr_run_events;
206static unsigned long nr_sleep_events;
207static unsigned long nr_wakeup_events;
208
209static unsigned long nr_sleep_corrections;
210static unsigned long nr_run_events_optimized;
211
212static struct sched_event *
213get_new_event(struct task_desc *task, nsec_t timestamp)
214{
215 struct sched_event *event = calloc(1, sizeof(*event));
216 unsigned long idx = task->nr_events;
217 size_t size;
218
219 event->timestamp = timestamp;
220 event->nr = idx;
221
222 task->nr_events++;
223 size = sizeof(struct sched_event *) * task->nr_events;
224 task->events = realloc(task->events, size);
225 BUG_ON(!task->events);
226
227 task->events[idx] = event;
228
229 return event;
230}
231
232static struct sched_event *last_event(struct task_desc *task)
233{
234 if (!task->nr_events)
235 return NULL;
236
237 return task->events[task->nr_events - 1];
238}
239
240static void
241add_sched_event_run(struct task_desc *task, nsec_t timestamp,
242 unsigned long duration)
243{
244 struct sched_event *event, *curr_event = last_event(task);
245
246 /*
247 * optimize an existing RUN event by merging this one
248 * to it:
249 */
250 if (curr_event && curr_event->type == SCHED_EVENT_RUN) {
251 nr_run_events_optimized++;
252 curr_event->duration += duration;
253 return;
254 }
255
256 event = get_new_event(task, timestamp);
257
258 event->type = SCHED_EVENT_RUN;
259 event->duration = duration;
260
261 nr_run_events++;
262}
263
264static unsigned long targetless_wakeups;
265static unsigned long multitarget_wakeups;
266
267static void
268add_sched_event_wakeup(struct task_desc *task, nsec_t timestamp,
269 struct task_desc *wakee)
270{
271 struct sched_event *event, *wakee_event;
272
273 event = get_new_event(task, timestamp);
274 event->type = SCHED_EVENT_WAKEUP;
275 event->wakee = wakee;
276
277 wakee_event = last_event(wakee);
278 if (!wakee_event || wakee_event->type != SCHED_EVENT_SLEEP) {
279 targetless_wakeups++;
280 return;
281 }
282 if (wakee_event->wait_sem) {
283 multitarget_wakeups++;
284 return;
285 }
286
287 wakee_event->wait_sem = calloc(1, sizeof(*wakee_event->wait_sem));
288 sem_init(wakee_event->wait_sem, 0, 0);
289 wakee_event->specific_wait = 1;
290 event->wait_sem = wakee_event->wait_sem;
291
292 nr_wakeup_events++;
293}
294
295static void
296add_sched_event_sleep(struct task_desc *task, nsec_t timestamp,
297 unsigned long uninterruptible __used)
298{
299 struct sched_event *event = get_new_event(task, timestamp);
300
301 event->type = SCHED_EVENT_SLEEP;
302
303 nr_sleep_events++;
304}
305
306static struct task_desc *register_pid(unsigned long pid, const char *comm)
307{
308 struct task_desc *task;
309
310 BUG_ON(pid >= MAX_PID);
311
312 task = pid_to_task[pid];
313
314 if (task)
315 return task;
316
317 task = calloc(1, sizeof(*task));
318 task->pid = pid;
319 task->nr = nr_tasks;
320 strcpy(task->comm, comm);
321 /*
322 * every task starts in sleeping state - this gets ignored
323 * if there's no wakeup pointing to this sleep state:
324 */
325 add_sched_event_sleep(task, 0, 0);
326
327 pid_to_task[pid] = task;
328 nr_tasks++;
329 tasks = realloc(tasks, nr_tasks*sizeof(struct task_task *));
330 BUG_ON(!tasks);
331 tasks[task->nr] = task;
332
333 printk("registered task #%ld, PID %ld (%s)\n", nr_tasks, pid, comm);
334
335 return task;
336}
337
338
339static int first_trace_line = 1;
340
341static nsec_t first_timestamp;
342static nsec_t prev_timestamp;
343
344void parse_line(char *line);
345
346void parse_line(char *line)
347{
348 unsigned long param1 = 0, param2 = 0;
349 char comm[COMM_LEN], comm2[COMM_LEN];
350 unsigned long pid, pid2, timestamp0;
351 struct task_desc *task, *task2;
352 char func_str[SYM_LEN];
353 nsec_t timestamp;
354 int ret;
355
356 //" <idle> 0 0D.s3 0us+: try_to_wake_up <events/0 9> (1 0)"
357 ret = sscanf(line, "%20s %5ld %*s %ldus%*c:"
358 " %128s <%20s %ld> (%ld %ld)\n",
359 comm, &pid, &timestamp0,
360 func_str, comm2, &pid2, &param1, &param2);
361 dprintk("ret: %d\n", ret);
362 if (ret != 8)
363 return;
364
365 timestamp = timestamp0 * 1000LL;
366
367 if (first_trace_line) {
368 first_trace_line = 0;
369 first_timestamp = timestamp;
370 }
371
372 timestamp -= first_timestamp;
373 BUG_ON(timestamp < prev_timestamp);
374 prev_timestamp = timestamp;
375
376 dprintk("parsed: %s - %ld %Ld: %s - <%s %ld> (%ld %ld)\n",
377 comm,
378 pid,
379 timestamp,
380 func_str,
381 comm2,
382 pid2,
383 param1,
384 param2);
385
386 task = register_pid(pid, comm);
387 task2 = register_pid(pid2, comm2);
388
389 if (!strcmp(func_str, "update_curr")) {
390 dprintk("%Ld: task %ld runs for %ld nsecs\n",
391 timestamp, task->nr, param1);
392 add_sched_event_run(task, timestamp, param1);
393 } else if (!strcmp(func_str, "try_to_wake_up")) {
394 dprintk("%Ld: task %ld wakes up task %ld\n",
395 timestamp, task->nr, task2->nr);
396 add_sched_event_wakeup(task, timestamp, task2);
397 } else if (!strcmp(func_str, "deactivate_task")) {
398 dprintk("%Ld: task %ld goes to sleep (uninterruptible: %ld)\n",
399 timestamp, task->nr, param1);
400 add_sched_event_sleep(task, timestamp, param1);
401 }
402}
403
404static void print_task_traces(void)
405{
406 struct task_desc *task;
407 unsigned long i;
408
409 for (i = 0; i < nr_tasks; i++) {
410 task = tasks[i];
411 printk("task %6ld (%20s:%10ld), nr_events: %ld\n",
412 task->nr, task->comm, task->pid, task->nr_events);
413 }
414}
415
416static void add_cross_task_wakeups(void)
417{
418 struct task_desc *task1, *task2;
419 unsigned long i, j;
420
421 for (i = 0; i < nr_tasks; i++) {
422 task1 = tasks[i];
423 j = i + 1;
424 if (j == nr_tasks)
425 j = 0;
426 task2 = tasks[j];
427 add_sched_event_wakeup(task1, 0, task2);
428 }
429}
430
431static void
432process_sched_event(struct task_desc *this_task, struct sched_event *event)
433{
434 int ret = 0;
435 nsec_t now;
436 long long delta;
437
438 now = get_nsecs();
439 delta = start_time + event->timestamp - now;
440
441 dprintk("task %ld, event #%ld, %Ld, delta: %.3f (%Ld)\n",
442 this_task->nr, event->nr, event->timestamp,
443 (double)delta/1e6, delta);
444
445 if (0 && delta > 0) {
446 dprintk("%.3f: task %ld FIX %.3f\n",
447 (double)event->timestamp/1e6,
448 this_task->nr,
449 (double)delta/1e6);
450 sleep_nsecs(start_time + event->timestamp - now);
451 nr_sleep_corrections++;
452 }
453
454 switch (event->type) {
455 case SCHED_EVENT_RUN:
456 dprintk("%.3f: task %ld RUN for %.3f\n",
457 (double)event->timestamp/1e6,
458 this_task->nr,
459 (double)event->duration/1e6);
460 burn_nsecs(event->duration);
461 break;
462 case SCHED_EVENT_SLEEP:
463 dprintk("%.3f: task %ld %s SLEEP\n",
464 (double)event->timestamp/1e6,
465 this_task->nr, event->wait_sem ? "" : "SKIP");
466 if (event->wait_sem)
467 ret = sem_wait(event->wait_sem);
468 BUG_ON(ret);
469 break;
470 case SCHED_EVENT_WAKEUP:
471 dprintk("%.3f: task %ld WAKEUP => task %ld\n",
472 (double)event->timestamp/1e6,
473 this_task->nr,
474 event->wakee->nr);
475 if (event->wait_sem)
476 ret = sem_post(event->wait_sem);
477 BUG_ON(ret);
478 break;
479 default:
480 BUG_ON(1);
481 }
482}
483
484static nsec_t get_cpu_usage_nsec_parent(void)
485{
486 struct rusage ru;
487 nsec_t sum;
488 int err;
489
490 err = getrusage(RUSAGE_SELF, &ru);
491 BUG_ON(err);
492
493 sum = ru.ru_utime.tv_sec*1e9 + ru.ru_utime.tv_usec*1e3;
494 sum += ru.ru_stime.tv_sec*1e9 + ru.ru_stime.tv_usec*1e3;
495
496 return sum;
497}
498
499static nsec_t get_cpu_usage_nsec_self(void)
500{
501 char filename [] = "/proc/1234567890/sched";
502 unsigned long msecs, nsecs;
503 char *line = NULL;
504 nsec_t total = 0;
505 size_t len = 0;
506 ssize_t chars;
507 FILE *file;
508 int ret;
509
510 sprintf(filename, "/proc/%d/sched", getpid());
511 file = fopen(filename, "r");
512 BUG_ON(!file);
513
514 while ((chars = getline(&line, &len, file)) != -1) {
515 dprintk("got line with length %zu :\n", chars);
516 dprintk("%s", line);
517 ret = sscanf(line, "se.sum_exec_runtime : %ld.%06ld\n",
518 &msecs, &nsecs);
519 if (ret == 2) {
520 total = msecs*1e6 + nsecs;
521 dprintk("total: (%ld.%06ld) %Ld\n",
522 msecs, nsecs, total);
523 break;
524 }
525 }
526 if (line)
527 free(line);
528 fclose(file);
529
530 return total;
531}
532
533static void *thread_func(void *ctx)
534{
535 struct task_desc *this_task = ctx;
536 nsec_t cpu_usage_0, cpu_usage_1;
537 unsigned long i, ret;
538 char comm2[22];
539
540 dprintk("task %ld started up.\n", this_task->nr);
541 sprintf(comm2, ":%s", this_task->comm);
542 prctl(PR_SET_NAME, comm2);
543
544again:
545 ret = sem_post(&this_task->ready_for_work);
546 BUG_ON(ret);
547 D();
548 ret = pthread_mutex_lock(&start_work_mutex);
549 BUG_ON(ret);
550 ret = pthread_mutex_unlock(&start_work_mutex);
551 BUG_ON(ret);
552 D();
553
554 cpu_usage_0 = get_cpu_usage_nsec_self();
555
556 for (i = 0; i < this_task->nr_events; i++) {
557 this_task->curr_event = i;
558 process_sched_event(this_task, this_task->events[i]);
559 }
560
561 cpu_usage_1 = get_cpu_usage_nsec_self();
562 this_task->cpu_usage = cpu_usage_1 - cpu_usage_0;
563
564 dprintk("task %ld cpu usage: %0.3f msecs\n",
565 this_task->nr, (double)this_task->cpu_usage / 1e6);
566
567 D();
568 ret = sem_post(&this_task->work_done_sem);
569 BUG_ON(ret);
570 D();
571
572 ret = pthread_mutex_lock(&work_done_wait_mutex);
573 BUG_ON(ret);
574 ret = pthread_mutex_unlock(&work_done_wait_mutex);
575 BUG_ON(ret);
576 D();
577
578 goto again;
579}
580
581static void create_tasks(void)
582{
583 struct task_desc *task;
584 pthread_attr_t attr;
585 unsigned long i;
586 int err;
587
588 err = pthread_attr_init(&attr);
589 BUG_ON(err);
590 err = pthread_attr_setstacksize(&attr, (size_t)(16*1024));
591 BUG_ON(err);
592 err = pthread_mutex_lock(&start_work_mutex);
593 BUG_ON(err);
594 err = pthread_mutex_lock(&work_done_wait_mutex);
595 BUG_ON(err);
596 for (i = 0; i < nr_tasks; i++) {
597 task = tasks[i];
598 sem_init(&task->sleep_sem, 0, 0);
599 sem_init(&task->ready_for_work, 0, 0);
600 sem_init(&task->work_done_sem, 0, 0);
601 task->curr_event = 0;
602 err = pthread_create(&task->thread, &attr, thread_func, task);
603 BUG_ON(err);
604 }
605}
606
607static nsec_t cpu_usage;
608static nsec_t runavg_cpu_usage;
609static nsec_t parent_cpu_usage;
610static nsec_t runavg_parent_cpu_usage;
611
612static void wait_for_tasks(void)
613{
614 nsec_t cpu_usage_0, cpu_usage_1;
615 struct task_desc *task;
616 unsigned long i, ret;
617
618 DP();
619 start_time = get_nsecs();
620 DP();
621 cpu_usage = 0;
622 pthread_mutex_unlock(&work_done_wait_mutex);
623
624 for (i = 0; i < nr_tasks; i++) {
625 task = tasks[i];
626 ret = sem_wait(&task->ready_for_work);
627 BUG_ON(ret);
628 sem_init(&task->ready_for_work, 0, 0);
629 }
630 ret = pthread_mutex_lock(&work_done_wait_mutex);
631 BUG_ON(ret);
632
633 cpu_usage_0 = get_cpu_usage_nsec_parent();
634
635 pthread_mutex_unlock(&start_work_mutex);
636
637#if 0
638 for (i = 0; i < nr_tasks; i++) {
639 unsigned long missed;
640
641 task = tasks[i];
642 while (task->curr_event + 1 < task->nr_events) {
643 dprintk("parent waiting for %ld (%ld != %ld)\n",
644 i, task->curr_event, task->nr_events);
645 sleep_nsecs(100000000);
646 }
647 missed = task->nr_events - 1 - task->curr_event;
648 if (missed)
649 printk("task %ld missed events: %ld\n", i, missed);
650 ret = sem_post(&task->sleep_sem);
651 BUG_ON(ret);
652 }
653#endif
654 DP();
655 for (i = 0; i < nr_tasks; i++) {
656 task = tasks[i];
657 ret = sem_wait(&task->work_done_sem);
658 BUG_ON(ret);
659 sem_init(&task->work_done_sem, 0, 0);
660 cpu_usage += task->cpu_usage;
661 task->cpu_usage = 0;
662 }
663
664 cpu_usage_1 = get_cpu_usage_nsec_parent();
665 if (!runavg_cpu_usage)
666 runavg_cpu_usage = cpu_usage;
667 runavg_cpu_usage = (runavg_cpu_usage*9 + cpu_usage)/10;
668
669 parent_cpu_usage = cpu_usage_1 - cpu_usage_0;
670 if (!runavg_parent_cpu_usage)
671 runavg_parent_cpu_usage = parent_cpu_usage;
672 runavg_parent_cpu_usage = (runavg_parent_cpu_usage*9 +
673 parent_cpu_usage)/10;
674
675 ret = pthread_mutex_lock(&start_work_mutex);
676 BUG_ON(ret);
677
678 for (i = 0; i < nr_tasks; i++) {
679 task = tasks[i];
680 sem_init(&task->sleep_sem, 0, 0);
681 task->curr_event = 0;
682 }
683}
684
685static int __cmd_sched(void);
686
687static void parse_trace(void)
688{
689 __cmd_sched();
690
691 printk("nr_run_events: %ld\n", nr_run_events);
692 printk("nr_sleep_events: %ld\n", nr_sleep_events);
693 printk("nr_wakeup_events: %ld\n", nr_wakeup_events);
694
695 if (targetless_wakeups)
696 printk("target-less wakeups: %ld\n", targetless_wakeups);
697 if (multitarget_wakeups)
698 printk("multi-target wakeups: %ld\n", multitarget_wakeups);
699 if (nr_run_events_optimized)
700 printk("run events optimized: %ld\n",
701 nr_run_events_optimized);
702}
703
704static unsigned long nr_runs;
705static nsec_t sum_runtime;
706static nsec_t sum_fluct;
707static nsec_t run_avg;
708
709static void run_one_test(void)
710{
711 nsec_t T0, T1, delta, avg_delta, fluct, std_dev;
712
713 T0 = get_nsecs();
714 wait_for_tasks();
715 T1 = get_nsecs();
716
717 delta = T1 - T0;
718 sum_runtime += delta;
719 nr_runs++;
720
721 avg_delta = sum_runtime / nr_runs;
722 if (delta < avg_delta)
723 fluct = avg_delta - delta;
724 else
725 fluct = delta - avg_delta;
726 sum_fluct += fluct;
727 std_dev = sum_fluct / nr_runs / sqrt(nr_runs);
728 if (!run_avg)
729 run_avg = delta;
730 run_avg = (run_avg*9 + delta)/10;
731
732 printk("#%-3ld: %0.3f, ",
733 nr_runs, (double)delta/1000000.0);
734
735#if 0
736 printk("%0.2f +- %0.2f, ",
737 (double)avg_delta/1e6, (double)std_dev/1e6);
738#endif
739 printk("ravg: %0.2f, ",
740 (double)run_avg/1e6);
741
742 printk("cpu: %0.2f / %0.2f",
743 (double)cpu_usage/1e6, (double)runavg_cpu_usage/1e6);
744
745#if 0
746 /*
747 * rusage statistics done by the parent, these are less
748 * accurate than the sum_exec_runtime based statistics:
749 */
750 printk(" [%0.2f / %0.2f]",
751 (double)parent_cpu_usage/1e6,
752 (double)runavg_parent_cpu_usage/1e6);
753#endif
754
755 printk("\n");
756
757 if (nr_sleep_corrections)
758 printk(" (%ld sleep corrections)\n", nr_sleep_corrections);
759 nr_sleep_corrections = 0;
760}
761
762static void test_calibrations(void)
763{
764 nsec_t T0, T1;
765
766 T0 = get_nsecs();
767 burn_nsecs(1e6);
768 T1 = get_nsecs();
769
770 printk("the run test took %Ld nsecs\n", T1-T0);
771
772 T0 = get_nsecs();
773 sleep_nsecs(1e6);
774 T1 = get_nsecs();
775
776 printk("the sleep test took %Ld nsecs\n", T1-T0);
777}
778
31static int 779static int
32process_comm_event(event_t *event, unsigned long offset, unsigned long head) 780process_comm_event(event_t *event, unsigned long offset, unsigned long head)
33{ 781{
@@ -50,6 +798,46 @@ process_comm_event(event_t *event, unsigned long offset, unsigned long head)
50 return 0; 798 return 0;
51} 799}
52 800
801static void process_sched_wakeup_event(struct event *event,
802 int cpu __used, u64 timestamp __used, struct thread *thread __used)
803{
804 printf("sched_wakeup event %p\n", event);
805}
806
807static void process_sched_switch_event(struct event *event,
808 int cpu __used, u64 timestamp __used, struct thread *thread __used)
809{
810 printf("sched_switch event %p\n", event);
811}
812
813static void
814process_raw_event(event_t *raw_event, void *more_data,
815 int cpu, u64 timestamp, struct thread *thread)
816{
817 struct {
818 u32 size;
819 char data[0];
820 } *raw = more_data;
821 struct event *event;
822 int type;
823
824 type = trace_parse_common_type(raw->data);
825 event = trace_find_event(type);
826
827 /*
828 * FIXME: better resolve from pid from the struct trace_entry
829 * field, although it should be the same than this perf
830 * event pid
831 */
832 printf("id %d, type: %d, event: %s\n",
833 raw_event->header.type, type, event->name);
834
835 if (!strcmp(event->name, "sched_switch"))
836 process_sched_switch_event(event, cpu, timestamp, thread);
837 if (!strcmp(event->name, "sched_wakeup"))
838 process_sched_wakeup_event(event, cpu, timestamp, thread);
839}
840
53static int 841static int
54process_sample_event(event_t *event, unsigned long offset, unsigned long head) 842process_sample_event(event_t *event, unsigned long offset, unsigned long head)
55{ 843{
@@ -122,20 +910,8 @@ process_sample_event(event_t *event, unsigned long offset, unsigned long head)
122 dump_printf(" ...... dso: [hypervisor]\n"); 910 dump_printf(" ...... dso: [hypervisor]\n");
123 } 911 }
124 912
125 if (sample_type & PERF_SAMPLE_RAW) { 913 if (sample_type & PERF_SAMPLE_RAW)
126 struct { 914 process_raw_event(event, more_data, cpu, timestamp, thread);
127 u32 size;
128 char data[0];
129 } *raw = more_data;
130
131 /*
132 * FIXME: better resolve from pid from the struct trace_entry
133 * field, although it should be the same than this perf
134 * event pid
135 */
136 print_event(cpu, raw->data, raw->size, timestamp, thread->comm);
137 }
138 total += period;
139 915
140 return 0; 916 return 0;
141} 917}
@@ -277,6 +1053,8 @@ static const struct option options[] = {
277 1053
278int cmd_sched(int argc, const char **argv, const char *prefix __used) 1054int cmd_sched(int argc, const char **argv, const char *prefix __used)
279{ 1055{
1056 long nr_iterations = LONG_MAX, i;
1057
280 symbol__init(); 1058 symbol__init();
281 page_size = getpagesize(); 1059 page_size = getpagesize();
282 1060
@@ -293,5 +1071,19 @@ int cmd_sched(int argc, const char **argv, const char *prefix __used)
293 1071
294 setup_pager(); 1072 setup_pager();
295 1073
296 return __cmd_sched(); 1074 calibrate_run_measurement_overhead();
1075 calibrate_sleep_measurement_overhead();
1076
1077 test_calibrations();
1078
1079 parse_trace();
1080 print_task_traces();
1081 add_cross_task_wakeups();
1082
1083 create_tasks();
1084 printk("------------------------------------------------------------\n");
1085 for (i = 0; i < nr_iterations; i++)
1086 run_one_test();
1087
1088 return 0;
297} 1089}