builtin-trace.c 21.6 KB
Newer Older
1
#include <traceevent/event-parse.h>
A
Arnaldo Carvalho de Melo 已提交
2
#include "builtin.h"
3
#include "util/color.h"
4
#include "util/debug.h"
A
Arnaldo Carvalho de Melo 已提交
5
#include "util/evlist.h"
6 7
#include "util/machine.h"
#include "util/thread.h"
A
Arnaldo Carvalho de Melo 已提交
8
#include "util/parse-options.h"
9
#include "util/strlist.h"
A
Arnaldo Carvalho de Melo 已提交
10 11 12 13 14
#include "util/thread_map.h"

#include <libaudit.h>
#include <stdlib.h>

15 16 17 18 19
static size_t syscall_arg__scnprintf_hex(char *bf, size_t size, unsigned long arg)
{
	return scnprintf(bf, size, "%#lx", arg);
}

A
Arnaldo Carvalho de Melo 已提交
20 21
static struct syscall_fmt {
	const char *name;
22
	const char *alias;
A
Arnaldo Carvalho de Melo 已提交
23 24
	bool	   errmsg;
	bool	   timeout;
25
	bool	   hexret;
A
Arnaldo Carvalho de Melo 已提交
26
} syscall_fmts[] = {
27
	{ .name	    = "access",	    .errmsg = true, },
28
	{ .name	    = "arch_prctl", .errmsg = true, .alias = "prctl", },
29 30
	{ .name	    = "brk",	    .hexret = true, },
	{ .name	    = "mmap",	    .hexret = true, },
31
	{ .name	    = "connect",    .errmsg = true, },
32 33 34
	{ .name	    = "fstat",	    .errmsg = true, .alias = "newfstat", },
	{ .name	    = "fstatat",    .errmsg = true, .alias = "newfstatat", },
	{ .name	    = "futex",	    .errmsg = true, },
35 36
	{ .name	    = "mmap",	    .hexret = true, },
	{ .name	    = "mremap",	    .hexret = true, },
37
	{ .name	    = "open",	    .errmsg = true, },
38 39 40 41 42
	{ .name	    = "poll",	    .errmsg = true, .timeout = true, },
	{ .name	    = "ppoll",	    .errmsg = true, .timeout = true, },
	{ .name	    = "read",	    .errmsg = true, },
	{ .name	    = "recvfrom",   .errmsg = true, },
	{ .name	    = "select",	    .errmsg = true, .timeout = true, },
43
	{ .name	    = "socket",	    .errmsg = true, },
44
	{ .name	    = "stat",	    .errmsg = true, .alias = "newstat", },
A
Arnaldo Carvalho de Melo 已提交
45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61
};

static int syscall_fmt__cmp(const void *name, const void *fmtp)
{
	const struct syscall_fmt *fmt = fmtp;
	return strcmp(name, fmt->name);
}

static struct syscall_fmt *syscall_fmt__find(const char *name)
{
	const int nmemb = ARRAY_SIZE(syscall_fmts);
	return bsearch(name, syscall_fmts, nmemb, sizeof(struct syscall_fmt), syscall_fmt__cmp);
}

struct syscall {
	struct event_format *tp_format;
	const char	    *name;
62
	bool		    filtered;
A
Arnaldo Carvalho de Melo 已提交
63
	struct syscall_fmt  *fmt;
64
	size_t		    (**arg_scnprintf)(char *bf, size_t size, unsigned long arg);
A
Arnaldo Carvalho de Melo 已提交
65 66
};

67 68 69 70 71 72 73 74 75 76 77
static size_t fprintf_duration(unsigned long t, FILE *fp)
{
	double duration = (double)t / NSEC_PER_MSEC;
	size_t printed = fprintf(fp, "(");

	if (duration >= 1.0)
		printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration);
	else if (duration >= 0.01)
		printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration);
	else
		printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration);
78
	return printed + fprintf(fp, "): ");
