builtin-sched.c 69.2 KB
Newer Older
I
Ingo Molnar 已提交
1
#include "builtin.h"
2
#include "perf.h"
I
Ingo Molnar 已提交
3 4

#include "util/util.h"
5
#include "util/evlist.h"
I
Ingo Molnar 已提交
6
#include "util/cache.h"
7
#include "util/evsel.h"
I
Ingo Molnar 已提交
8 9 10
#include "util/symbol.h"
#include "util/thread.h"
#include "util/header.h"
11
#include "util/session.h"
12
#include "util/tool.h"
13
#include "util/cloexec.h"
J
Jiri Olsa 已提交
14
#include "util/thread_map.h"
15
#include "util/color.h"
16
#include "util/stat.h"
I
Ingo Molnar 已提交
17

18
#include <subcmd/parse-options.h>
19
#include "util/trace-event.h"
I
Ingo Molnar 已提交
20 21 22

#include "util/debug.h"

23
#include <linux/log2.h>
24
#include <sys/prctl.h>
25
#include <sys/resource.h>
I
Ingo Molnar 已提交
26

27 28 29
#include <semaphore.h>
#include <pthread.h>
#include <math.h>
30
#include <api/fs/fs.h>
31
#include <linux/time64.h>
32

33 34 35 36
#define PR_SET_NAME		15               /* Set process name */
#define MAX_CPUS		4096
#define COMM_LEN		20
#define SYM_LEN			129
37
#define MAX_PID			1024000
I
Ingo Molnar 已提交
38

39
struct sched_atom;
I
Ingo Molnar 已提交
40

41 42 43 44
struct task_desc {
	unsigned long		nr;
	unsigned long		pid;
	char			comm[COMM_LEN];
I
Ingo Molnar 已提交
45

46 47
	unsigned long		nr_events;
	unsigned long		curr_event;
48
	struct sched_atom	**atoms;
49 50 51

	pthread_t		thread;
	sem_t			sleep_sem;
I
Ingo Molnar 已提交
52

53 54 55 56 57 58 59 60 61 62
	sem_t			ready_for_work;
	sem_t			work_done_sem;

	u64			cpu_usage;
};

enum sched_event_type {
	SCHED_EVENT_RUN,
	SCHED_EVENT_SLEEP,
	SCHED_EVENT_WAKEUP,
63
	SCHED_EVENT_MIGRATION,
64 65
};

66
struct sched_atom {
67
	enum sched_event_type	type;
68
	int			specific_wait;
69 70 71 72 73 74 75
	u64			timestamp;
	u64			duration;
	unsigned long		nr;
	sem_t			*wait_sem;
	struct task_desc	*wakee;
};

76
#define TASK_STATE_TO_CHAR_STR "RSDTtZXxKWP"
77 78 79 80 81 82 83 84 85 86 87

enum thread_state {
	THREAD_SLEEPING = 0,
	THREAD_WAIT_CPU,
	THREAD_SCHED_IN,
	THREAD_IGNORE
};

struct work_atom {
	struct list_head	list;
	enum thread_state	state;
88
	u64			sched_out_time;
89 90 91 92 93
	u64			wake_up_time;
	u64			sched_in_time;
	u64			runtime;
};

94 95
struct work_atoms {
	struct list_head	work_list;
96 97 98
	struct thread		*thread;
	struct rb_node		node;
	u64			max_lat;
99
	u64			max_lat_at;
100 101 102
	u64			total_lat;
	u64			nb_atoms;
	u64			total_runtime;
103
	int			num_merged;
104 105
};

106
typedef int (*sort_fn_t)(struct work_atoms *, struct work_atoms *);
107

108
struct perf_sched;
109

110 111 112
struct trace_sched_handler {
	int (*switch_event)(struct perf_sched *sched, struct perf_evsel *evsel,
			    struct perf_sample *sample, struct machine *machine);
113

114 115
	int (*runtime_event)(struct perf_sched *sched, struct perf_evsel *evsel,
			     struct perf_sample *sample, struct machine *machine);
116

117 118
	int (*wakeup_event)(struct perf_sched *sched, struct perf_evsel *evsel,
			    struct perf_sample *sample, struct machine *machine);
119

120 121 122
	/* PERF_RECORD_FORK event, not sched_process_fork tracepoint */
	int (*fork_event)(struct perf_sched *sched, union perf_event *event,
			  struct machine *machine);
123 124

	int (*migrate_task_event)(struct perf_sched *sched,
125 126 127
				  struct perf_evsel *evsel,
				  struct perf_sample *sample,
				  struct machine *machine);
128 129
};

J
Jiri Olsa 已提交
130
#define COLOR_PIDS PERF_COLOR_BLUE
J
Jiri Olsa 已提交
131
#define COLOR_CPUS PERF_COLOR_BG_RED
J
Jiri Olsa 已提交
132

133 134 135 136
struct perf_sched_map {
	DECLARE_BITMAP(comp_cpus_mask, MAX_CPUS);
	int			*comp_cpus;
	bool			 comp;
J
Jiri Olsa 已提交
137 138
	struct thread_map	*color_pids;
	const char		*color_pids_str;
J
Jiri Olsa 已提交
139 140
	struct cpu_map		*color_cpus;
	const char		*color_cpus_str;
141 142
	struct cpu_map		*cpus;
	const char		*cpus_str;
143 144
};

145 146 147 148
struct perf_sched {
	struct perf_tool tool;
	const char	 *sort_order;
	unsigned long	 nr_tasks;
149
	struct task_desc **pid_to_task;
150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191
	struct task_desc **tasks;
	const struct trace_sched_handler *tp_handler;
	pthread_mutex_t	 start_work_mutex;
	pthread_mutex_t	 work_done_wait_mutex;
	int		 profile_cpu;
/*
 * 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.
 */
	int		 max_cpu;
	u32		 curr_pid[MAX_CPUS];
	struct thread	 *curr_thread[MAX_CPUS];
	char		 next_shortname1;
	char		 next_shortname2;
	unsigned int	 replay_repeat;
	unsigned long	 nr_run_events;
	unsigned long	 nr_sleep_events;
	unsigned long	 nr_wakeup_events;
	unsigned long	 nr_sleep_corrections;
	unsigned long	 nr_run_events_optimized;
	unsigned long	 targetless_wakeups;
	unsigned long	 multitarget_wakeups;
	unsigned long	 nr_runs;
	unsigned long	 nr_timestamps;
	unsigned long	 nr_unordered_timestamps;
	unsigned long	 nr_context_switch_bugs;
	unsigned long	 nr_events;
	unsigned long	 nr_lost_chunks;
	unsigned long	 nr_lost_events;
	u64		 run_measurement_overhead;
	u64		 sleep_measurement_overhead;
	u64		 start_time;
	u64		 cpu_usage;
	u64		 runavg_cpu_usage;
	u64		 parent_cpu_usage;
	u64		 runavg_parent_cpu_usage;
	u64		 sum_runtime;
	u64		 sum_fluct;
	u64		 run_avg;
	u64		 all_runtime;
	u64		 all_count;
	u64		 cpu_last_switched[MAX_CPUS];
192
	struct rb_root	 atom_root, sorted_atom_root, merged_atom_root;
193
	struct list_head sort_list, cmp_pid;
194
	bool force;
195
	bool skip_merge;
196
	struct perf_sched_map map;
197 198 199 200 201

	/* options for timehist command */
	bool		summary;
	bool		summary_only;
	u64		skipped_samples;
202
};
203

204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226
/* per thread run time data */
struct thread_runtime {
	u64 last_time;      /* time of previous sched in/out event */
	u64 dt_run;         /* run time */
	u64 dt_wait;        /* time between CPU access (off cpu) */
	u64 dt_delay;       /* time between wakeup and sched-in */
	u64 ready_to_run;   /* time of wakeup */

	struct stats run_stats;
	u64 total_run_time;
};

/* per event run time data */
struct evsel_runtime {
	u64 *last_time; /* time this event was last seen per cpu */
	u32 ncpu;       /* highest cpu slot allocated */
};

/* track idle times per cpu */
static struct thread **idle_threads;
static int idle_max_cpu;
static char idle_comm[] = "<idle>";

227
static u64 get_nsecs(void)
I
Ingo Molnar 已提交
228 229 230 231 232
{
	struct timespec ts;

	clock_gettime(CLOCK_MONOTONIC, &ts);

233
	return ts.tv_sec * NSEC_PER_SEC + ts.tv_nsec;
I
Ingo Molnar 已提交
234 235
}

236
static void burn_nsecs(struct perf_sched *sched, u64 nsecs)
I
Ingo Molnar 已提交
237
{
238
	u64 T0 = get_nsecs(), T1;
I
Ingo Molnar 已提交
239 240 241

	do {
		T1 = get_nsecs();
242
	} while (T1 + sched->run_measurement_overhead < T0 + nsecs);
I
Ingo Molnar 已提交
243 244
}

245
static void sleep_nsecs(u64 nsecs)
I
Ingo Molnar 已提交
246 247 248 249 250 251 252 253 254
{
	struct timespec ts;

	ts.tv_nsec = nsecs % 999999999;
	ts.tv_sec = nsecs / 999999999;

	nanosleep(&ts, NULL);
}

255
static void calibrate_run_measurement_overhead(struct perf_sched *sched)
I
Ingo Molnar 已提交
256
{
257
	u64 T0, T1, delta, min_delta = NSEC_PER_SEC;
I
Ingo Molnar 已提交
258 259 260 261
	int i;

	for (i = 0; i < 10; i++) {
		T0 = get_nsecs();
262
		burn_nsecs(sched, 0);
I
Ingo Molnar 已提交
263 264 265 266
		T1 = get_nsecs();
		delta = T1-T0;
		min_delta = min(min_delta, delta);
	}
267
	sched->run_measurement_overhead = min_delta;
I
Ingo Molnar 已提交
268

269
	printf("run measurement overhead: %" PRIu64 " nsecs\n", min_delta);
I
Ingo Molnar 已提交
270 271
}

272
static void calibrate_sleep_measurement_overhead(struct perf_sched *sched)
I
Ingo Molnar 已提交
273
{
274
	u64 T0, T1, delta, min_delta = NSEC_PER_SEC;
I
Ingo Molnar 已提交
275 276 277 278 279 280 281 282 283 284
	int i;

	for (i = 0; i < 10; i++) {
		T0 = get_nsecs();
		sleep_nsecs(10000);
		T1 = get_nsecs();
		delta = T1-T0;
		min_delta = min(min_delta, delta);
	}
	min_delta -= 10000;
285
	sched->sleep_measurement_overhead = min_delta;
I
Ingo Molnar 已提交
286

287
	printf("sleep measurement overhead: %" PRIu64 " nsecs\n", min_delta);
I
Ingo Molnar 已提交
288 289
}

290
static struct sched_atom *
291
get_new_event(struct task_desc *task, u64 timestamp)
I
Ingo Molnar 已提交
292
{
293
	struct sched_atom *event = zalloc(sizeof(*event));
I
Ingo Molnar 已提交
294 295 296 297 298 299 300
	unsigned long idx = task->nr_events;
	size_t size;

	event->timestamp = timestamp;
	event->nr = idx;

	task->nr_events++;
301 302 303
	size = sizeof(struct sched_atom *) * task->nr_events;
	task->atoms = realloc(task->atoms, size);
	BUG_ON(!task->atoms);
I
Ingo Molnar 已提交
304

305
	task->atoms[idx] = event;
I
Ingo Molnar 已提交
306 307 308 309

	return event;
}

310
static struct sched_atom *last_event(struct task_desc *task)
I
Ingo Molnar 已提交
311 312 313 314
{
	if (!task->nr_events)
		return NULL;

315
	return task->atoms[task->nr_events - 1];
I
Ingo Molnar 已提交
316 317
}

318 319
static void add_sched_event_run(struct perf_sched *sched, struct task_desc *task,
				u64 timestamp, u64 duration)
I
Ingo Molnar 已提交
320
{
321
	struct sched_atom *event, *curr_event = last_event(task);
I
Ingo Molnar 已提交
322 323

	/*
324 325 326
	 * optimize an existing RUN event by merging this one
	 * to it:
	 */
I
Ingo Molnar 已提交
327
	if (curr_event && curr_event->type == SCHED_EVENT_RUN) {
328
		sched->nr_run_events_optimized++;
I
Ingo Molnar 已提交
329 330 331 332 333 334 335 336 337
		curr_event->duration += duration;
		return;
	}

	event = get_new_event(task, timestamp);

	event->type = SCHED_EVENT_RUN;
	event->duration = duration;

338
	sched->nr_run_events++;
I
Ingo Molnar 已提交
339 340
}

341 342
static void add_sched_event_wakeup(struct perf_sched *sched, struct task_desc *task,
				   u64 timestamp, struct task_desc *wakee)
I
Ingo Molnar 已提交
343
{
344
	struct sched_atom *event, *wakee_event;
I
Ingo Molnar 已提交
345 346 347 348 349 350 351

	event = get_new_event(task, timestamp);
	event->type = SCHED_EVENT_WAKEUP;
	event->wakee = wakee;

	wakee_event = last_event(wakee);
	if (!wakee_event || wakee_event->type != SCHED_EVENT_SLEEP) {
352
		sched->targetless_wakeups++;
I
Ingo Molnar 已提交
353 354 355
		return;
	}
	if (wakee_event->wait_sem) {
356
		sched->multitarget_wakeups++;
I
Ingo Molnar 已提交
357 358 359
		return;
	}

360
	wakee_event->wait_sem = zalloc(sizeof(*wakee_event->wait_sem));
I
Ingo Molnar 已提交
361 362 363 364
	sem_init(wakee_event->wait_sem, 0, 0);
	wakee_event->specific_wait = 1;
	event->wait_sem = wakee_event->wait_sem;

365
	sched->nr_wakeup_events++;
I
Ingo Molnar 已提交
366 367
}

368 369
static void add_sched_event_sleep(struct perf_sched *sched, struct task_desc *task,
				  u64 timestamp, u64 task_state __maybe_unused)
I
Ingo Molnar 已提交
370
{
371
	struct sched_atom *event = get_new_event(task, timestamp);
I
Ingo Molnar 已提交
372 373 374

	event->type = SCHED_EVENT_SLEEP;

375
	sched->nr_sleep_events++;
I
Ingo Molnar 已提交
376 377
}

378 379
static struct task_desc *register_pid(struct perf_sched *sched,
				      unsigned long pid, const char *comm)
I
Ingo Molnar 已提交
380 381
{
	struct task_desc *task;
382
	static int pid_max;
I
Ingo Molnar 已提交
383

384 385 386 387 388
	if (sched->pid_to_task == NULL) {
		if (sysctl__read_int("kernel/pid_max", &pid_max) < 0)
			pid_max = MAX_PID;
		BUG_ON((sched->pid_to_task = calloc(pid_max, sizeof(struct task_desc *))) == NULL);
	}
389 390 391 392 393 394
	if (pid >= (unsigned long)pid_max) {
		BUG_ON((sched->pid_to_task = realloc(sched->pid_to_task, (pid + 1) *
			sizeof(struct task_desc *))) == NULL);
		while (pid >= (unsigned long)pid_max)
			sched->pid_to_task[pid_max++] = NULL;
	}
I
Ingo Molnar 已提交
395

396
	task = sched->pid_to_task[pid];
I
Ingo Molnar 已提交
397 398 399 400

	if (task)
		return task;

401
	task = zalloc(sizeof(*task));
I
Ingo Molnar 已提交
402
	task->pid = pid;
403
	task->nr = sched->nr_tasks;
I
Ingo Molnar 已提交
404 405 406 407 408
	strcpy(task->comm, comm);
	/*
	 * every task starts in sleeping state - this gets ignored
	 * if there's no wakeup pointing to this sleep state:
	 */
409
	add_sched_event_sleep(sched, task, 0, 0);
I
Ingo Molnar 已提交
410

411 412
	sched->pid_to_task[pid] = task;
	sched->nr_tasks++;
413
	sched->tasks = realloc(sched->tasks, sched->nr_tasks * sizeof(struct task_desc *));
414 415
	BUG_ON(!sched->tasks);
	sched->tasks[task->nr] = task;
I
Ingo Molnar 已提交
416

I
Ingo Molnar 已提交
417
	if (verbose)
418
		printf("registered task #%ld, PID %ld (%s)\n", sched->nr_tasks, pid, comm);
I
Ingo Molnar 已提交
419 420 421 422 423

	return task;
}


424
static void print_task_traces(struct perf_sched *sched)
I
Ingo Molnar 已提交
425 426 427 428
{
	struct task_desc *task;
	unsigned long i;

429 430
	for (i = 0; i < sched->nr_tasks; i++) {
		task = sched->tasks[i];
I
Ingo Molnar 已提交
431
		printf("task %6ld (%20s:%10ld), nr_events: %ld\n",
I
Ingo Molnar 已提交
432 433 434 435
			task->nr, task->comm, task->pid, task->nr_events);
	}
}

436
static void add_cross_task_wakeups(struct perf_sched *sched)
I
Ingo Molnar 已提交
437 438 439 440
{
	struct task_desc *task1, *task2;
	unsigned long i, j;

441 442
	for (i = 0; i < sched->nr_tasks; i++) {
		task1 = sched->tasks[i];
I
Ingo Molnar 已提交
443
		j = i + 1;
444
		if (j == sched->nr_tasks)
I
Ingo Molnar 已提交
445
			j = 0;
446 447
		task2 = sched->tasks[j];
		add_sched_event_wakeup(sched, task1, 0, task2);
I
Ingo Molnar 已提交
448 449 450
	}
}

451 452
static void perf_sched__process_event(struct perf_sched *sched,
				      struct sched_atom *atom)
I
Ingo Molnar 已提交
453 454 455
{
	int ret = 0;

456
	switch (atom->type) {
I
Ingo Molnar 已提交
457
		case SCHED_EVENT_RUN:
458
			burn_nsecs(sched, atom->duration);
I
Ingo Molnar 已提交
459 460
			break;
		case SCHED_EVENT_SLEEP:
461 462
			if (atom->wait_sem)
				ret = sem_wait(atom->wait_sem);
I
Ingo Molnar 已提交
463 464 465
			BUG_ON(ret);
			break;
		case SCHED_EVENT_WAKEUP:
466 467
			if (atom->wait_sem)
				ret = sem_post(atom->wait_sem);
I
Ingo Molnar 已提交
468 469
			BUG_ON(ret);
			break;
470 471
		case SCHED_EVENT_MIGRATION:
			break;
I
Ingo Molnar 已提交
472 473 474 475 476
		default:
			BUG_ON(1);
	}
}

477
static u64 get_cpu_usage_nsec_parent(void)
I
Ingo Molnar 已提交
478 479
{
	struct rusage ru;
480
	u64 sum;
I
Ingo Molnar 已提交
481 482 483 484 485
	int err;

	err = getrusage(RUSAGE_SELF, &ru);
	BUG_ON(err);

486 487
	sum =  ru.ru_utime.tv_sec * NSEC_PER_SEC + ru.ru_utime.tv_usec * NSEC_PER_USEC;
	sum += ru.ru_stime.tv_sec * NSEC_PER_SEC + ru.ru_stime.tv_usec * NSEC_PER_USEC;
I
Ingo Molnar 已提交
488 489 490 491

	return sum;
}

492
static int self_open_counters(struct perf_sched *sched, unsigned long cur_task)
I
Ingo Molnar 已提交
493
{
494
	struct perf_event_attr attr;
495
	char sbuf[STRERR_BUFSIZE], info[STRERR_BUFSIZE];
496
	int fd;
497 498
	struct rlimit limit;
	bool need_privilege = false;
I
Ingo Molnar 已提交
499

500
	memset(&attr, 0, sizeof(attr));
I
Ingo Molnar 已提交
501

502 503
	attr.type = PERF_TYPE_SOFTWARE;
	attr.config = PERF_COUNT_SW_TASK_CLOCK;
I
Ingo Molnar 已提交
504

505
force_again:
506 507
	fd = sys_perf_event_open(&attr, 0, -1, -1,
				 perf_event_open_cloexec_flag());
508

509
	if (fd < 0) {
510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525
		if (errno == EMFILE) {
			if (sched->force) {
				BUG_ON(getrlimit(RLIMIT_NOFILE, &limit) == -1);
				limit.rlim_cur += sched->nr_tasks - cur_task;
				if (limit.rlim_cur > limit.rlim_max) {
					limit.rlim_max = limit.rlim_cur;
					need_privilege = true;
				}
				if (setrlimit(RLIMIT_NOFILE, &limit) == -1) {
					if (need_privilege && errno == EPERM)
						strcpy(info, "Need privilege\n");
				} else
					goto force_again;
			} else
				strcpy(info, "Have a try with -f option\n");
		}
526
		pr_err("Error: sys_perf_event_open() syscall returned "
527
		       "with %d (%s)\n%s", fd,
528
		       str_error_r(errno, sbuf, sizeof(sbuf)), info);
529 530
		exit(EXIT_FAILURE);
	}
531 532 533 534 535 536 537 538 539 540 541 542
	return fd;
}

static u64 get_cpu_usage_nsec_self(int fd)
{
	u64 runtime;
	int ret;

	ret = read(fd, &runtime, sizeof(runtime));
	BUG_ON(ret != sizeof(runtime));

	return runtime;
I
Ingo Molnar 已提交
543 544
}

545 546 547
struct sched_thread_parms {
	struct task_desc  *task;
	struct perf_sched *sched;
548
	int fd;
549 550
};

I
Ingo Molnar 已提交
551 552
static void *thread_func(void *ctx)
{
553 554 555
	struct sched_thread_parms *parms = ctx;
	struct task_desc *this_task = parms->task;
	struct perf_sched *sched = parms->sched;
556
	u64 cpu_usage_0, cpu_usage_1;
I
Ingo Molnar 已提交
557 558
	unsigned long i, ret;
	char comm2[22];
559
	int fd = parms->fd;
I
Ingo Molnar 已提交
560

561
	zfree(&parms);
562

I
Ingo Molnar 已提交
563 564
	sprintf(comm2, ":%s", this_task->comm);
	prctl(PR_SET_NAME, comm2);
565 566
	if (fd < 0)
		return NULL;
I
Ingo Molnar 已提交
567 568 569
again:
	ret = sem_post(&this_task->ready_for_work);
	BUG_ON(ret);
570
	ret = pthread_mutex_lock(&sched->start_work_mutex);
I
Ingo Molnar 已提交
571
	BUG_ON(ret);
572
	ret = pthread_mutex_unlock(&sched->start_work_mutex);
I
Ingo Molnar 已提交
573 574
	BUG_ON(ret);

575
	cpu_usage_0 = get_cpu_usage_nsec_self(fd);
I
Ingo Molnar 已提交
576 577 578

	for (i = 0; i < this_task->nr_events; i++) {
		this_task->curr_event = i;
579
		perf_sched__process_event(sched, this_task->atoms[i]);
I
Ingo Molnar 已提交
580 581
	}

582
	cpu_usage_1 = get_cpu_usage_nsec_self(fd);
I
Ingo Molnar 已提交
583 584 585 586
	this_task->cpu_usage = cpu_usage_1 - cpu_usage_0;
	ret = sem_post(&this_task->work_done_sem);
	BUG_ON(ret);

587
	ret = pthread_mutex_lock(&sched->work_done_wait_mutex);
I
Ingo Molnar 已提交
588
	BUG_ON(ret);
589
	ret = pthread_mutex_unlock(&sched->work_done_wait_mutex);
I
Ingo Molnar 已提交
590 591 592 593 594
	BUG_ON(ret);

	goto again;
}

595
static void create_tasks(struct perf_sched *sched)
I
Ingo Molnar 已提交
596 597 598 599 600 601 602 603
{
	struct task_desc *task;
	pthread_attr_t attr;
	unsigned long i;
	int err;

	err = pthread_attr_init(&attr);
	BUG_ON(err);
604 605
	err = pthread_attr_setstacksize(&attr,
			(size_t) max(16 * 1024, PTHREAD_STACK_MIN));
I
Ingo Molnar 已提交
606
	BUG_ON(err);
607
	err = pthread_mutex_lock(&sched->start_work_mutex);
I
Ingo Molnar 已提交
608
	BUG_ON(err);
609
	err = pthread_mutex_lock(&sched->work_done_wait_mutex);
I
Ingo Molnar 已提交
610
	BUG_ON(err);
611 612 613 614 615
	for (i = 0; i < sched->nr_tasks; i++) {
		struct sched_thread_parms *parms = malloc(sizeof(*parms));
		BUG_ON(parms == NULL);
		parms->task = task = sched->tasks[i];
		parms->sched = sched;
616
		parms->fd = self_open_counters(sched, i);
I
Ingo Molnar 已提交
617 618 619 620
		sem_init(&task->sleep_sem, 0, 0);
		sem_init(&task->ready_for_work, 0, 0);
		sem_init(&task->work_done_sem, 0, 0);
		task->curr_event = 0;
621
		err = pthread_create(&task->thread, &attr, thread_func, parms);
I
Ingo Molnar 已提交
622 623 624 625
		BUG_ON(err);
	}
}

626
static void wait_for_tasks(struct perf_sched *sched)
I
Ingo Molnar 已提交
627
{
628
	u64 cpu_usage_0, cpu_usage_1;
I
Ingo Molnar 已提交
629 630 631
	struct task_desc *task;
	unsigned long i, ret;

632 633 634
	sched->start_time = get_nsecs();
	sched->cpu_usage = 0;
	pthread_mutex_unlock(&sched->work_done_wait_mutex);
I
Ingo Molnar 已提交
635

636 637
	for (i = 0; i < sched->nr_tasks; i++) {
		task = sched->tasks[i];
I
Ingo Molnar 已提交
638 639 640 641
		ret = sem_wait(&task->ready_for_work);
		BUG_ON(ret);
		sem_init(&task->ready_for_work, 0, 0);
	}
642
	ret = pthread_mutex_lock(&sched->work_done_wait_mutex);
I
Ingo Molnar 已提交
643 644 645 646
	BUG_ON(ret);

	cpu_usage_0 = get_cpu_usage_nsec_parent();

647
	pthread_mutex_unlock(&sched->start_work_mutex);
I
Ingo Molnar 已提交
648

649 650
	for (i = 0; i < sched->nr_tasks; i++) {
		task = sched->tasks[i];
I
Ingo Molnar 已提交
651 652 653
		ret = sem_wait(&task->work_done_sem);
		BUG_ON(ret);
		sem_init(&task->work_done_sem, 0, 0);
654
		sched->cpu_usage += task->cpu_usage;
I
Ingo Molnar 已提交
655 656 657 658
		task->cpu_usage = 0;
	}

	cpu_usage_1 = get_cpu_usage_nsec_parent();
659 660
	if (!sched->runavg_cpu_usage)
		sched->runavg_cpu_usage = sched->cpu_usage;
661
	sched->runavg_cpu_usage = (sched->runavg_cpu_usage * (sched->replay_repeat - 1) + sched->cpu_usage) / sched->replay_repeat;
I
Ingo Molnar 已提交
662

663 664 665
	sched->parent_cpu_usage = cpu_usage_1 - cpu_usage_0;
	if (!sched->runavg_parent_cpu_usage)
		sched->runavg_parent_cpu_usage = sched->parent_cpu_usage;
666 667
	sched->runavg_parent_cpu_usage = (sched->runavg_parent_cpu_usage * (sched->replay_repeat - 1) +
					 sched->parent_cpu_usage)/sched->replay_repeat;
I
Ingo Molnar 已提交
668

669
	ret = pthread_mutex_lock(&sched->start_work_mutex);
I
Ingo Molnar 已提交
670 671
	BUG_ON(ret);

672 673
	for (i = 0; i < sched->nr_tasks; i++) {
		task = sched->tasks[i];
I
Ingo Molnar 已提交
674 675 676 677 678
		sem_init(&task->sleep_sem, 0, 0);
		task->curr_event = 0;
	}
}