79 80
}

81 82 83 84
struct thread_trace {
	u64		  entry_time;
	u64		  exit_time;
	bool		  entry_pending;
85
	unsigned long	  nr_events;
86
	char		  *entry_str;
87
	double		  runtime_ms;
88 89 90 91 92 93 94
};

static struct thread_trace *thread_trace__new(void)
{
	return zalloc(sizeof(struct thread_trace));
}

95
static struct thread_trace *thread__trace(struct thread *thread, FILE *fp)
96
{
97 98
	struct thread_trace *ttrace;

99 100 101 102 103
	if (thread == NULL)
		goto fail;

	if (thread->priv == NULL)
		thread->priv = thread_trace__new();
104
		
105 106 107
	if (thread->priv == NULL)
		goto fail;

108 109 110 111
	ttrace = thread->priv;
	++ttrace->nr_events;

	return ttrace;
112
fail:
113
	color_fprintf(fp, PERF_COLOR_RED,
114 115 116 117
		      "WARNING: not enough memory, dropping samples!\n");
	return NULL;
}

A
Arnaldo Carvalho de Melo 已提交
118
struct trace {
119
	struct perf_tool	tool;
A
Arnaldo Carvalho de Melo 已提交
120 121 122 123 124 125
	int			audit_machine;
	struct {
		int		max;
		struct syscall  *table;
	} syscalls;
	struct perf_record_opts opts;
126 127
	struct machine		host;
	u64			base_time;
128
	FILE			*output;
129
	unsigned long		nr_events;
130 131
	struct strlist		*ev_qualifier;
	bool			not_ev_qualifier;
132
	bool			sched;
133
	bool			multiple_threads;
134
	double			duration_filter;
135
	double			runtime_ms;
A
Arnaldo Carvalho de Melo 已提交
136 137
};

138 139 140 141 142
static bool trace__filter_duration(struct trace *trace, double t)
{
	return t < (trace->duration_filter * NSEC_PER_MSEC);
}

143 144 145 146
static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
{
	double ts = (double)(tstamp - trace->base_time) / NSEC_PER_MSEC;

147
	return fprintf(fp, "%10.3f ", ts);
148 149
}

150 151 152 153 154 155 156
static bool done = false;

static void sig_handler(int sig __maybe_unused)
{
	done = true;
}

157
static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
158
					u64 duration, u64 tstamp, FILE *fp)
159 160
{
	size_t printed = trace__fprintf_tstamp(trace, tstamp, fp);
161
	printed += fprintf_duration(duration, fp);
162 163

	if (trace->multiple_threads)
164
		printed += fprintf(fp, "%d ", thread->tid);
165 166 167 168

	return printed;
}

169 170
static int trace__process_event(struct trace *trace, struct machine *machine,
				union perf_event *event)
171 172 173 174 175
{
	int ret = 0;

	switch (event->header.type) {
	case PERF_RECORD_LOST:
176
		color_fprintf(trace->output, PERF_COLOR_RED,
177 178 179 180 181 182 183 184 185 186
			      "LOST %" PRIu64 " events!\n", event->lost.lost);
		ret = machine__process_lost_event(machine, event);
	default:
		ret = machine__process_event(machine, event);
		break;
	}

	return ret;
}

187
static int trace__tool_process(struct perf_tool *tool,
188 189 190 191
			       union perf_event *event,
			       struct perf_sample *sample __maybe_unused,
			       struct machine *machine)
{
192 193
	struct trace *trace = container_of(tool, struct trace, tool);
	return trace__process_event(trace, machine, event);
194 195 196 197 198 199 200 201 202 203 204 205 206
}