679
static void run_one_test(struct perf_sched *sched)
I
Ingo Molnar 已提交
680
{
K
Kyle McMartin 已提交
681
	u64 T0, T1, delta, avg_delta, fluct;
I
Ingo Molnar 已提交
682 683

	T0 = get_nsecs();
684
	wait_for_tasks(sched);
I
Ingo Molnar 已提交
685 686 687
	T1 = get_nsecs();

	delta = T1 - T0;
688 689
	sched->sum_runtime += delta;
	sched->nr_runs++;
I
Ingo Molnar 已提交
690

691
	avg_delta = sched->sum_runtime / sched->nr_runs;
I
Ingo Molnar 已提交
692 693 694 695
	if (delta < avg_delta)
		fluct = avg_delta - delta;
	else
		fluct = delta - avg_delta;
696 697 698
	sched->sum_fluct += fluct;
	if (!sched->run_avg)
		sched->run_avg = delta;
699
	sched->run_avg = (sched->run_avg * (sched->replay_repeat - 1) + delta) / sched->replay_repeat;
I
Ingo Molnar 已提交
700

701
	printf("#%-3ld: %0.3f, ", sched->nr_runs, (double)delta / NSEC_PER_MSEC);
I
Ingo Molnar 已提交
702

703
	printf("ravg: %0.2f, ", (double)sched->run_avg / NSEC_PER_MSEC);
I
Ingo Molnar 已提交
704

I
Ingo Molnar 已提交
705
	printf("cpu: %0.2f / %0.2f",
706
		(double)sched->cpu_usage / NSEC_PER_MSEC, (double)sched->runavg_cpu_usage / NSEC_PER_MSEC);
I
Ingo Molnar 已提交
707 708 709

#if 0
	/*
710
	 * rusage statistics done by the parent, these are less
711
	 * accurate than the sched->sum_exec_runtime based statistics:
712
	 */
I
Ingo Molnar 已提交
713
	printf(" [%0.2f / %0.2f]",
714 715
		(double)sched->parent_cpu_usage / NSEC_PER_MSEC,
		(double)sched->runavg_parent_cpu_usage / NSEC_PER_MSEC);
I
Ingo Molnar 已提交
716 717
#endif

I
Ingo Molnar 已提交
718
	printf("\n");
I
Ingo Molnar 已提交
719

720 721 722
	if (sched->nr_sleep_corrections)
		printf(" (%ld sleep corrections)\n", sched->nr_sleep_corrections);
	sched->nr_sleep_corrections = 0;
I
Ingo Molnar 已提交
723 724
}

725
static void test_calibrations(struct perf_sched *sched)
I
Ingo Molnar 已提交
726
{
727
	u64 T0, T1;
I
Ingo Molnar 已提交
728 729

	T0 = get_nsecs();
730
	burn_nsecs(sched, NSEC_PER_MSEC);
I
Ingo Molnar 已提交
731 732
	T1 = get_nsecs();

733
	printf("the run test took %" PRIu64 " nsecs\n", T1 - T0);
I
Ingo Molnar 已提交
734 735

	T0 = get_nsecs();
736
	sleep_nsecs(NSEC_PER_MSEC);
I
Ingo Molnar 已提交
737 738
	T1 = get_nsecs();

739
	printf("the sleep test took %" PRIu64 " nsecs\n", T1 - T0);
I
Ingo Molnar 已提交
740 741
}

742
static int
743
replay_wakeup_event(struct perf_sched *sched,
744 745
		    struct perf_evsel *evsel, struct perf_sample *sample,
		    struct machine *machine __maybe_unused)
746
{
747 748
	const char *comm = perf_evsel__strval(evsel, sample, "comm");
	const u32 pid	 = perf_evsel__intval(evsel, sample, "pid");
749
	struct task_desc *waker, *wakee;
750

I
Ingo Molnar 已提交
751
	if (verbose) {
752
		printf("sched_wakeup event %p\n", evsel);
753

754
		printf(" ... pid %d woke up %s/%d\n", sample->tid, comm, pid);
I
Ingo Molnar 已提交
755
	}
756

757
	waker = register_pid(sched, sample->tid, "<unknown>");
758
	wakee = register_pid(sched, pid, comm);
759

760
	add_sched_event_wakeup(sched, waker, sample->time, wakee);
761
	return 0;
I
Ingo Molnar 已提交
762 763
}

764 765 766 767
static int replay_switch_event(struct perf_sched *sched,
			       struct perf_evsel *evsel,
			       struct perf_sample *sample,
			       struct machine *machine __maybe_unused)
I
Ingo Molnar 已提交
768
{
769 770 771 772 773
	const char *prev_comm  = perf_evsel__strval(evsel, sample, "prev_comm"),
		   *next_comm  = perf_evsel__strval(evsel, sample, "next_comm");
	const u32 prev_pid = perf_evsel__intval(evsel, sample, "prev_pid"),
		  next_pid = perf_evsel__intval(evsel, sample, "next_pid");
	const u64 prev_state = perf_evsel__intval(evsel, sample, "prev_state");
774
	struct task_desc *prev, __maybe_unused *next;
775 776
	u64 timestamp0, timestamp = sample->time;
	int cpu = sample->cpu;
777 778
	s64 delta;

I
Ingo Molnar 已提交
779
	if (verbose)
780
		printf("sched_switch event %p\n", evsel);
I
Ingo Molnar 已提交
781

782
	if (cpu >= MAX_CPUS || cpu < 0)
783
		return 0;
784

785
	timestamp0 = sched->cpu_last_switched[cpu];
786 787 788 789 790
	if (timestamp0)
		delta = timestamp - timestamp0;
	else
		delta = 0;

791
	if (delta < 0) {
792
		pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta);
793 794
		return -1;
	}
795

796 797
	pr_debug(" ... switch from %s/%d to %s/%d [ran %" PRIu64 " nsecs]\n",
		 prev_comm, prev_pid, next_comm, next_pid, delta);
798

799 800
	prev = register_pid(sched, prev_pid, prev_comm);
	next = register_pid(sched, next_pid, next_comm);
801

802
	sched->cpu_last_switched[cpu] = timestamp;
803

804
	add_sched_event_run(sched, prev, timestamp, delta);
805
	add_sched_event_sleep(sched, prev, timestamp, prev_state);
806 807

	return 0;
808 809
}

810 811 812
static int replay_fork_event(struct perf_sched *sched,
			     union perf_event *event,
			     struct machine *machine)
813
{
814 815
	struct thread *child, *parent;

816 817 818 819
	child = machine__findnew_thread(machine, event->fork.pid,
					event->fork.tid);
	parent = machine__findnew_thread(machine, event->fork.ppid,
					 event->fork.ptid);
820 821 822 823

	if (child == NULL || parent == NULL) {
		pr_debug("thread does not exist on fork event: child %p, parent %p\n",
				 child, parent);
824
		goto out_put;
825
	}
826

827
	if (verbose) {
828
		printf("fork event\n");
829 830
		printf("... parent: %s/%d\n", thread__comm_str(parent), parent->tid);
		printf("...  child: %s/%d\n", thread__comm_str(child), child->tid);
831
	}
832

833 834
	register_pid(sched, parent->tid, thread__comm_str(parent));
	register_pid(sched, child->tid, thread__comm_str(child));
835 836 837
out_put:
	thread__put(child);
	thread__put(parent);
838
	return 0;
839
}
840

841 842
struct sort_dimension {
	const char		*name;
843
	sort_fn_t		cmp;
844 845 846
	struct list_head	list;
};

847
static int
848
thread_lat_cmp(struct list_head *list, struct work_atoms *l, struct work_atoms *r)
849 850 851 852
{
	struct sort_dimension *sort;
	int ret = 0;

853 854
	BUG_ON(list_empty(list));

855 856 857 858 859 860 861 862 863
	list_for_each_entry(sort, list, list) {
		ret = sort->cmp(l, r);
		if (ret)
			return ret;
	}

	return ret;
}

864
static struct work_atoms *
865 866 867 868
thread_atoms_search(struct rb_root *root, struct thread *thread,
			 struct list_head *sort_list)
{
	struct rb_node *node = root->rb_node;
869
	struct work_atoms key = { .thread = thread };
870 871

	while (node) {
872
		struct work_atoms *atoms;
873 874
		int cmp;

875
		atoms = container_of(node, struct work_atoms, node);
876 877 878 879 880 881 882 883 884 885 886 887 888 889

		cmp = thread_lat_cmp(sort_list, &key, atoms);
		if (cmp > 0)
			node = node->rb_left;
		else if (cmp < 0)
			node = node->rb_right;
		else {
			BUG_ON(thread != atoms->thread);
			return atoms;
		}
	}
	return NULL;
}

890
static void
891
__thread_latency_insert(struct rb_root *root, struct work_atoms *data,
892
			 struct list_head *sort_list)
893 894 895 896
{
	struct rb_node **new = &(root->rb_node), *parent = NULL;

	while (*new) {
897
		struct work_atoms *this;
898
		int cmp;
899

900
		this = container_of(*new, struct work_atoms, node);
901
		parent = *new;
902 903 904 905

		cmp = thread_lat_cmp(sort_list, data, this);

		if (cmp > 0)
906 907
			new = &((*new)->rb_left);
		else
908
			new = &((*new)->rb_right);
909 910 911 912 913 914
	}

	rb_link_node(&data->node, parent, new);
	rb_insert_color(&data->node, root);
}

915
static int thread_atoms_insert(struct perf_sched *sched, struct thread *thread)
916
{
917
	struct work_atoms *atoms = zalloc(sizeof(*atoms));
918 919 920 921
	if (!atoms) {
		pr_err("No memory at %s\n", __func__);
		return -1;
	}
922

923
	atoms->thread = thread__get(thread);
924
	INIT_LIST_HEAD(&atoms->work_list);
925
	__thread_latency_insert(&sched->atom_root, atoms, &sched->cmp_pid);
926
	return 0;
927 928
}

929
static char sched_out_state(u64 prev_state)
930 931 932
{
	const char *str = TASK_STATE_TO_CHAR_STR;

933
	return str[prev_state];
934 935
}

936
static int
937 938 939
add_sched_out_event(struct work_atoms *atoms,
		    char run_state,
		    u64 timestamp)
940
{
941
	struct work_atom *atom = zalloc(sizeof(*atom));
942 943 944 945
	if (!atom) {
		pr_err("Non memory at %s", __func__);
		return -1;
	}
946

947 948
	atom->sched_out_time = timestamp;

949
	if (run_state == 'R') {
950
		atom->state = THREAD_WAIT_CPU;
951
		atom->wake_up_time = atom->sched_out_time;
952 953
	}

954
	list_add_tail(&atom->list, &atoms->work_list);
955
	return 0;
956 957 958
}

static void
959 960
add_runtime_event(struct work_atoms *atoms, u64 delta,
		  u64 timestamp __maybe_unused)
961 962 963 964 965 966 967 968 969 970 971 972 973
{
	struct work_atom *atom;

	BUG_ON(list_empty(&atoms->work_list));

	atom = list_entry(atoms->work_list.prev, struct work_atom, list);

	atom->runtime += delta;
	atoms->total_runtime += delta;
}

static void
add_sched_in_event(struct work_atoms *atoms, u64 timestamp)
974
{
975
	struct work_atom *atom;
976
	u64 delta;
977

978
	if (list_empty(&atoms->work_list))
979 980
		return;

981
	atom = list_entry(atoms->work_list.prev, struct work_atom, list);
982

983
	if (atom->state != THREAD_WAIT_CPU)
984 985
		return;

986 987
	if (timestamp < atom->wake_up_time) {
		atom->state = THREAD_IGNORE;
988 989 990
		return;
	}

991 992
	atom->state = THREAD_SCHED_IN;
	atom->sched_in_time = timestamp;
993

994
	delta = atom->sched_in_time - atom->wake_up_time;
995
	atoms->total_lat += delta;
996
	if (delta > atoms->max_lat) {
997
		atoms->max_lat = delta;
998 999
		atoms->max_lat_at = timestamp;
	}
1000
	atoms->nb_atoms++;
1001 1002
}

1003 1004 1005 1006
static int latency_switch_event(struct perf_sched *sched,
				struct perf_evsel *evsel,
				struct perf_sample *sample,
				struct machine *machine)
1007
{
1008 1009 1010
	const u32 prev_pid = perf_evsel__intval(evsel, sample, "prev_pid"),
		  next_pid = perf_evsel__intval(evsel, sample, "next_pid");
	const u64 prev_state = perf_evsel__intval(evsel, sample, "prev_state");
1011
	struct work_atoms *out_events, *in_events;
1012
	struct thread *sched_out, *sched_in;
1013
	u64 timestamp0, timestamp = sample->time;
1014
	int cpu = sample->cpu, err = -1;
I
Ingo Molnar 已提交
1015 1016
	s64 delta;

1017
	BUG_ON(cpu >= MAX_CPUS || cpu < 0);
I
Ingo Molnar 已提交
1018

1019 1020
	timestamp0 = sched->cpu_last_switched[cpu];
	sched->cpu_last_switched[cpu] = timestamp;
I
Ingo Molnar 已提交
1021 1022 1023 1024 1025
	if (timestamp0)
		delta = timestamp - timestamp0;
	else
		delta = 0;

1026 1027 1028 1029
	if (delta < 0) {
		pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta);
		return -1;
	}
1030

1031 1032
	sched_out = machine__findnew_thread(machine, -1, prev_pid);
	sched_in = machine__findnew_thread(machine, -1, next_pid);
1033 1034
	if (sched_out == NULL || sched_in == NULL)
		goto out_put;
1035

1036
	out_events = thread_atoms_search(&sched->atom_root, sched_out, &sched->cmp_pid);
1037
	if (!out_events) {
1038
		if (thread_atoms_insert(sched, sched_out))
1039
			goto out_put;
1040
		out_events = thread_atoms_search(&sched->atom_root, sched_out, &sched->cmp_pid);
1041 1042
		if (!out_events) {
			pr_err("out-event: Internal tree error");
1043
			goto out_put;
1044
		}
1045
	}
1046
	if (add_sched_out_event(out_events, sched_out_state(prev_state), timestamp))
1047
		return -1;
1048

1049
	in_events = thread_atoms_search(&sched->atom_root, sched_in, &sched->cmp_pid);
1050
	if (!in_events) {
1051
		if (thread_atoms_insert(sched, sched_in))
1052
			goto out_put;
1053
		in_events = thread_atoms_search(&sched->atom_root, sched_in, &sched->cmp_pid);
1054 1055
		if (!in_events) {
			pr_err("in-event: Internal tree error");
1056
			goto out_put;
1057
		}
1058 1059 1060 1061
		/*
		 * Take came in we have not heard about yet,
		 * add in an initial atom in runnable state:
		 */
1062
		if (add_sched_out_event(in_events, 'R', timestamp))
1063
			goto out_put;
1064
	}
1065
	add_sched_in_event(in_events, timestamp);
1066 1067 1068 1069 1070
	err = 0;
out_put:
	thread__put(sched_out);
	thread__put(sched_in);
	return err;
1071
}
1072

1073 1074 1075 1076
static int latency_runtime_event(struct perf_sched *sched,
				 struct perf_evsel *evsel,
				 struct perf_sample *sample,
				 struct machine *machine)
1077
{
1078 1079
	const u32 pid	   = perf_evsel__intval(evsel, sample, "pid");
	const u64 runtime  = perf_evsel__intval(evsel, sample, "runtime");
1080
	struct thread *thread = machine__findnew_thread(machine, -1, pid);
1081
	struct work_atoms *atoms = thread_atoms_search(&sched->atom_root, thread, &sched->cmp_pid);
1082
	u64 timestamp = sample->time;
1083 1084 1085 1086
	int cpu = sample->cpu, err = -1;

	if (thread == NULL)
		return -1;
1087 1088 1089

	BUG_ON(cpu >= MAX_CPUS || cpu < 0);
	if (!atoms) {
1090
		if (thread_atoms_insert(sched, thread))
1091
			goto out_put;
1092
		atoms = thread_atoms_search(&sched->atom_root, thread, &sched->cmp_pid);
1093
		if (!atoms) {
1094
			pr_err("in-event: Internal tree error");
1095
			goto out_put;
1096 1097
		}
		if (add_sched_out_event(atoms, 'R', timestamp))
1098
			goto out_put;
1099 1100
	}

1101
	add_runtime_event(atoms, runtime, timestamp);
1102 1103 1104 1105
	err = 0;
out_put:
	thread__put(thread);
	return err;
1106 1107
}

1108 1109 1110 1111
static int latency_wakeup_event(struct perf_sched *sched,
				struct perf_evsel *evsel,
				struct perf_sample *sample,
				struct machine *machine)
1112
{
1113
	const u32 pid	  = perf_evsel__intval(evsel, sample, "pid");
1114
	struct work_atoms *atoms;
1115
	struct work_atom *atom;
1116
	struct thread *wakee;
1117
	u64 timestamp = sample->time;
1118
	int err = -1;
1119

1120
	wakee = machine__findnew_thread(machine, -1, pid);
1121 1122
	if (wakee == NULL)
		return -1;
1123
	atoms = thread_atoms_search(&sched->atom_root, wakee, &sched->cmp_pid);
1124
	if (!atoms) {
1125
		if (thread_atoms_insert(sched, wakee))
1126
			goto out_put;
1127
		atoms = thread_atoms_search(&sched->atom_root, wakee, &sched->cmp_pid);
1128
		if (!atoms) {
1129
			pr_err("wakeup-event: Internal tree error");
1130
			goto out_put;
1131 1132
		}
		if (add_sched_out_event(atoms, 'S', timestamp))
1133
			goto out_put;
1134 1135
	}

1136
	BUG_ON(list_empty(&atoms->work_list));
1137

1138
	atom = list_entry(atoms->work_list.prev, struct work_atom, list);
1139

1140
	/*
1141 1142 1143 1144 1145 1146
	 * As we do not guarantee the wakeup event happens when
	 * task is out of run queue, also may happen when task is
	 * on run queue and wakeup only change ->state to TASK_RUNNING,
	 * then we should not set the ->wake_up_time when wake up a
	 * task which is on run queue.
	 *
1147 1148
	 * You WILL be missing events if you've recorded only
	 * one CPU, or are only looking at only one, so don't
1149
	 * skip in this case.
1150
	 */
1151
	if (sched->profile_cpu == -1 && atom->state != THREAD_SLEEPING)
1152
		goto out_ok;
1153

1154
	sched->nr_timestamps++;
1155
	if (atom->sched_out_time > timestamp) {
1156
		sched->nr_unordered_timestamps++;
1157
		goto out_ok;
1158
	}
1159

1160 1161
	atom->state = THREAD_WAIT_CPU;
	atom->wake_up_time = timestamp;
1162 1163 1164 1165 1166
out_ok:
	err = 0;
out_put:
	thread__put(wakee);
	return err;
1167 1168
}

1169 1170 1171 1172
static int latency_migrate_task_event(struct perf_sched *sched,
				      struct perf_evsel *evsel,
				      struct perf_sample *sample,
				      struct machine *machine)
1173
{
1174
	const u32 pid = perf_evsel__intval(evsel, sample, "pid");
1175
	u64 timestamp = sample->time;
1176 1177 1178
	struct work_atoms *atoms;
	struct work_atom *atom;
	struct thread *migrant;
1179
	int err = -1;
1180 1181 1182 1183

	/*
	 * Only need to worry about migration when profiling one CPU.
	 */
1184
	if (sched->profile_cpu == -1)
1185
		return 0;
1186

1187
	migrant = machine__findnew_thread(machine, -1, pid);
1188 1189
	if (migrant == NULL)
		return -1;
1190
	atoms = thread_atoms_search(&sched->atom_root, migrant, &sched->cmp_pid);
1191
	if (!atoms) {
1192
		if (thread_atoms_insert(sched, migrant))
1193
			goto out_put;
1194
		register_pid(sched, migrant->tid, thread__comm_str(migrant));
1195
		atoms = thread_atoms_search(&sched->atom_root, migrant, &sched->cmp_pid);
1196
		if (!atoms) {
1197
			pr_err("migration-event: Internal tree error");
1198
			goto out_put;
1199 1200
		}
		if (add_sched_out_event(atoms, 'R', timestamp))
1201
			goto out_put;
1202 1203 1204 1205 1206 1207 1208
	}

	BUG_ON(list_empty(&atoms->work_list));

	atom = list_entry(atoms->work_list.prev, struct work_atom, list);
	atom->sched_in_time = atom->sched_out_time = atom->wake_up_time = timestamp;

1209
	sched->nr_timestamps++;
1210 1211

	if (atom->sched_out_time > timestamp)
1212
		sched->nr_unordered_timestamps++;
1213 1214 1215 1216
	err = 0;
out_put:
	thread__put(migrant);
	return err;
1217 1218
}

1219
static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_list)
1220 1221 1222
{
	int i;
	int ret;
1223
	u64 avg;
1224
	char max_lat_at[32];
1225

1226
	if (!work_list->nb_atoms)
1227
		return;
1228 1229 1230
	/*
	 * Ignore idle threads:
	 */
1231
	if (!strcmp(thread__comm_str(work_list->thread), "swapper"))
1232
		return;
1233

1234 1235
	sched->all_runtime += work_list->total_runtime;
	sched->all_count   += work_list->nb_atoms;
1236

1237 1238 1239 1240
	if (work_list->num_merged > 1)
		ret = printf("  %s:(%d) ", thread__comm_str(work_list->thread), work_list->num_merged);
	else
		ret = printf("  %s:%d ", thread__comm_str(work_list->thread), work_list->thread->tid);
1241

M
mingo 已提交
1242
	for (i = 0; i < 24 - ret; i++)
1243 1244
		printf(" ");

1245
	avg = work_list->total_lat / work_list->nb_atoms;
1246
	timestamp__scnprintf_usec(work_list->max_lat_at, max_lat_at, sizeof(max_lat_at));
1247

1248
	printf("|%11.3f ms |%9" PRIu64 " | avg:%9.3f ms | max:%9.3f ms | max at: %13s s\n",
1249 1250 1251
	      (double)work_list->total_runtime / NSEC_PER_MSEC,
		 work_list->nb_atoms, (double)avg / NSEC_PER_MSEC,
		 (double)work_list->max_lat / NSEC_PER_MSEC,
1252
		 max_lat_at);
1253 1254
}

1255
static int pid_cmp(struct work_atoms *l, struct work_atoms *r)
1256
{
1257 1258
	if (l->thread == r->thread)
		return 0;
1259
	if (l->thread->tid < r->thread->tid)
1260
		return -1;
1261
	if (l->thread->tid > r->thread->tid)
1262
		return 1;
1263
	return (int)(l->thread - r->thread);
1264 1265
}

1266
static int avg_cmp(struct work_atoms *l, struct work_atoms *r)
1267 1268 1269 1270 1271 1272 1273 1274 1275 1276 1277 1278 1279 1280 1281 1282 1283 1284 1285 1286
{
	u64 avgl, avgr;

	if (!l->nb_atoms)
		return -1;

	if (!r->nb_atoms)
		return 1;

	avgl = l->total_lat / l->nb_atoms;
	avgr = r->total_lat / r->nb_atoms;

	if (avgl < avgr)
		return -1;
	if (avgl > avgr)
		return 1;

	return 0;
}

1287
static int max_cmp(struct work_atoms *l, struct work_atoms *r)
1288 1289 1290 1291 1292 1293 1294 1295 1296
{
	if (l->max_lat < r->max_lat)
		return -1;
	if (l->max_lat > r->max_lat)
		return 1;

	return 0;
}

1297
static int switch_cmp(struct work_atoms *l, struct work_atoms *r)
1298 1299 1300 1301 1302 1303 1304 1305 1306
{
	if (l->nb_atoms < r->nb_atoms)
		return -1;
	if (l->nb_atoms > r->nb_atoms)
		return 1;

	return 0;
}

1307
static int runtime_cmp(struct work_atoms *l, struct work_atoms *r)
1308 1309 1310 1311 1312 1313 1314 1315 1316
{
	if (l->total_runtime < r->total_runtime)
		return -1;
	if (l->total_runtime > r->total_runtime)
		return 1;

	return 0;
}

1317
static int sort_dimension__add(const char *tok, struct list_head *list)
1318
{
1319 1320 1321 1322 1323 1324 1325 1326 1327 1328 1329 1330 1331 1332 1333 1334 1335 1336 1337 1338 1339 1340 1341 1342 1343 1344 1345 1346
	size_t i;
	static struct sort_dimension avg_sort_dimension = {
		.name = "avg",
		.cmp  = avg_cmp,
	};
	static struct sort_dimension max_sort_dimension = {
		.name = "max",
		.cmp  = max_cmp,
	};
	static struct sort_dimension pid_sort_dimension = {
		.name = "pid",
		.cmp  = pid_cmp,
	};
	static struct sort_dimension runtime_sort_dimension = {
		.name = "runtime",
		.cmp  = runtime_cmp,
	};
	static struct sort_dimension switch_sort_dimension = {
		.name = "switch",
		.cmp  = switch_cmp,
	};
	struct sort_dimension *available_sorts[] = {
		&pid_sort_dimension,
		&avg_sort_dimension,
		&max_sort_dimension,
		&switch_sort_dimension,
		&runtime_sort_dimension,
	};
1347

1348
	for (i = 0; i < ARRAY_SIZE(available_sorts); i++) {
1349 1350 1351 1352 1353 1354 1355 1356 1357 1358
		if (!strcmp(available_sorts[i]->name, tok)) {
			list_add_tail(&available_sorts[i]->list, list);

			return 0;
		}
	}

	return -1;
}