static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
{
	int err = symbol__init();

	if (err)
		return err;

	machine__init(&trace->host, "", HOST_KERNEL_ID);
	machine__create_kernel_maps(&trace->host);

	if (perf_target__has_task(&trace->opts.target)) {
207
		err = perf_event__synthesize_thread_map(&trace->tool, evlist->threads,
208 209 210
							trace__tool_process,
							&trace->host);
	} else {
211
		err = perf_event__synthesize_threads(&trace->tool, trace__tool_process,
212 213 214 215 216 217 218 219 220
						     &trace->host);
	}

	if (err)
		symbol__exit();

	return err;
}

221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238
static int syscall__set_arg_fmts(struct syscall *sc)
{
	struct format_field *field;
	int idx = 0;

	sc->arg_scnprintf = calloc(sc->tp_format->format.nr_fields - 1, sizeof(void *));
	if (sc->arg_scnprintf == NULL)
		return -1;

	for (field = sc->tp_format->format.fields->next; field; field = field->next) {
		if (field->flags & FIELD_IS_POINTER)
			sc->arg_scnprintf[idx] = syscall_arg__scnprintf_hex;
		++idx;
	}

	return 0;
}

A
Arnaldo Carvalho de Melo 已提交
239 240 241 242
static int trace__read_syscall_info(struct trace *trace, int id)
{
	char tp_name[128];
	struct syscall *sc;
243 244 245 246
	const char *name = audit_syscall_to_name(id, trace->audit_machine);

	if (name == NULL)
		return -1;
A
Arnaldo Carvalho de Melo 已提交
247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265

	if (id > trace->syscalls.max) {
		struct syscall *nsyscalls = realloc(trace->syscalls.table, (id + 1) * sizeof(*sc));

		if (nsyscalls == NULL)
			return -1;

		if (trace->syscalls.max != -1) {
			memset(nsyscalls + trace->syscalls.max + 1, 0,
			       (id - trace->syscalls.max) * sizeof(*sc));
		} else {
			memset(nsyscalls, 0, (id + 1) * sizeof(*sc));
		}

		trace->syscalls.table = nsyscalls;
		trace->syscalls.max   = id;
	}

	sc = trace->syscalls.table + id;
266
	sc->name = name;
267

268 269 270 271 272 273 274 275 276 277 278
	if (trace->ev_qualifier) {
		bool in = strlist__find(trace->ev_qualifier, name) != NULL;

		if (!(in ^ trace->not_ev_qualifier)) {
			sc->filtered = true;
			/*
			 * No need to do read tracepoint information since this will be
			 * filtered out.
			 */
			return 0;
		}
279 280
	}

281
	sc->fmt  = syscall_fmt__find(sc->name);
A
Arnaldo Carvalho de Melo 已提交
282

283
	snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name);
A
Arnaldo Carvalho de Melo 已提交
284
	sc->tp_format = event_format__new("syscalls", tp_name);
285 286 287 288 289

	if (sc->tp_format == NULL && sc->fmt && sc->fmt->alias) {
		snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->fmt->alias);
		sc->tp_format = event_format__new("syscalls", tp_name);
	}
A
Arnaldo Carvalho de Melo 已提交
290

291 292 293 294
	if (sc->tp_format == NULL)
		return -1;

	return syscall__set_arg_fmts(sc);
A
Arnaldo Carvalho de Melo 已提交
295 296
}

297 298
static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
				      unsigned long *args)
A
Arnaldo Carvalho de Melo 已提交
299 300 301 302 303 304 305 306
{
	int i = 0;
	size_t printed = 0;

	if (sc->tp_format != NULL) {
		struct format_field *field;

		for (field = sc->tp_format->format.fields->next; field; field = field->next) {
307
			printed += scnprintf(bf + printed, size - printed,
308 309 310 311 312 313 314 315
					     "%s%s: ", printed ? ", " : "", field->name);

			if (sc->arg_scnprintf && sc->arg_scnprintf[i])
				printed += sc->arg_scnprintf[i](bf + printed, size - printed, args[i]);
			else
				printed += scnprintf(bf + printed, size - printed,
						     "%ld", args[i]);
                       ++i;
A
Arnaldo Carvalho de Melo 已提交
316 317 318
		}
	} else {
		while (i < 6) {
319 320 321
			printed += scnprintf(bf + printed, size - printed,
					     "%sarg%d: %ld",
					     printed ? ", " : "", i, args[i]);
A
Arnaldo Carvalho de Melo 已提交
322 323 324 325 326 327 328
			++i;
		}
	}

	return printed;
}