1359
static void perf_sched__sort_lat(struct perf_sched *sched)
1360 1361
{
	struct rb_node *node;
1362 1363
	struct rb_root *root = &sched->atom_root;
again:
1364
	for (;;) {
1365
		struct work_atoms *data;
1366
		node = rb_first(root);
1367 1368 1369
		if (!node)
			break;

1370
		rb_erase(node, root);
1371
		data = rb_entry(node, struct work_atoms, node);
1372
		__thread_latency_insert(&sched->sorted_atom_root, data, &sched->sort_list);
1373
	}
1374 1375 1376 1377
	if (root == &sched->atom_root) {
		root = &sched->merged_atom_root;
		goto again;
	}
1378 1379
}

1380
static int process_sched_wakeup_event(struct perf_tool *tool,
1381
				      struct perf_evsel *evsel,
1382
				      struct perf_sample *sample,
1383
				      struct machine *machine)
1384
{
1385
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
1386

1387 1388
	if (sched->tp_handler->wakeup_event)
		return sched->tp_handler->wakeup_event(sched, evsel, sample, machine);
1389

1390
	return 0;
1391 1392
}

J
Jiri Olsa 已提交
1393 1394 1395 1396 1397 1398 1399 1400 1401 1402 1403 1404 1405 1406 1407 1408 1409 1410 1411 1412 1413 1414 1415 1416 1417 1418 1419 1420 1421 1422 1423 1424
union map_priv {
	void	*ptr;
	bool	 color;
};

static bool thread__has_color(struct thread *thread)
{
	union map_priv priv = {
		.ptr = thread__priv(thread),
	};

	return priv.color;
}

static struct thread*
map__findnew_thread(struct perf_sched *sched, struct machine *machine, pid_t pid, pid_t tid)
{
	struct thread *thread = machine__findnew_thread(machine, pid, tid);
	union map_priv priv = {
		.color = false,
	};

	if (!sched->map.color_pids || !thread || thread__priv(thread))
		return thread;

	if (thread_map__has(sched->map.color_pids, tid))
		priv.color = true;

	thread__set_priv(thread, priv.ptr);
	return thread;
}

1425 1426
static int map_switch_event(struct perf_sched *sched, struct perf_evsel *evsel,
			    struct perf_sample *sample, struct machine *machine)
1427
{
1428 1429
	const u32 next_pid = perf_evsel__intval(evsel, sample, "next_pid");
	struct thread *sched_in;
1430
	int new_shortname;
1431
	u64 timestamp0, timestamp = sample->time;
1432
	s64 delta;
1433 1434 1435
	int i, this_cpu = sample->cpu;
	int cpus_nr;
	bool new_cpu = false;
1436
	const char *color = PERF_COLOR_NORMAL;
1437
	char stimestamp[32];
1438 1439 1440

	BUG_ON(this_cpu >= MAX_CPUS || this_cpu < 0);

1441 1442
	if (this_cpu > sched->max_cpu)
		sched->max_cpu = this_cpu;
1443

1444 1445 1446 1447 1448 1449 1450 1451 1452
	if (sched->map.comp) {
		cpus_nr = bitmap_weight(sched->map.comp_cpus_mask, MAX_CPUS);
		if (!test_and_set_bit(this_cpu, sched->map.comp_cpus_mask)) {
			sched->map.comp_cpus[cpus_nr++] = this_cpu;
			new_cpu = true;
		}
	} else
		cpus_nr = sched->max_cpu;

1453 1454
	timestamp0 = sched->cpu_last_switched[this_cpu];
	sched->cpu_last_switched[this_cpu] = timestamp;
1455 1456 1457 1458 1459
	if (timestamp0)
		delta = timestamp - timestamp0;
	else
		delta = 0;

1460
	if (delta < 0) {
1461
		pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta);
1462 1463
		return -1;
	}
1464

J
Jiri Olsa 已提交
1465
	sched_in = map__findnew_thread(sched, machine, -1, next_pid);
1466 1467
	if (sched_in == NULL)
		return -1;
1468

1469
	sched->curr_thread[this_cpu] = thread__get(sched_in);
1470 1471 1472 1473 1474

	printf("  ");

	new_shortname = 0;
	if (!sched_in->shortname[0]) {
1475 1476 1477 1478 1479 1480 1481
		if (!strcmp(thread__comm_str(sched_in), "swapper")) {
			/*
			 * Don't allocate a letter-number for swapper:0
			 * as a shortname. Instead, we use '.' for it.
			 */
			sched_in->shortname[0] = '.';
			sched_in->shortname[1] = ' ';
1482
		} else {
1483 1484 1485 1486 1487
			sched_in->shortname[0] = sched->next_shortname1;
			sched_in->shortname[1] = sched->next_shortname2;

			if (sched->next_shortname1 < 'Z') {
				sched->next_shortname1++;
1488
			} else {
1489 1490 1491 1492 1493
				sched->next_shortname1 = 'A';
				if (sched->next_shortname2 < '9')
					sched->next_shortname2++;
				else
					sched->next_shortname2 = '0';
1494 1495 1496 1497 1498
			}
		}
		new_shortname = 1;
	}

1499 1500
	for (i = 0; i < cpus_nr; i++) {
		int cpu = sched->map.comp ? sched->map.comp_cpus[i] : i;
J
Jiri Olsa 已提交
1501 1502
		struct thread *curr_thread = sched->curr_thread[cpu];
		const char *pid_color = color;
J
Jiri Olsa 已提交
1503
		const char *cpu_color = color;
J
Jiri Olsa 已提交
1504 1505 1506

		if (curr_thread && thread__has_color(curr_thread))
			pid_color = COLOR_PIDS;
1507

1508 1509 1510
		if (sched->map.cpus && !cpu_map__has(sched->map.cpus, cpu))
			continue;

J
Jiri Olsa 已提交
1511 1512 1513
		if (sched->map.color_cpus && cpu_map__has(sched->map.color_cpus, cpu))
			cpu_color = COLOR_CPUS;

1514
		if (cpu != this_cpu)
1515
			color_fprintf(stdout, color, " ");
1516
		else
J
Jiri Olsa 已提交
1517
			color_fprintf(stdout, cpu_color, "*");
1518

1519
		if (sched->curr_thread[cpu])
J
Jiri Olsa 已提交
1520
			color_fprintf(stdout, pid_color, "%2s ", sched->curr_thread[cpu]->shortname);
1521
		else
1522
			color_fprintf(stdout, color, "   ");
1523 1524
	}

1525 1526 1527
	if (sched->map.cpus && !cpu_map__has(sched->map.cpus, this_cpu))
		goto out;

1528 1529
	timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp));
	color_fprintf(stdout, color, "  %12s secs ", stimestamp);
1530
	if (new_shortname || (verbose && sched_in->tid)) {
J
Jiri Olsa 已提交
1531 1532 1533 1534 1535 1536
		const char *pid_color = color;

		if (thread__has_color(sched_in))
			pid_color = COLOR_PIDS;

		color_fprintf(stdout, pid_color, "%s => %s:%d",
1537
		       sched_in->shortname, thread__comm_str(sched_in), sched_in->tid);
1538
	}
1539

1540
	if (sched->map.comp && new_cpu)
1541
		color_fprintf(stdout, color, " (CPU %d)", this_cpu);
1542

1543
out:
1544
	color_fprintf(stdout, color, "\n");
1545

1546 1547
	thread__put(sched_in);

1548
	return 0;
1549 1550
}

1551
static int process_sched_switch_event(struct perf_tool *tool,
1552
				      struct perf_evsel *evsel,
1553
				      struct perf_sample *sample,
1554
				      struct machine *machine)
1555
{
1556
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
1557
	int this_cpu = sample->cpu, err = 0;
1558 1559
	u32 prev_pid = perf_evsel__intval(evsel, sample, "prev_pid"),
	    next_pid = perf_evsel__intval(evsel, sample, "next_pid");
1560

1561
	if (sched->curr_pid[this_cpu] != (u32)-1) {
1562 1563 1564 1565
		/*
		 * Are we trying to switch away a PID that is
		 * not current?
		 */
1566
		if (sched->curr_pid[this_cpu] != prev_pid)
1567
			sched->nr_context_switch_bugs++;
1568 1569
	}

1570 1571
	if (sched->tp_handler->switch_event)
		err = sched->tp_handler->switch_event(sched, evsel, sample, machine);
1572 1573

	sched->curr_pid[this_cpu] = next_pid;
1574
	return err;
1575 1576
}

1577
static int process_sched_runtime_event(struct perf_tool *tool,
1578
				       struct perf_evsel *evsel,
1579
				       struct perf_sample *sample,
1580
				       struct machine *machine)
1581
{
1582
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
1583

1584 1585
	if (sched->tp_handler->runtime_event)
		return sched->tp_handler->runtime_event(sched, evsel, sample, machine);
1586

1587
	return 0;
1588 1589
}

1590 1591 1592 1593
static int perf_sched__process_fork_event(struct perf_tool *tool,
					  union perf_event *event,
					  struct perf_sample *sample,
					  struct machine *machine)
1594
{
1595
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
1596

1597 1598 1599 1600
	/* run the fork event through the perf machineruy */
	perf_event__process_fork(tool, event, sample, machine);

	/* and then run additional processing needed for this command */
1601
	if (sched->tp_handler->fork_event)
1602
		return sched->tp_handler->fork_event(sched, event, machine);
1603

1604
	return 0;
1605 1606
}

1607
static int process_sched_migrate_task_event(struct perf_tool *tool,
1608
					    struct perf_evsel *evsel,
1609
					    struct perf_sample *sample,
1610
					    struct machine *machine)
1611
{
1612
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
1613

1614 1615
	if (sched->tp_handler->migrate_task_event)
		return sched->tp_handler->migrate_task_event(sched, evsel, sample, machine);
1616

1617
	return 0;
1618 1619
}

1620
typedef int (*tracepoint_handler)(struct perf_tool *tool,
1621
				  struct perf_evsel *evsel,
1622
				  struct perf_sample *sample,
1623
				  struct machine *machine);
I
Ingo Molnar 已提交
1624

1625 1626
static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_unused,
						 union perf_event *event __maybe_unused,
1627 1628 1629
						 struct perf_sample *sample,
						 struct perf_evsel *evsel,
						 struct machine *machine)
I
Ingo Molnar 已提交
1630
{
1631
	int err = 0;
I
Ingo Molnar 已提交
1632

1633 1634
	if (evsel->handler != NULL) {
		tracepoint_handler f = evsel->handler;
1635
		err = f(tool, evsel, sample, machine);
1636
	}
I
Ingo Molnar 已提交
1637

1638
	return err;
I
Ingo Molnar 已提交
1639 1640
}

1641
static int perf_sched__read_events(struct perf_sched *sched)
I
Ingo Molnar 已提交
1642
{
1643 1644 1645 1646 1647 1648 1649
	const struct perf_evsel_str_handler handlers[] = {
		{ "sched:sched_switch",	      process_sched_switch_event, },
		{ "sched:sched_stat_runtime", process_sched_runtime_event, },
		{ "sched:sched_wakeup",	      process_sched_wakeup_event, },
		{ "sched:sched_wakeup_new",   process_sched_wakeup_event, },
		{ "sched:sched_migrate_task", process_sched_migrate_task_event, },
	};
1650
	struct perf_session *session;
1651 1652 1653
	struct perf_data_file file = {
		.path = input_name,
		.mode = PERF_DATA_MODE_READ,
1654
		.force = sched->force,
1655
	};
1656
	int rc = -1;
1657

1658
	session = perf_session__new(&file, false, &sched->tool);
1659 1660 1661 1662
	if (session == NULL) {
		pr_debug("No Memory for session\n");
		return -1;
	}
1663

1664
	symbol__init(&session->header.env);
1665

1666 1667
	if (perf_session__set_tracepoints_handlers(session, handlers))
		goto out_delete;
1668

1669
	if (perf_session__has_traces(session, "record -R")) {
1670
		int err = perf_session__process_events(session);
1671 1672 1673 1674
		if (err) {
			pr_err("Failed to process events, error %d", err);
			goto out_delete;
		}
1675

1676 1677 1678
		sched->nr_events      = session->evlist->stats.nr_events[0];
		sched->nr_lost_events = session->evlist->stats.total_lost;
		sched->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST];
1679
	}
1680

1681
	rc = 0;
1682 1683
out_delete:
	perf_session__delete(session);
1684
	return rc;
I
Ingo Molnar 已提交
1685 1686
}