329 330 331 332 333 334 335 336 337 338
typedef int (*tracepoint_handler)(struct trace *trace, struct perf_evsel *evsel,
				  struct perf_sample *sample);

static struct syscall *trace__syscall_info(struct trace *trace,
					   struct perf_evsel *evsel,
					   struct perf_sample *sample)
{
	int id = perf_evsel__intval(evsel, sample, "id");

	if (id < 0) {
339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354

		/*
		 * XXX: Noticed on x86_64, reproduced as far back as 3.0.36, haven't tried
		 * before that, leaving at a higher verbosity level till that is
		 * explained. Reproduced with plain ftrace with:
		 *
		 * echo 1 > /t/events/raw_syscalls/sys_exit/enable
		 * grep "NR -1 " /t/trace_pipe
		 *
		 * After generating some load on the machine.
 		 */
		if (verbose > 1) {
			static u64 n;
			fprintf(trace->output, "Invalid syscall %d id, skipping (%s, %" PRIu64 ") ...\n",
				id, perf_evsel__name(evsel), ++n);
		}
355 356 357 358 359 360 361 362 363 364 365 366 367
		return NULL;
	}

	if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL) &&
	    trace__read_syscall_info(trace, id))
		goto out_cant_read;

	if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL))
		goto out_cant_read;

	return &trace->syscalls.table[id];

out_cant_read:
368 369 370 371 372 373
	if (verbose) {
		fprintf(trace->output, "Problems reading syscall %d", id);
		if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL)
			fprintf(trace->output, "(%s)", trace->syscalls.table[id].name);
		fputs(" information\n", trace->output);
	}
374 375 376 377 378 379
	return NULL;
}

static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
			    struct perf_sample *sample)
{
380
	char *msg;
381
	void *args;
382
	size_t printed = 0;
383
	struct thread *thread;
384
	struct syscall *sc = trace__syscall_info(trace, evsel, sample);
385 386 387 388
	struct thread_trace *ttrace;

	if (sc == NULL)
		return -1;
389

390 391 392 393
	if (sc->filtered)
		return 0;

	thread = machine__findnew_thread(&trace->host, sample->tid);
394
	ttrace = thread__trace(thread, trace->output);
395
	if (ttrace == NULL)
396 397 398 399
		return -1;

	args = perf_evsel__rawptr(evsel, sample, "args");
	if (args == NULL) {
400
		fprintf(trace->output, "Problems reading syscall arguments\n");
401 402 403
		return -1;
	}

404 405 406 407 408 409 410 411 412 413 414 415 416 417 418
	ttrace = thread->priv;

	if (ttrace->entry_str == NULL) {
		ttrace->entry_str = malloc(1024);
		if (!ttrace->entry_str)
			return -1;
	}

	ttrace->entry_time = sample->time;
	msg = ttrace->entry_str;
	printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);

	printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed,  args);

	if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
419
		if (!trace->duration_filter) {
420 421
			trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output);
			fprintf(trace->output, "%-70s\n", ttrace->entry_str);
422
		}
423 424
	} else
		ttrace->entry_pending = true;
425 426 427 428 429 430 431 432

	return 0;
}

static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
			   struct perf_sample *sample)
{
	int ret;
433
	u64 duration = 0;
434
	struct thread *thread;
435
	struct syscall *sc = trace__syscall_info(trace, evsel, sample);
436 437 438 439
	struct thread_trace *ttrace;

	if (sc == NULL)
		return -1;
440

441 442 443 444
	if (sc->filtered)
		return 0;