1687 1688 1689 1690 1691 1692 1693 1694 1695 1696 1697 1698 1699 1700 1701 1702 1703 1704 1705 1706 1707 1708 1709 1710 1711 1712 1713 1714 1715 1716 1717 1718 1719 1720 1721 1722 1723 1724 1725 1726 1727 1728 1729 1730 1731 1732 1733 1734 1735 1736 1737 1738 1739 1740 1741 1742 1743 1744 1745 1746 1747 1748 1749 1750 1751 1752 1753 1754 1755 1756 1757 1758 1759 1760 1761 1762 1763 1764 1765 1766 1767 1768 1769 1770 1771 1772 1773 1774 1775 1776 1777 1778 1779 1780 1781 1782 1783 1784 1785 1786 1787 1788 1789 1790 1791 1792 1793 1794 1795 1796 1797 1798 1799 1800 1801 1802 1803 1804 1805 1806 1807 1808 1809 1810 1811 1812 1813 1814 1815 1816 1817 1818 1819 1820 1821 1822 1823 1824 1825 1826 1827 1828 1829 1830 1831 1832 1833 1834 1835 1836 1837 1838 1839 1840 1841 1842 1843 1844 1845 1846 1847 1848 1849 1850 1851 1852 1853 1854 1855 1856 1857 1858 1859 1860 1861 1862 1863 1864 1865 1866 1867 1868 1869 1870 1871 1872 1873 1874 1875 1876 1877 1878 1879 1880 1881 1882 1883 1884 1885 1886 1887 1888 1889 1890 1891 1892 1893 1894 1895 1896 1897 1898 1899 1900 1901 1902 1903 1904 1905 1906 1907 1908 1909 1910 1911 1912 1913 1914 1915 1916 1917 1918 1919 1920 1921 1922 1923 1924 1925 1926 1927 1928 1929 1930 1931 1932 1933 1934 1935 1936 1937 1938 1939 1940 1941 1942 1943 1944 1945 1946 1947 1948 1949 1950 1951 1952 1953 1954 1955 1956 1957 1958 1959 1960 1961 1962 1963 1964 1965 1966 1967 1968 1969 1970 1971 1972 1973 1974 1975 1976 1977 1978 1979 1980 1981 1982 1983 1984 1985 1986 1987 1988 1989 1990 1991 1992 1993 1994 1995 1996 1997 1998 1999 2000 2001 2002 2003 2004 2005 2006 2007 2008 2009 2010 2011 2012 2013 2014 2015 2016 2017
/*
 * scheduling times are printed as msec.usec
 */
static inline void print_sched_time(unsigned long long nsecs, int width)
{
	unsigned long msecs;
	unsigned long usecs;

	msecs  = nsecs / NSEC_PER_MSEC;
	nsecs -= msecs * NSEC_PER_MSEC;
	usecs  = nsecs / NSEC_PER_USEC;
	printf("%*lu.%03lu ", width, msecs, usecs);
}

/*
 * returns runtime data for event, allocating memory for it the
 * first time it is used.
 */
static struct evsel_runtime *perf_evsel__get_runtime(struct perf_evsel *evsel)
{
	struct evsel_runtime *r = evsel->priv;

	if (r == NULL) {
		r = zalloc(sizeof(struct evsel_runtime));
		evsel->priv = r;
	}

	return r;
}

/*
 * save last time event was seen per cpu
 */
static void perf_evsel__save_time(struct perf_evsel *evsel,
				  u64 timestamp, u32 cpu)
{
	struct evsel_runtime *r = perf_evsel__get_runtime(evsel);

	if (r == NULL)
		return;

	if ((cpu >= r->ncpu) || (r->last_time == NULL)) {
		int i, n = __roundup_pow_of_two(cpu+1);
		void *p = r->last_time;

		p = realloc(r->last_time, n * sizeof(u64));
		if (!p)
			return;

		r->last_time = p;
		for (i = r->ncpu; i < n; ++i)
			r->last_time[i] = (u64) 0;

		r->ncpu = n;
	}

	r->last_time[cpu] = timestamp;
}

/* returns last time this event was seen on the given cpu */
static u64 perf_evsel__get_time(struct perf_evsel *evsel, u32 cpu)
{
	struct evsel_runtime *r = perf_evsel__get_runtime(evsel);

	if ((r == NULL) || (r->last_time == NULL) || (cpu >= r->ncpu))
		return 0;

	return r->last_time[cpu];
}

static int comm_width = 20;

static char *timehist_get_commstr(struct thread *thread)
{
	static char str[32];
	const char *comm = thread__comm_str(thread);
	pid_t tid = thread->tid;
	pid_t pid = thread->pid_;
	int n;

	if (pid == 0)
		n = scnprintf(str, sizeof(str), "%s", comm);

	else if (tid != pid)
		n = scnprintf(str, sizeof(str), "%s[%d/%d]", comm, tid, pid);

	else
		n = scnprintf(str, sizeof(str), "%s[%d]", comm, tid);

	if (n > comm_width)
		comm_width = n;

	return str;
}

static void timehist_header(void)
{
	printf("%15s %6s ", "time", "cpu");

	printf(" %-20s  %9s  %9s  %9s",
		"task name", "wait time", "sch delay", "run time");

	printf("\n");

	/*
	 * units row
	 */
	printf("%15s %-6s ", "", "");

	printf(" %-20s  %9s  %9s  %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");

	/*
	 * separator
	 */
	printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);

	printf(" %.20s  %.9s  %.9s  %.9s",
		graph_dotted_line, graph_dotted_line, graph_dotted_line,
		graph_dotted_line);

	printf("\n");
}

static void timehist_print_sample(struct perf_sample *sample,
				  struct thread *thread)
{
	struct thread_runtime *tr = thread__priv(thread);
	char tstr[64];

	timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
	printf("%15s [%04d] ", tstr, sample->cpu);

	printf(" %-*s ", comm_width, timehist_get_commstr(thread));

	print_sched_time(tr->dt_wait, 6);
	print_sched_time(tr->dt_delay, 6);
	print_sched_time(tr->dt_run, 6);
	printf("\n");
}

/*
 * Explanation of delta-time stats:
 *
 *            t = time of current schedule out event
 *        tprev = time of previous sched out event
 *                also time of schedule-in event for current task
 *    last_time = time of last sched change event for current task
 *                (i.e, time process was last scheduled out)
 * ready_to_run = time of wakeup for current task
 *
 * -----|------------|------------|------------|------
 *    last         ready        tprev          t
 *    time         to run
 *
 *      |-------- dt_wait --------|
 *                   |- dt_delay -|-- dt_run --|
 *
 *   dt_run = run time of current task
 *  dt_wait = time between last schedule out event for task and tprev
 *            represents time spent off the cpu
 * dt_delay = time between wakeup and schedule-in of task
 */

static void timehist_update_runtime_stats(struct thread_runtime *r,
					 u64 t, u64 tprev)
{
	r->dt_delay   = 0;
	r->dt_wait    = 0;
	r->dt_run     = 0;
	if (tprev) {
		r->dt_run = t - tprev;
		if (r->ready_to_run) {
			if (r->ready_to_run > tprev)
				pr_debug("time travel: wakeup time for task > previous sched_switch event\n");
			else
				r->dt_delay = tprev - r->ready_to_run;
		}

		if (r->last_time > tprev)
			pr_debug("time travel: last sched out time for task > previous sched_switch event\n");
		else if (r->last_time)
			r->dt_wait = tprev - r->last_time;
	}

	update_stats(&r->run_stats, r->dt_run);
	r->total_run_time += r->dt_run;
}

static bool is_idle_sample(struct perf_sample *sample,
			   struct perf_evsel *evsel)
{
	/* pid 0 == swapper == idle task */
	if (sample->pid == 0)
		return true;

	if (strcmp(perf_evsel__name(evsel), "sched:sched_switch") == 0) {
		if (perf_evsel__intval(evsel, sample, "prev_pid") == 0)
			return true;
	}
	return false;
}

/*
 * Track idle stats per cpu by maintaining a local thread
 * struct for the idle task on each cpu.
 */
static int init_idle_threads(int ncpu)
{
	int i;

	idle_threads = zalloc(ncpu * sizeof(struct thread *));
	if (!idle_threads)
		return -ENOMEM;

	idle_max_cpu = ncpu - 1;

	/* allocate the actual thread struct if needed */
	for (i = 0; i < ncpu; ++i) {
		idle_threads[i] = thread__new(0, 0);
		if (idle_threads[i] == NULL)
			return -ENOMEM;

		thread__set_comm(idle_threads[i], idle_comm, 0);
	}

	return 0;
}

static void free_idle_threads(void)
{
	int i;

	if (idle_threads == NULL)
		return;

	for (i = 0; i <= idle_max_cpu; ++i) {
		if ((idle_threads[i]))
			thread__delete(idle_threads[i]);
	}

	free(idle_threads);
}

static struct thread *get_idle_thread(int cpu)
{
	/*
	 * expand/allocate array of pointers to local thread
	 * structs if needed
	 */
	if ((cpu >= idle_max_cpu) || (idle_threads == NULL)) {
		int i, j = __roundup_pow_of_two(cpu+1);
		void *p;

		p = realloc(idle_threads, j * sizeof(struct thread *));
		if (!p)
			return NULL;

		idle_threads = (struct thread **) p;
		i = idle_max_cpu ? idle_max_cpu + 1 : 0;
		for (; i < j; ++i)
			idle_threads[i] = NULL;

		idle_max_cpu = j;
	}

	/* allocate a new thread struct if needed */
	if (idle_threads[cpu] == NULL) {
		idle_threads[cpu] = thread__new(0, 0);

		if (idle_threads[cpu]) {
			idle_threads[cpu]->tid = 0;
			thread__set_comm(idle_threads[cpu], idle_comm, 0);
		}
	}

	return idle_threads[cpu];
}

/*
 * handle runtime stats saved per thread
 */
static struct thread_runtime *thread__init_runtime(struct thread *thread)
{
	struct thread_runtime *r;

	r = zalloc(sizeof(struct thread_runtime));
	if (!r)
		return NULL;

	init_stats(&r->run_stats);
	thread__set_priv(thread, r);

	return r;
}

static struct thread_runtime *thread__get_runtime(struct thread *thread)
{
	struct thread_runtime *tr;

	tr = thread__priv(thread);
	if (tr == NULL) {
		tr = thread__init_runtime(thread);
		if (tr == NULL)
			pr_debug("Failed to malloc memory for runtime data.\n");
	}

	return tr;
}

static struct thread *timehist_get_thread(struct perf_sample *sample,
					  struct machine *machine,
					  struct perf_evsel *evsel)
{
	struct thread *thread;

	if (is_idle_sample(sample, evsel)) {
		thread = get_idle_thread(sample->cpu);
		if (thread == NULL)
			pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu);

	} else {
		thread = machine__findnew_thread(machine, sample->pid, sample->tid);
		if (thread == NULL) {
			pr_debug("Failed to get thread for tid %d. skipping sample.\n",
				 sample->tid);
		}
	}

	return thread;
}

2018 2019
static bool timehist_skip_sample(struct perf_sched *sched,
				 struct thread *thread)
2020 2021 2022
{
	bool rc = false;

2023
	if (thread__is_filtered(thread)) {
2024
		rc = true;
2025 2026
		sched->skipped_samples++;
	}
2027 2028 2029 2030 2031 2032 2033 2034 2035 2036 2037 2038 2039 2040 2041 2042 2043 2044 2045 2046 2047 2048 2049 2050 2051 2052 2053 2054 2055

	return rc;
}

static int timehist_sched_wakeup_event(struct perf_tool *tool __maybe_unused,
				       union perf_event *event __maybe_unused,
				       struct perf_evsel *evsel,
				       struct perf_sample *sample,
				       struct machine *machine)
{
	struct thread *thread;
	struct thread_runtime *tr = NULL;
	/* want pid of awakened task not pid in sample */
	const u32 pid = perf_evsel__intval(evsel, sample, "pid");

	thread = machine__findnew_thread(machine, 0, pid);
	if (thread == NULL)
		return -1;

	tr = thread__get_runtime(thread);
	if (tr == NULL)
		return -1;

	if (tr->ready_to_run == 0)
		tr->ready_to_run = sample->time;

	return 0;
}

2056
static int timehist_sched_change_event(struct perf_tool *tool,
2057 2058 2059 2060 2061 2062 2063 2064 2065 2066
				       union perf_event *event,
				       struct perf_evsel *evsel,
				       struct perf_sample *sample,
				       struct machine *machine)
{
	struct addr_location al;
	struct thread *thread;
	struct thread_runtime *tr = NULL;
	u64 tprev;
	int rc = 0;
2067
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
2068 2069 2070 2071 2072 2073 2074 2075 2076 2077 2078 2079 2080 2081

	if (machine__resolve(machine, &al, sample) < 0) {
		pr_err("problem processing %d event. skipping it\n",
		       event->header.type);
		rc = -1;
		goto out;
	}

	thread = timehist_get_thread(sample, machine, evsel);
	if (thread == NULL) {
		rc = -1;
		goto out;
	}

2082
	if (timehist_skip_sample(sched, thread))
2083 2084 2085 2086 2087 2088 2089 2090 2091 2092 2093
		goto out;

	tr = thread__get_runtime(thread);
	if (tr == NULL) {
		rc = -1;
		goto out;
	}

	tprev = perf_evsel__get_time(evsel, sample->cpu);

	timehist_update_runtime_stats(tr, sample->time, tprev);
2094 2095
	if (!sched->summary_only)
		timehist_print_sample(sample, thread);
2096 2097 2098 2099 2100 2101 2102 2103 2104 2105 2106 2107 2108 2109 2110 2111 2112 2113 2114 2115 2116 2117 2118 2119 2120 2121 2122 2123 2124 2125 2126 2127 2128 2129 2130 2131 2132 2133 2134

out:
	if (tr) {
		/* time of this sched_switch event becomes last time task seen */
		tr->last_time = sample->time;

		/* sched out event for task so reset ready to run time */
		tr->ready_to_run = 0;
	}

	perf_evsel__save_time(evsel, sample->time, sample->cpu);

	return rc;
}

static int timehist_sched_switch_event(struct perf_tool *tool,
			     union perf_event *event,
			     struct perf_evsel *evsel,
			     struct perf_sample *sample,
			     struct machine *machine __maybe_unused)
{
	return timehist_sched_change_event(tool, event, evsel, sample, machine);
}

static int process_lost(struct perf_tool *tool __maybe_unused,
			union perf_event *event,
			struct perf_sample *sample,
			struct machine *machine __maybe_unused)
{
	char tstr[64];

	timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
	printf("%15s ", tstr);
	printf("lost %" PRIu64 " events on cpu %d\n", event->lost.lost, sample->cpu);