	thread = machine__findnew_thread(&trace->host, sample->tid);
445
	ttrace = thread__trace(thread, trace->output);
446
	if (ttrace == NULL)
447 448 449 450
		return -1;

	ret = perf_evsel__intval(evsel, sample, "ret");

451 452 453 454
	ttrace = thread->priv;

	ttrace->exit_time = sample->time;

455
	if (ttrace->entry_time) {
456
		duration = sample->time - ttrace->entry_time;
457 458 459 460
		if (trace__filter_duration(trace, duration))
			goto out;
	} else if (trace->duration_filter)
		goto out;
461

462
	trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output);
463 464

	if (ttrace->entry_pending) {
465
		fprintf(trace->output, "%-70s", ttrace->entry_str);
466
	} else {
467 468 469
		fprintf(trace->output, " ... [");
		color_fprintf(trace->output, PERF_COLOR_YELLOW, "continued");
		fprintf(trace->output, "]: %s()", sc->name);
470 471
	}

472 473 474 475
	if (sc->fmt == NULL) {
signed_print:
		fprintf(trace->output, ") = %d", ret);
	} else if (ret < 0 && sc->fmt->errmsg) {
476 477 478 479
		char bf[256];
		const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
			   *e = audit_errno_to_name(-ret);

480
		fprintf(trace->output, ") = -1 %s %s", e, emsg);
481
	} else if (ret == 0 && sc->fmt->timeout)
482
		fprintf(trace->output, ") = 0 Timeout");
483 484
	else if (sc->fmt->hexret)
		fprintf(trace->output, ") = %#x", ret);
485
	else
486
		goto signed_print;
487

488
	fputc('\n', trace->output);
489
out:
490 491
	ttrace->entry_pending = false;

492 493 494
	return 0;
}

495 496 497 498 499 500
static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel,
				     struct perf_sample *sample)
{
        u64 runtime = perf_evsel__intval(evsel, sample, "runtime");
	double runtime_ms = (double)runtime / NSEC_PER_MSEC;
	struct thread *thread = machine__findnew_thread(&trace->host, sample->tid);
501
	struct thread_trace *ttrace = thread__trace(thread, trace->output);
502 503 504 505 506 507 508 509 510

	if (ttrace == NULL)
		goto out_dump;

	ttrace->runtime_ms += runtime_ms;
	trace->runtime_ms += runtime_ms;
	return 0;

out_dump:
511
	fprintf(trace->output, "%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n",
512 513 514 515 516 517 518 519
	       evsel->name,
	       perf_evsel__strval(evsel, sample, "comm"),
	       (pid_t)perf_evsel__intval(evsel, sample, "pid"),
	       runtime,
	       perf_evsel__intval(evsel, sample, "vruntime"));
	return 0;
}

520
static int trace__run(struct trace *trace, int argc, const char **argv)
A
Arnaldo Carvalho de Melo 已提交
521
{
522
	struct perf_evlist *evlist = perf_evlist__new();
523
	struct perf_evsel *evsel;
524 525
	int err = -1, i;
	unsigned long before;
526
	const bool forks = argc > 0;
A
Arnaldo Carvalho de Melo 已提交
527 528

	if (evlist == NULL) {
529
		fprintf(trace->output, "Not enough memory to run!\n");
A
Arnaldo Carvalho de Melo 已提交
530 531 532
		goto out;
	}

533 534
	if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) ||
	    perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) {
535
		fprintf(trace->output, "Couldn't read the raw_syscalls tracepoints information!\n");
A
Arnaldo Carvalho de Melo 已提交
536 537 538
		goto out_delete_evlist;
	}

539 540 541
	if (trace->sched &&
	    perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime",
				   trace__sched_stat_runtime)) {
542
		fprintf(trace->output, "Couldn't read the sched_stat_runtime tracepoint information!\n");
543 544 545
		goto out_delete_evlist;
	}