	return 0;
}


2135 2136 2137 2138 2139 2140 2141 2142 2143 2144 2145 2146 2147 2148 2149 2150 2151 2152 2153 2154 2155 2156 2157 2158 2159 2160 2161 2162 2163 2164 2165 2166 2167 2168 2169 2170 2171 2172 2173 2174 2175 2176 2177 2178 2179 2180 2181 2182 2183 2184 2185 2186 2187 2188 2189 2190 2191 2192 2193 2194 2195 2196 2197 2198 2199 2200 2201 2202 2203 2204 2205 2206 2207 2208 2209 2210 2211 2212 2213 2214 2215 2216 2217 2218 2219 2220 2221 2222 2223 2224 2225 2226 2227 2228 2229 2230 2231 2232 2233 2234 2235 2236 2237 2238 2239 2240 2241 2242 2243 2244 2245 2246 2247 2248 2249 2250 2251 2252 2253 2254 2255 2256 2257 2258 2259
static void print_thread_runtime(struct thread *t,
				 struct thread_runtime *r)
{
	double mean = avg_stats(&r->run_stats);
	float stddev;

	printf("%*s   %5d  %9" PRIu64 " ",
	       comm_width, timehist_get_commstr(t), t->ppid,
	       (u64) r->run_stats.n);

	print_sched_time(r->total_run_time, 8);
	stddev = rel_stddev_stats(stddev_stats(&r->run_stats), mean);
	print_sched_time(r->run_stats.min, 6);
	printf(" ");
	print_sched_time((u64) mean, 6);
	printf(" ");
	print_sched_time(r->run_stats.max, 6);
	printf("  ");
	printf("%5.2f", stddev);
	printf("\n");
}

struct total_run_stats {
	u64  sched_count;
	u64  task_count;
	u64  total_run_time;
};

static int __show_thread_runtime(struct thread *t, void *priv)
{
	struct total_run_stats *stats = priv;
	struct thread_runtime *r;

	if (thread__is_filtered(t))
		return 0;

	r = thread__priv(t);
	if (r && r->run_stats.n) {
		stats->task_count++;
		stats->sched_count += r->run_stats.n;
		stats->total_run_time += r->total_run_time;
		print_thread_runtime(t, r);
	}

	return 0;
}

static int show_thread_runtime(struct thread *t, void *priv)
{
	if (t->dead)
		return 0;

	return __show_thread_runtime(t, priv);
}

static int show_deadthread_runtime(struct thread *t, void *priv)
{
	if (!t->dead)
		return 0;

	return __show_thread_runtime(t, priv);
}

static void timehist_print_summary(struct perf_sched *sched,
				   struct perf_session *session)
{
	struct machine *m = &session->machines.host;
	struct total_run_stats totals;
	u64 task_count;
	struct thread *t;
	struct thread_runtime *r;
	int i;

	memset(&totals, 0, sizeof(totals));

	if (comm_width < 30)
		comm_width = 30;

	printf("\nRuntime summary\n");
	printf("%*s  parent   sched-in  ", comm_width, "comm");
	printf("   run-time    min-run     avg-run     max-run  stddev\n");
	printf("%*s            (count)  ", comm_width, "");
	printf("     (msec)     (msec)      (msec)      (msec)       %%\n");
	printf("%.105s\n", graph_dotted_line);

	machine__for_each_thread(m, show_thread_runtime, &totals);
	task_count = totals.task_count;
	if (!task_count)
		printf("<no still running tasks>\n");

	printf("\nTerminated tasks:\n");
	machine__for_each_thread(m, show_deadthread_runtime, &totals);
	if (task_count == totals.task_count)
		printf("<no terminated tasks>\n");

	/* CPU idle stats not tracked when samples were skipped */
	if (sched->skipped_samples)
		return;

	printf("\nIdle stats:\n");
	for (i = 0; i <= idle_max_cpu; ++i) {
		t = idle_threads[i];
		if (!t)
			continue;

		r = thread__priv(t);
		if (r && r->run_stats.n) {
			totals.sched_count += r->run_stats.n;
			printf("    CPU %2d idle for ", i);
			print_sched_time(r->total_run_time, 6);
			printf(" msec\n");
		} else
			printf("    CPU %2d idle entire time window\n", i);
	}

	printf("\n"
	       "    Total number of unique tasks: %" PRIu64 "\n"
	       "Total number of context switches: %" PRIu64 "\n"
	       "           Total run time (msec): ",
	       totals.task_count, totals.sched_count);

	print_sched_time(totals.total_run_time, 2);
	printf("\n");
}

2260 2261 2262 2263 2264 2265 2266 2267 2268 2269 2270 2271 2272 2273 2274 2275 2276 2277 2278 2279 2280 2281 2282 2283 2284 2285 2286 2287 2288 2289 2290 2291 2292 2293 2294 2295 2296 2297 2298 2299 2300
typedef int (*sched_handler)(struct perf_tool *tool,
			  union perf_event *event,
			  struct perf_evsel *evsel,
			  struct perf_sample *sample,
			  struct machine *machine);

static int perf_timehist__process_sample(struct perf_tool *tool,
					 union perf_event *event,
					 struct perf_sample *sample,
					 struct perf_evsel *evsel,
					 struct machine *machine)
{
	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
	int err = 0;
	int this_cpu = sample->cpu;

	if (this_cpu > sched->max_cpu)
		sched->max_cpu = this_cpu;

	if (evsel->handler != NULL) {
		sched_handler f = evsel->handler;

		err = f(tool, event, evsel, sample, machine);
	}

	return err;
}

static int perf_sched__timehist(struct perf_sched *sched)
{
	const struct perf_evsel_str_handler handlers[] = {
		{ "sched:sched_switch",       timehist_sched_switch_event, },
		{ "sched:sched_wakeup",	      timehist_sched_wakeup_event, },
		{ "sched:sched_wakeup_new",   timehist_sched_wakeup_event, },
	};
	struct perf_data_file file = {
		.path = input_name,
		.mode = PERF_DATA_MODE_READ,
	};

	struct perf_session *session;
2301
	struct perf_evlist *evlist;
2302 2303 2304 2305 2306 2307 2308 2309 2310 2311 2312 2313 2314 2315 2316 2317 2318 2319 2320 2321 2322 2323
	int err = -1;

	/*
	 * event handlers for timehist option
	 */
	sched->tool.sample	 = perf_timehist__process_sample;
	sched->tool.mmap	 = perf_event__process_mmap;
	sched->tool.comm	 = perf_event__process_comm;
	sched->tool.exit	 = perf_event__process_exit;
	sched->tool.fork	 = perf_event__process_fork;
	sched->tool.lost	 = process_lost;
	sched->tool.attr	 = perf_event__process_attr;
	sched->tool.tracing_data = perf_event__process_tracing_data;
	sched->tool.build_id	 = perf_event__process_build_id;

	sched->tool.ordered_events = true;
	sched->tool.ordering_requires_timestamps = true;

	session = perf_session__new(&file, false, &sched->tool);
	if (session == NULL)
		return -ENOMEM;

2324 2325
	evlist = session->evlist;

2326 2327 2328 2329 2330 2331 2332 2333 2334 2335 2336 2337 2338 2339 2340 2341 2342 2343
	symbol__init(&session->header.env);

	setup_pager();

	/* setup per-evsel handlers */
	if (perf_session__set_tracepoints_handlers(session, handlers))
		goto out;

	if (!perf_session__has_traces(session, "record -R"))
		goto out;

	/* pre-allocate struct for per-CPU idle stats */
	sched->max_cpu = session->header.env.nr_cpus_online;
	if (sched->max_cpu == 0)
		sched->max_cpu = 4;
	if (init_idle_threads(sched->max_cpu))
		goto out;

2344 2345 2346 2347 2348 2349
	/* summary_only implies summary option, but don't overwrite summary if set */
	if (sched->summary_only)
		sched->summary = sched->summary_only;

	if (!sched->summary_only)
		timehist_header();
2350 2351 2352 2353 2354 2355 2356

	err = perf_session__process_events(session);
	if (err) {
		pr_err("Failed to process events, error %d", err);
		goto out;
	}

2357 2358 2359 2360 2361 2362 2363
	sched->nr_events      = evlist->stats.nr_events[0];
	sched->nr_lost_events = evlist->stats.total_lost;
	sched->nr_lost_chunks = evlist->stats.nr_events[PERF_RECORD_LOST];

	if (sched->summary)
		timehist_print_summary(sched, session);

2364 2365 2366 2367 2368 2369 2370 2371
out:
	free_idle_threads();
	perf_session__delete(session);

	return err;
}


2372
static void print_bad_events(struct perf_sched *sched)
2373
{
2374
	if (sched->nr_unordered_timestamps && sched->nr_timestamps) {
2375
		printf("  INFO: %.3f%% unordered timestamps (%ld out of %ld)\n",
2376 2377
			(double)sched->nr_unordered_timestamps/(double)sched->nr_timestamps*100.0,
			sched->nr_unordered_timestamps, sched->nr_timestamps);
2378
	}
2379
	if (sched->nr_lost_events && sched->nr_events) {
2380
		printf("  INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n",
2381 2382
			(double)sched->nr_lost_events/(double)sched->nr_events * 100.0,
			sched->nr_lost_events, sched->nr_events, sched->nr_lost_chunks);
2383
	}
2384
	if (sched->nr_context_switch_bugs && sched->nr_timestamps) {
2385
		printf("  INFO: %.3f%% context switch bugs (%ld out of %ld)",
2386 2387 2388
			(double)sched->nr_context_switch_bugs/(double)sched->nr_timestamps*100.0,
			sched->nr_context_switch_bugs, sched->nr_timestamps);
		if (sched->nr_lost_events)
2389 2390 2391 2392 2393
			printf(" (due to lost events?)");
		printf("\n");
	}
}

2394 2395 2396 2397 2398 2399 2400 2401 2402 2403 2404 2405 2406 2407 2408 2409 2410 2411 2412 2413 2414 2415 2416 2417 2418 2419 2420 2421 2422 2423 2424 2425 2426 2427 2428 2429 2430 2431 2432 2433 2434 2435 2436 2437 2438 2439 2440 2441 2442 2443 2444 2445 2446
static void __merge_work_atoms(struct rb_root *root, struct work_atoms *data)
{
	struct rb_node **new = &(root->rb_node), *parent = NULL;
	struct work_atoms *this;
	const char *comm = thread__comm_str(data->thread), *this_comm;

	while (*new) {
		int cmp;

		this = container_of(*new, struct work_atoms, node);
		parent = *new;

		this_comm = thread__comm_str(this->thread);
		cmp = strcmp(comm, this_comm);
		if (cmp > 0) {
			new = &((*new)->rb_left);
		} else if (cmp < 0) {
			new = &((*new)->rb_right);
		} else {
			this->num_merged++;
			this->total_runtime += data->total_runtime;
			this->nb_atoms += data->nb_atoms;
			this->total_lat += data->total_lat;
			list_splice(&data->work_list, &this->work_list);
			if (this->max_lat < data->max_lat) {
				this->max_lat = data->max_lat;
				this->max_lat_at = data->max_lat_at;
			}
			zfree(&data);
			return;
		}
	}

	data->num_merged++;
	rb_link_node(&data->node, parent, new);
	rb_insert_color(&data->node, root);
}

static void perf_sched__merge_lat(struct perf_sched *sched)
{
	struct work_atoms *data;
	struct rb_node *node;

	if (sched->skip_merge)
		return;

	while ((node = rb_first(&sched->atom_root))) {
		rb_erase(node, &sched->atom_root);
		data = rb_entry(node, struct work_atoms, node);
		__merge_work_atoms(&sched->merged_atom_root, data);
	}
}

2447
static int perf_sched__lat(struct perf_sched *sched)
2448 2449 2450 2451
{
	struct rb_node *next;

	setup_pager();
2452

2453
	if (perf_sched__read_events(sched))
2454
		return -1;
2455

2456
	perf_sched__merge_lat(sched);
2457
	perf_sched__sort_lat(sched);
2458

2459 2460 2461
	printf("\n -----------------------------------------------------------------------------------------------------------------\n");
	printf("  Task                  |   Runtime ms  | Switches | Average delay ms | Maximum delay ms | Maximum delay at       |\n");
	printf(" -----------------------------------------------------------------------------------------------------------------\n");
2462

2463
	next = rb_first(&sched->sorted_atom_root);
2464 2465 2466 2467 2468

	while (next) {
		struct work_atoms *work_list;

		work_list = rb_entry(next, struct work_atoms, node);
2469
		output_lat_thread(sched, work_list);
2470
		next = rb_next(next);
2471
		thread__zput(work_list->thread);
2472 2473
	}

2474
	printf(" -----------------------------------------------------------------------------------------------------------------\n");
2475
	printf("  TOTAL:                |%11.3f ms |%9" PRIu64 " |\n",
2476
		(double)sched->all_runtime / NSEC_PER_MSEC, sched->all_count);
2477 2478 2479

	printf(" ---------------------------------------------------\n");

2480
	print_bad_events(sched);
2481 2482
	printf("\n");

2483
	return 0;
2484 2485
}