A
Arnaldo Carvalho de Melo 已提交
546 547
	err = perf_evlist__create_maps(evlist, &trace->opts.target);
	if (err < 0) {
548
		fprintf(trace->output, "Problems parsing the target to trace, check your options!\n");
A
Arnaldo Carvalho de Melo 已提交
549 550 551
		goto out_delete_evlist;
	}

552 553
	err = trace__symbols_init(trace, evlist);
	if (err < 0) {
554
		fprintf(trace->output, "Problems initializing symbol libraries!\n");
555
		goto out_delete_maps;
556 557
	}

558
	perf_evlist__config(evlist, &trace->opts);
A
Arnaldo Carvalho de Melo 已提交
559

560 561 562 563
	signal(SIGCHLD, sig_handler);
	signal(SIGINT, sig_handler);

	if (forks) {
564
		err = perf_evlist__prepare_workload(evlist, &trace->opts.target,
565
						    argv, false, false);
566
		if (err < 0) {
567
			fprintf(trace->output, "Couldn't run the workload!\n");
568
			goto out_delete_maps;
569 570 571
		}
	}

A
Arnaldo Carvalho de Melo 已提交
572 573
	err = perf_evlist__open(evlist);
	if (err < 0) {
574
		fprintf(trace->output, "Couldn't create the events: %s\n", strerror(errno));
575
		goto out_delete_maps;
A
Arnaldo Carvalho de Melo 已提交
576 577 578 579
	}

	err = perf_evlist__mmap(evlist, UINT_MAX, false);
	if (err < 0) {
580
		fprintf(trace->output, "Couldn't mmap the events: %s\n", strerror(errno));
581
		goto out_close_evlist;
A
Arnaldo Carvalho de Melo 已提交
582 583 584
	}

	perf_evlist__enable(evlist);
585 586 587 588

	if (forks)
		perf_evlist__start_workload(evlist);

589
	trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1;
A
Arnaldo Carvalho de Melo 已提交
590
again:
591
	before = trace->nr_events;
A
Arnaldo Carvalho de Melo 已提交
592 593 594 595 596 597

	for (i = 0; i < evlist->nr_mmaps; i++) {
		union perf_event *event;

		while ((event = perf_evlist__mmap_read(evlist, i)) != NULL) {
			const u32 type = event->header.type;
598
			tracepoint_handler handler;
A
Arnaldo Carvalho de Melo 已提交
599 600
			struct perf_sample sample;

601
			++trace->nr_events;
A
Arnaldo Carvalho de Melo 已提交
602 603 604

			err = perf_evlist__parse_sample(evlist, event, &sample);
			if (err) {
605
				fprintf(trace->output, "Can't parse sample, err = %d, skipping...\n", err);
A
Arnaldo Carvalho de Melo 已提交
606 607 608
				continue;
			}

609 610 611 612
			if (trace->base_time == 0)
				trace->base_time = sample.time;

			if (type != PERF_RECORD_SAMPLE) {
613
				trace__process_event(trace, &trace->host, event);
614 615 616
				continue;
			}

A
Arnaldo Carvalho de Melo 已提交
617 618
			evsel = perf_evlist__id2evsel(evlist, sample.id);
			if (evsel == NULL) {
619
				fprintf(trace->output, "Unknown tp ID %" PRIu64 ", skipping...\n", sample.id);
A
Arnaldo Carvalho de Melo 已提交
620 621 622
				continue;
			}

623
			if (sample.raw_data == NULL) {
624
				fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
625 626 627 628 629
				       perf_evsel__name(evsel), sample.tid,
				       sample.cpu, sample.raw_size);
				continue;
			}

630 631
			handler = evsel->handler.func;
			handler(trace, evsel, &sample);
A
Arnaldo Carvalho de Melo 已提交
632 633 634
		}
	}