2486 2487
static int setup_map_cpus(struct perf_sched *sched)
{
2488 2489
	struct cpu_map *map;

2490 2491 2492 2493
	sched->max_cpu  = sysconf(_SC_NPROCESSORS_CONF);

	if (sched->map.comp) {
		sched->map.comp_cpus = zalloc(sched->max_cpu * sizeof(int));
J
Jiri Olsa 已提交
2494 2495
		if (!sched->map.comp_cpus)
			return -1;
2496 2497
	}

2498 2499 2500 2501 2502 2503 2504 2505 2506 2507
	if (!sched->map.cpus_str)
		return 0;

	map = cpu_map__new(sched->map.cpus_str);
	if (!map) {
		pr_err("failed to get cpus map from %s\n", sched->map.cpus_str);
		return -1;
	}

	sched->map.cpus = map;
2508 2509 2510
	return 0;
}

J
Jiri Olsa 已提交
2511 2512 2513 2514 2515 2516 2517 2518 2519 2520 2521 2522 2523 2524 2525 2526 2527
static int setup_color_pids(struct perf_sched *sched)
{
	struct thread_map *map;

	if (!sched->map.color_pids_str)
		return 0;

	map = thread_map__new_by_tid_str(sched->map.color_pids_str);
	if (!map) {
		pr_err("failed to get thread map from %s\n", sched->map.color_pids_str);
		return -1;
	}

	sched->map.color_pids = map;
	return 0;
}

J
Jiri Olsa 已提交
2528 2529 2530 2531 2532 2533 2534 2535 2536 2537 2538 2539 2540 2541 2542 2543 2544
static int setup_color_cpus(struct perf_sched *sched)
{
	struct cpu_map *map;

	if (!sched->map.color_cpus_str)
		return 0;

	map = cpu_map__new(sched->map.color_cpus_str);
	if (!map) {
		pr_err("failed to get thread map from %s\n", sched->map.color_cpus_str);
		return -1;
	}

	sched->map.color_cpus = map;
	return 0;
}

2545
static int perf_sched__map(struct perf_sched *sched)
2546
{
2547 2548
	if (setup_map_cpus(sched))
		return -1;
2549

J
Jiri Olsa 已提交
2550 2551 2552
	if (setup_color_pids(sched))
		return -1;

J
Jiri Olsa 已提交
2553 2554 2555
	if (setup_color_cpus(sched))
		return -1;

2556
	setup_pager();
2557
	if (perf_sched__read_events(sched))
2558
		return -1;
2559
	print_bad_events(sched);
2560
	return 0;
2561 2562
}

2563
static int perf_sched__replay(struct perf_sched *sched)
2564 2565 2566
{
	unsigned long i;

2567 2568
	calibrate_run_measurement_overhead(sched);
	calibrate_sleep_measurement_overhead(sched);
2569

2570
	test_calibrations(sched);
2571

2572
	if (perf_sched__read_events(sched))
2573
		return -1;
2574

2575 2576 2577
	printf("nr_run_events:        %ld\n", sched->nr_run_events);
	printf("nr_sleep_events:      %ld\n", sched->nr_sleep_events);
	printf("nr_wakeup_events:     %ld\n", sched->nr_wakeup_events);
2578

2579 2580 2581 2582 2583
	if (sched->targetless_wakeups)
		printf("target-less wakeups:  %ld\n", sched->targetless_wakeups);
	if (sched->multitarget_wakeups)
		printf("multi-target wakeups: %ld\n", sched->multitarget_wakeups);
	if (sched->nr_run_events_optimized)
2584
		printf("run atoms optimized: %ld\n",
2585
			sched->nr_run_events_optimized);
2586

2587 2588
	print_task_traces(sched);
	add_cross_task_wakeups(sched);
2589

2590
	create_tasks(sched);
2591
	printf("------------------------------------------------------------\n");
2592 2593
	for (i = 0; i < sched->replay_repeat; i++)
		run_one_test(sched);
2594 2595

	return 0;
2596 2597
}

2598 2599
static void setup_sorting(struct perf_sched *sched, const struct option *options,
			  const char * const usage_msg[])
2600
{
2601
	char *tmp, *tok, *str = strdup(sched->sort_order);
2602 2603 2604

	for (tok = strtok_r(str, ", ", &tmp);
			tok; tok = strtok_r(NULL, ", ", &tmp)) {
2605
		if (sort_dimension__add(tok, &sched->sort_list) < 0) {
2606 2607
			usage_with_options_msg(usage_msg, options,
					"Unknown --sort key: `%s'", tok);
2608 2609 2610 2611 2612
		}
	}

	free(str);

2613
	sort_dimension__add("pid", &sched->cmp_pid);
2614 2615
}

2616 2617 2618 2619
static int __cmd_record(int argc, const char **argv)
{
	unsigned int rec_argc, i, j;
	const char **rec_argv;
2620 2621 2622 2623 2624 2625 2626 2627 2628 2629 2630 2631 2632
	const char * const record_args[] = {
		"record",
		"-a",
		"-R",
		"-m", "1024",
		"-c", "1",
		"-e", "sched:sched_switch",
		"-e", "sched:sched_stat_wait",
		"-e", "sched:sched_stat_sleep",
		"-e", "sched:sched_stat_iowait",
		"-e", "sched:sched_stat_runtime",
		"-e", "sched:sched_process_fork",
		"-e", "sched:sched_wakeup",
2633
		"-e", "sched:sched_wakeup_new",
2634 2635
		"-e", "sched:sched_migrate_task",
	};
2636 2637 2638 2639

	rec_argc = ARRAY_SIZE(record_args) + argc - 1;
	rec_argv = calloc(rec_argc + 1, sizeof(char *));

2640
	if (rec_argv == NULL)
2641 2642
		return -ENOMEM;

2643 2644 2645 2646 2647 2648 2649 2650 2651 2652 2653
	for (i = 0; i < ARRAY_SIZE(record_args); i++)
		rec_argv[i] = strdup(record_args[i]);

	for (j = 1; j < (unsigned int)argc; j++, i++)
		rec_argv[i] = argv[j];

	BUG_ON(i != rec_argc);

	return cmd_record(i, rec_argv, NULL);
}

2654
int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
I
Ingo Molnar 已提交
2655
{
2656 2657 2658 2659 2660 2661 2662
	const char default_sort_order[] = "avg, max, switch, runtime";
	struct perf_sched sched = {
		.tool = {
			.sample		 = perf_sched__process_tracepoint_sample,
			.comm		 = perf_event__process_comm,
			.lost		 = perf_event__process_lost,
			.fork		 = perf_sched__process_fork_event,
2663
			.ordered_events = true,
2664 2665 2666 2667 2668 2669 2670 2671 2672 2673
		},
		.cmp_pid	      = LIST_HEAD_INIT(sched.cmp_pid),
		.sort_list	      = LIST_HEAD_INIT(sched.sort_list),
		.start_work_mutex     = PTHREAD_MUTEX_INITIALIZER,
		.work_done_wait_mutex = PTHREAD_MUTEX_INITIALIZER,
		.sort_order	      = default_sort_order,
		.replay_repeat	      = 10,
		.profile_cpu	      = -1,
		.next_shortname1      = 'A',
		.next_shortname2      = '0',
2674
		.skip_merge           = 0,
2675
	};
2676 2677 2678 2679 2680 2681 2682 2683 2684
	const struct option sched_options[] = {
	OPT_STRING('i', "input", &input_name, "file",
		    "input file name"),
	OPT_INCR('v', "verbose", &verbose,
		    "be more verbose (show symbol address, etc)"),
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
		    "dump raw trace in ASCII"),
	OPT_END()
	};
2685 2686 2687 2688 2689 2690 2691
	const struct option latency_options[] = {
	OPT_STRING('s', "sort", &sched.sort_order, "key[,key2...]",
		   "sort by key(s): runtime, switch, avg, max"),
	OPT_INTEGER('C', "CPU", &sched.profile_cpu,
		    "CPU to profile on"),
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
		    "dump raw trace in ASCII"),
2692 2693
	OPT_BOOLEAN('p', "pids", &sched.skip_merge,
		    "latency stats per pid instead of per comm"),
2694
	OPT_PARENT(sched_options)
2695 2696 2697 2698 2699 2700
	};
	const struct option replay_options[] = {
	OPT_UINTEGER('r', "repeat", &sched.replay_repeat,
		     "repeat the workload replay N times (-1: infinite)"),
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
		    "dump raw trace in ASCII"),
2701
	OPT_BOOLEAN('f', "force", &sched.force, "don't complain, do it"),
2702
	OPT_PARENT(sched_options)
2703
	};
2704 2705 2706
	const struct option map_options[] = {
	OPT_BOOLEAN(0, "compact", &sched.map.comp,
		    "map output in compact mode"),
J
Jiri Olsa 已提交
2707 2708
	OPT_STRING(0, "color-pids", &sched.map.color_pids_str, "pids",
		   "highlight given pids in map"),
J
Jiri Olsa 已提交
2709 2710
	OPT_STRING(0, "color-cpus", &sched.map.color_cpus_str, "cpus",
                    "highlight given CPUs in map"),
2711 2712
	OPT_STRING(0, "cpus", &sched.map.cpus_str, "cpus",
                    "display given CPUs in map"),
2713
	OPT_PARENT(sched_options)
2714
	};
2715 2716 2717 2718 2719 2720 2721
	const struct option timehist_options[] = {
	OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name,
		   "file", "vmlinux pathname"),
	OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name,
		   "file", "kallsyms pathname"),
	OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
		    "Look for files with symbols relative to this directory"),
2722 2723 2724 2725
	OPT_BOOLEAN('s', "summary", &sched.summary_only,
		    "Show only syscall summary with statistics"),
	OPT_BOOLEAN('S', "with-summary", &sched.summary,
		    "Show all syscalls and summary with statistics"),
2726 2727 2728
	OPT_PARENT(sched_options)
	};

2729 2730 2731 2732 2733 2734 2735 2736
	const char * const latency_usage[] = {
		"perf sched latency [<options>]",
		NULL
	};
	const char * const replay_usage[] = {
		"perf sched replay [<options>]",
		NULL
	};
2737 2738 2739 2740
	const char * const map_usage[] = {
		"perf sched map [<options>]",
		NULL
	};
2741 2742 2743 2744
	const char * const timehist_usage[] = {
		"perf sched timehist [<options>]",
		NULL
	};
2745
	const char *const sched_subcommands[] = { "record", "latency", "map",
2746 2747
						  "replay", "script",
						  "timehist", NULL };
2748 2749
	const char *sched_usage[] = {
		NULL,
2750 2751 2752 2753 2754 2755 2756 2757 2758 2759 2760 2761 2762 2763 2764 2765
		NULL
	};
	struct trace_sched_handler lat_ops  = {
		.wakeup_event	    = latency_wakeup_event,
		.switch_event	    = latency_switch_event,
		.runtime_event	    = latency_runtime_event,
		.migrate_task_event = latency_migrate_task_event,
	};
	struct trace_sched_handler map_ops  = {
		.switch_event	    = map_switch_event,
	};
	struct trace_sched_handler replay_ops  = {
		.wakeup_event	    = replay_wakeup_event,
		.switch_event	    = replay_switch_event,
		.fork_event	    = replay_fork_event,
	};
A
Adrian Hunter 已提交
2766 2767 2768 2769
	unsigned int i;

	for (i = 0; i < ARRAY_SIZE(sched.curr_pid); i++)
		sched.curr_pid[i] = -1;
2770

2771 2772
	argc = parse_options_subcommand(argc, argv, sched_options, sched_subcommands,
					sched_usage, PARSE_OPT_STOP_AT_NON_OPTION);
2773 2774
	if (!argc)
		usage_with_options(sched_usage, sched_options);
I
Ingo Molnar 已提交
2775

2776
	/*
2777
	 * Aliased to 'perf script' for now:
2778
	 */
2779 2780
	if (!strcmp(argv[0], "script"))
		return cmd_script(argc, argv, prefix);
2781

2782 2783 2784
	if (!strncmp(argv[0], "rec", 3)) {
		return __cmd_record(argc, argv);
	} else if (!strncmp(argv[0], "lat", 3)) {
2785
		sched.tp_handler = &lat_ops;
2786 2787 2788 2789 2790
		if (argc > 1) {
			argc = parse_options(argc, argv, latency_options, latency_usage, 0);
			if (argc)
				usage_with_options(latency_usage, latency_options);
		}
2791 2792
		setup_sorting(&sched, latency_options, latency_usage);
		return perf_sched__lat(&sched);
2793
	} else if (!strcmp(argv[0], "map")) {
2794
		if (argc) {
J
Jiri Olsa 已提交
2795
			argc = parse_options(argc, argv, map_options, map_usage, 0);
2796 2797 2798
			if (argc)
				usage_with_options(map_usage, map_options);
		}
2799 2800 2801
		sched.tp_handler = &map_ops;
		setup_sorting(&sched, latency_options, latency_usage);
		return perf_sched__map(&sched);
2802
	} else if (!strncmp(argv[0], "rep", 3)) {
2803
		sched.tp_handler = &replay_ops;
2804 2805 2806 2807 2808
		if (argc) {
			argc = parse_options(argc, argv, replay_options, replay_usage, 0);
			if (argc)
				usage_with_options(replay_usage, replay_options);
		}
2809
		return perf_sched__replay(&sched);
2810 2811 2812 2813 2814 2815 2816 2817
	} else if (!strcmp(argv[0], "timehist")) {
		if (argc) {
			argc = parse_options(argc, argv, timehist_options,
					     timehist_usage, 0);
			if (argc)
				usage_with_options(timehist_usage, timehist_options);
		}
		return perf_sched__timehist(&sched);
2818 2819 2820 2821
	} else {
		usage_with_options(sched_usage, sched_options);
	}

I
Ingo Molnar 已提交
2822
	return 0;
I
Ingo Molnar 已提交
2823
}