635
	if (trace->nr_events == before) {
636
		if (done)
637
			goto out_unmap_evlist;
638

A
Arnaldo Carvalho de Melo 已提交
639
		poll(evlist->pollfd, evlist->nr_fds, -1);
640 641 642 643
	}

	if (done)
		perf_evlist__disable(evlist);
A
Arnaldo Carvalho de Melo 已提交
644 645 646

	goto again;

647 648 649 650 651 652
out_unmap_evlist:
	perf_evlist__munmap(evlist);
out_close_evlist:
	perf_evlist__close(evlist);
out_delete_maps:
	perf_evlist__delete_maps(evlist);
A
Arnaldo Carvalho de Melo 已提交
653 654 655 656 657 658
out_delete_evlist:
	perf_evlist__delete(evlist);
out:
	return err;
}

659 660 661 662 663 664 665 666 667 668 669 670 671 672 673 674 675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695
static size_t trace__fprintf_threads_header(FILE *fp)
{
	size_t printed;

	printed  = fprintf(fp, "\n _____________________________________________________________________\n");
	printed += fprintf(fp," __)    Summary of events    (__\n\n");
	printed += fprintf(fp,"              [ task - pid ]     [ events ] [ ratio ]  [ runtime ]\n");
	printed += fprintf(fp," _____________________________________________________________________\n\n");

	return printed;
}

static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
{
	size_t printed = trace__fprintf_threads_header(fp);
	struct rb_node *nd;

	for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) {
		struct thread *thread = rb_entry(nd, struct thread, rb_node);
		struct thread_trace *ttrace = thread->priv;
		const char *color;
		double ratio;

		if (ttrace == NULL)
			continue;

		ratio = (double)ttrace->nr_events / trace->nr_events * 100.0;

		color = PERF_COLOR_NORMAL;
		if (ratio > 50.0)
			color = PERF_COLOR_RED;
		else if (ratio > 25.0)
			color = PERF_COLOR_GREEN;
		else if (ratio > 5.0)
			color = PERF_COLOR_YELLOW;

		printed += color_fprintf(fp, color, "%20s", thread->comm);
696
		printed += fprintf(fp, " - %-5d :%11lu   [", thread->tid, ttrace->nr_events);
697 698 699 700 701 702 703
		printed += color_fprintf(fp, color, "%5.1f%%", ratio);
		printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms);
	}

	return printed;
}

704 705 706 707 708 709 710 711 712
static int trace__set_duration(const struct option *opt, const char *str,
			       int unset __maybe_unused)
{
	struct trace *trace = opt->value;

	trace->duration_filter = atof(str);
	return 0;
}

713 714 715 716 717 718 719 720 721 722 723 724 725 726 727 728 729
static int trace__open_output(struct trace *trace, const char *filename)
{
	struct stat st;

	if (!stat(filename, &st) && st.st_size) {
		char oldname[PATH_MAX];

		scnprintf(oldname, sizeof(oldname), "%s.old", filename);
		unlink(oldname);
		rename(filename, oldname);
	}

	trace->output = fopen(filename, "w");

	return trace->output == NULL ? -errno : 0;
}

A
Arnaldo Carvalho de Melo 已提交
730 731 732
int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
{
	const char * const trace_usage[] = {
733 734
		"perf trace [<options>] [<command>]",
		"perf trace [<options>] -- <command> [<options>]",
A
Arnaldo Carvalho de Melo 已提交
735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751
		NULL
	};
	struct trace trace = {
		.audit_machine = audit_detect_machine(),
		.syscalls = {
			. max = -1,
		},
		.opts = {
			.target = {
				.uid	   = UINT_MAX,
				.uses_mmap = true,
			},
			.user_freq     = UINT_MAX,
			.user_interval = ULLONG_MAX,
			.no_delay      = true,
			.mmap_pages    = 1024,
		},
752
		.output = stdout,
A
Arnaldo Carvalho de Melo 已提交
753
	};
754
	const char *output_name = NULL;
755
	const char *ev_qualifier_str = NULL;
A
Arnaldo Carvalho de Melo 已提交
756
	const struct option trace_options[] = {
757 758
	OPT_STRING('e', "expr", &ev_qualifier_str, "expr",
		    "list of events to trace"),
759
	OPT_STRING('o', "output", &output_name, "file", "output file name"),
A
Arnaldo Carvalho de Melo 已提交
760 761
	OPT_STRING('p', "pid", &trace.opts.target.pid, "pid",
		    "trace events on existing process id"),
762
	OPT_STRING('t', "tid", &trace.opts.target.tid, "tid",
A
Arnaldo Carvalho de Melo 已提交
763
		    "trace events on existing thread id"),
764
	OPT_BOOLEAN('a', "all-cpus", &trace.opts.target.system_wide,
A
Arnaldo Carvalho de Melo 已提交
765
		    "system-wide collection from all CPUs"),
766
	OPT_STRING('C', "cpu", &trace.opts.target.cpu_list, "cpu",
A
Arnaldo Carvalho de Melo 已提交
767
		    "list of cpus to monitor"),
768
	OPT_BOOLEAN('i', "no-inherit", &trace.opts.no_inherit,
A
Arnaldo Carvalho de Melo 已提交
769
		    "child tasks do not inherit counters"),
770
	OPT_UINTEGER('m', "mmap-pages", &trace.opts.mmap_pages,
A
Arnaldo Carvalho de Melo 已提交
771
		     "number of mmap data pages"),
772
	OPT_STRING('u', "uid", &trace.opts.target.uid_str, "user",
A
Arnaldo Carvalho de Melo 已提交
773
		   "user to profile"),
774 775 776
	OPT_CALLBACK(0, "duration", &trace, "float",
		     "show only events with duration > N.M ms",
		     trace__set_duration),
777
	OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"),
778
	OPT_INCR('v', "verbose", &verbose, "be more verbose"),
A
Arnaldo Carvalho de Melo 已提交
779 780 781
	OPT_END()
	};
	int err;
782
	char bf[BUFSIZ];
A
Arnaldo Carvalho de Melo 已提交
783 784 785

	argc = parse_options(argc, argv, trace_options, trace_usage, 0);

786 787 788 789 790 791 792 793
	if (output_name != NULL) {
		err = trace__open_output(&trace, output_name);
		if (err < 0) {
			perror("failed to create output file");
			goto out;
		}
	}

794
	if (ev_qualifier_str != NULL) {
795 796 797 798 799 800
		const char *s = ev_qualifier_str;

		trace.not_ev_qualifier = *s == '!';
		if (trace.not_ev_qualifier)
			++s;
		trace.ev_qualifier = strlist__new(true, s);
801
		if (trace.ev_qualifier == NULL) {
802 803 804 805
			fputs("Not enough memory to parse event qualifier",
			      trace.output);
			err = -ENOMEM;
			goto out_close;
806 807 808
		}
	}

809 810 811
	err = perf_target__validate(&trace.opts.target);
	if (err) {
		perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
812 813
		fprintf(trace.output, "%s", bf);
		goto out_close;
814 815
	}

A
Arnaldo Carvalho de Melo 已提交
816 817 818
	err = perf_target__parse_uid(&trace.opts.target);
	if (err) {
		perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
819 820
		fprintf(trace.output, "%s", bf);
		goto out_close;
A
Arnaldo Carvalho de Melo 已提交
821 822
	}

823
	if (!argc && perf_target__none(&trace.opts.target))
824 825
		trace.opts.target.system_wide = true;

826 827 828
	err = trace__run(&trace, argc, argv);

	if (trace.sched && !err)
829
		trace__fprintf_thread_summary(&trace, trace.output);
830

831 832 833 834
out_close:
	if (output_name != NULL)
		fclose(trace.output);
out:
835
	return err;
A
Arnaldo Carvalho de Melo 已提交
836
}