diff options
| author | Ingo Molnar <mingo@kernel.org> | 2012-10-26 04:30:49 -0400 |
|---|---|---|
| committer | Ingo Molnar <mingo@kernel.org> | 2012-10-26 04:30:49 -0400 |
| commit | 8f7c1d07ade50dcdea7ec779b277e891f5c8292a (patch) | |
| tree | 7a68411556ee154d201d8635a1c542152bae34c3 /tools | |
| parent | 6ca2a9c6543dd1a307c0250991d4de93550209ce (diff) | |
| parent | 1302d88e66f12a7b46a5598e641d93f0713007e0 (diff) | |
Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core
Pull perf/core trace improvements from Arnaldo Carvalho de Melo:
* Don't stop synthesizing threads when one vanishes, this is for
the existing threads when we start a tool like trace.
* Use sched:sched_stat_runtime to provide a thread summary, this
produces the same output as the 'trace summary' subcommand of
tglx's original "trace" tool.
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Ingo Molnar <mingo@kernel.org>
Diffstat (limited to 'tools')
| -rw-r--r-- | tools/perf/Documentation/perf-trace.txt | 3 | ||||
| -rw-r--r-- | tools/perf/builtin-trace.c | 108 | ||||
| -rw-r--r-- | tools/perf/util/event.c | 13 |
3 files changed, 110 insertions, 14 deletions
diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt index 38d4b682af0b..68718ccdd178 100644 --- a/tools/perf/Documentation/perf-trace.txt +++ b/tools/perf/Documentation/perf-trace.txt | |||
| @@ -51,6 +51,9 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs. | |||
| 51 | --duration: | 51 | --duration: |
| 52 | Show only events that had a duration greater than N.M ms. | 52 | Show only events that had a duration greater than N.M ms. |
| 53 | 53 | ||
| 54 | --sched: | ||
| 55 | Accrue thread runtime and provide a summary at the end of the session. | ||
| 56 | |||
| 54 | SEE ALSO | 57 | SEE ALSO |
| 55 | -------- | 58 | -------- |
| 56 | linkperf:perf-record[1], linkperf:perf-script[1] | 59 | linkperf:perf-record[1], linkperf:perf-script[1] |
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index ba055103b525..7932ffa29889 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c | |||
| @@ -67,7 +67,9 @@ struct thread_trace { | |||
| 67 | u64 entry_time; | 67 | u64 entry_time; |
| 68 | u64 exit_time; | 68 | u64 exit_time; |
| 69 | bool entry_pending; | 69 | bool entry_pending; |
| 70 | unsigned long nr_events; | ||
| 70 | char *entry_str; | 71 | char *entry_str; |
| 72 | double runtime_ms; | ||
| 71 | }; | 73 | }; |
| 72 | 74 | ||
| 73 | static struct thread_trace *thread_trace__new(void) | 75 | static struct thread_trace *thread_trace__new(void) |
| @@ -77,16 +79,21 @@ static struct thread_trace *thread_trace__new(void) | |||
| 77 | 79 | ||
| 78 | static struct thread_trace *thread__trace(struct thread *thread) | 80 | static struct thread_trace *thread__trace(struct thread *thread) |
| 79 | { | 81 | { |
| 82 | struct thread_trace *ttrace; | ||
| 83 | |||
| 80 | if (thread == NULL) | 84 | if (thread == NULL) |
| 81 | goto fail; | 85 | goto fail; |
| 82 | 86 | ||
| 83 | if (thread->priv == NULL) | 87 | if (thread->priv == NULL) |
| 84 | thread->priv = thread_trace__new(); | 88 | thread->priv = thread_trace__new(); |
| 85 | 89 | ||
| 86 | if (thread->priv == NULL) | 90 | if (thread->priv == NULL) |
| 87 | goto fail; | 91 | goto fail; |
| 88 | 92 | ||
| 89 | return thread->priv; | 93 | ttrace = thread->priv; |
| 94 | ++ttrace->nr_events; | ||
| 95 | |||
| 96 | return ttrace; | ||
| 90 | fail: | 97 | fail: |
| 91 | color_fprintf(stdout, PERF_COLOR_RED, | 98 | color_fprintf(stdout, PERF_COLOR_RED, |
| 92 | "WARNING: not enough memory, dropping samples!\n"); | 99 | "WARNING: not enough memory, dropping samples!\n"); |
| @@ -102,8 +109,11 @@ struct trace { | |||
| 102 | struct perf_record_opts opts; | 109 | struct perf_record_opts opts; |
| 103 | struct machine host; | 110 | struct machine host; |
| 104 | u64 base_time; | 111 | u64 base_time; |
| 112 | unsigned long nr_events; | ||
| 113 | bool sched; | ||
| 105 | bool multiple_threads; | 114 | bool multiple_threads; |
| 106 | double duration_filter; | 115 | double duration_filter; |
| 116 | double runtime_ms; | ||
| 107 | }; | 117 | }; |
| 108 | 118 | ||
| 109 | static bool trace__filter_duration(struct trace *trace, double t) | 119 | static bool trace__filter_duration(struct trace *trace, double t) |
| @@ -382,11 +392,37 @@ out: | |||
| 382 | return 0; | 392 | return 0; |
| 383 | } | 393 | } |
| 384 | 394 | ||
| 395 | static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel, | ||
| 396 | struct perf_sample *sample) | ||
| 397 | { | ||
| 398 | u64 runtime = perf_evsel__intval(evsel, sample, "runtime"); | ||
| 399 | double runtime_ms = (double)runtime / NSEC_PER_MSEC; | ||
| 400 | struct thread *thread = machine__findnew_thread(&trace->host, sample->tid); | ||
| 401 | struct thread_trace *ttrace = thread__trace(thread); | ||
| 402 | |||
| 403 | if (ttrace == NULL) | ||
| 404 | goto out_dump; | ||
| 405 | |||
| 406 | ttrace->runtime_ms += runtime_ms; | ||
| 407 | trace->runtime_ms += runtime_ms; | ||
| 408 | return 0; | ||
| 409 | |||
| 410 | out_dump: | ||
| 411 | printf("%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n", | ||
| 412 | evsel->name, | ||
| 413 | perf_evsel__strval(evsel, sample, "comm"), | ||
| 414 | (pid_t)perf_evsel__intval(evsel, sample, "pid"), | ||
| 415 | runtime, | ||
| 416 | perf_evsel__intval(evsel, sample, "vruntime")); | ||
| 417 | return 0; | ||
| 418 | } | ||
| 419 | |||
| 385 | static int trace__run(struct trace *trace, int argc, const char **argv) | 420 | static int trace__run(struct trace *trace, int argc, const char **argv) |
| 386 | { | 421 | { |
| 387 | struct perf_evlist *evlist = perf_evlist__new(NULL, NULL); | 422 | struct perf_evlist *evlist = perf_evlist__new(NULL, NULL); |
| 388 | struct perf_evsel *evsel; | 423 | struct perf_evsel *evsel; |
| 389 | int err = -1, i, nr_events = 0, before; | 424 | int err = -1, i; |
| 425 | unsigned long before; | ||
| 390 | const bool forks = argc > 0; | 426 | const bool forks = argc > 0; |
| 391 | 427 | ||
| 392 | if (evlist == NULL) { | 428 | if (evlist == NULL) { |
| @@ -400,6 +436,13 @@ static int trace__run(struct trace *trace, int argc, const char **argv) | |||
| 400 | goto out_delete_evlist; | 436 | goto out_delete_evlist; |
| 401 | } | 437 | } |
| 402 | 438 | ||
| 439 | if (trace->sched && | ||
| 440 | perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime", | ||
| 441 | trace__sched_stat_runtime)) { | ||
| 442 | printf("Couldn't read the sched_stat_runtime tracepoint information!\n"); | ||
| 443 | goto out_delete_evlist; | ||
| 444 | } | ||
| 445 | |||
| 403 | err = perf_evlist__create_maps(evlist, &trace->opts.target); | 446 | err = perf_evlist__create_maps(evlist, &trace->opts.target); |
| 404 | if (err < 0) { | 447 | if (err < 0) { |
| 405 | printf("Problems parsing the target to trace, check your options!\n"); | 448 | printf("Problems parsing the target to trace, check your options!\n"); |
| @@ -444,7 +487,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv) | |||
| 444 | 487 | ||
| 445 | trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1; | 488 | trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1; |
| 446 | again: | 489 | again: |
| 447 | before = nr_events; | 490 | before = trace->nr_events; |
| 448 | 491 | ||
| 449 | for (i = 0; i < evlist->nr_mmaps; i++) { | 492 | for (i = 0; i < evlist->nr_mmaps; i++) { |
| 450 | union perf_event *event; | 493 | union perf_event *event; |
| @@ -454,7 +497,7 @@ again: | |||
| 454 | tracepoint_handler handler; | 497 | tracepoint_handler handler; |
| 455 | struct perf_sample sample; | 498 | struct perf_sample sample; |
| 456 | 499 | ||
| 457 | ++nr_events; | 500 | ++trace->nr_events; |
| 458 | 501 | ||
| 459 | err = perf_evlist__parse_sample(evlist, event, &sample); | 502 | err = perf_evlist__parse_sample(evlist, event, &sample); |
| 460 | if (err) { | 503 | if (err) { |
| @@ -495,7 +538,7 @@ again: | |||
| 495 | } | 538 | } |
| 496 | } | 539 | } |
| 497 | 540 | ||
| 498 | if (nr_events == before) { | 541 | if (trace->nr_events == before) { |
| 499 | if (done) | 542 | if (done) |
| 500 | goto out_delete_evlist; | 543 | goto out_delete_evlist; |
| 501 | 544 | ||
| @@ -513,6 +556,51 @@ out: | |||
| 513 | return err; | 556 | return err; |
| 514 | } | 557 | } |
| 515 | 558 | ||
| 559 | static size_t trace__fprintf_threads_header(FILE *fp) | ||
| 560 | { | ||
| 561 | size_t printed; | ||
| 562 | |||
| 563 | printed = fprintf(fp, "\n _____________________________________________________________________\n"); | ||
| 564 | printed += fprintf(fp," __) Summary of events (__\n\n"); | ||
| 565 | printed += fprintf(fp," [ task - pid ] [ events ] [ ratio ] [ runtime ]\n"); | ||
| 566 | printed += fprintf(fp," _____________________________________________________________________\n\n"); | ||
| 567 | |||
| 568 | return printed; | ||
| 569 | } | ||
| 570 | |||
| 571 | static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp) | ||
| 572 | { | ||
| 573 | size_t printed = trace__fprintf_threads_header(fp); | ||
| 574 | struct rb_node *nd; | ||
| 575 | |||
| 576 | for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) { | ||
| 577 | struct thread *thread = rb_entry(nd, struct thread, rb_node); | ||
| 578 | struct thread_trace *ttrace = thread->priv; | ||
| 579 | const char *color; | ||
| 580 | double ratio; | ||
| 581 | |||
| 582 | if (ttrace == NULL) | ||
| 583 | continue; | ||
| 584 | |||
| 585 | ratio = (double)ttrace->nr_events / trace->nr_events * 100.0; | ||
| 586 | |||
| 587 | color = PERF_COLOR_NORMAL; | ||
| 588 | if (ratio > 50.0) | ||
| 589 | color = PERF_COLOR_RED; | ||
| 590 | else if (ratio > 25.0) | ||
| 591 | color = PERF_COLOR_GREEN; | ||
| 592 | else if (ratio > 5.0) | ||
| 593 | color = PERF_COLOR_YELLOW; | ||
| 594 | |||
| 595 | printed += color_fprintf(fp, color, "%20s", thread->comm); | ||
| 596 | printed += fprintf(fp, " - %-5d :%11lu [", thread->pid, ttrace->nr_events); | ||
| 597 | printed += color_fprintf(fp, color, "%5.1f%%", ratio); | ||
| 598 | printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms); | ||
| 599 | } | ||
| 600 | |||
| 601 | return printed; | ||
| 602 | } | ||
| 603 | |||
| 516 | static int trace__set_duration(const struct option *opt, const char *str, | 604 | static int trace__set_duration(const struct option *opt, const char *str, |
| 517 | int unset __maybe_unused) | 605 | int unset __maybe_unused) |
| 518 | { | 606 | { |
| @@ -563,6 +651,7 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) | |||
| 563 | OPT_CALLBACK(0, "duration", &trace, "float", | 651 | OPT_CALLBACK(0, "duration", &trace, "float", |
| 564 | "show only events with duration > N.M ms", | 652 | "show only events with duration > N.M ms", |
| 565 | trace__set_duration), | 653 | trace__set_duration), |
| 654 | OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"), | ||
| 566 | OPT_END() | 655 | OPT_END() |
| 567 | }; | 656 | }; |
| 568 | int err; | 657 | int err; |
| @@ -587,5 +676,10 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) | |||
| 587 | if (!argc && perf_target__none(&trace.opts.target)) | 676 | if (!argc && perf_target__none(&trace.opts.target)) |
| 588 | trace.opts.target.system_wide = true; | 677 | trace.opts.target.system_wide = true; |
| 589 | 678 | ||
| 590 | return trace__run(&trace, argc, argv); | 679 | err = trace__run(&trace, argc, argv); |
| 680 | |||
| 681 | if (trace.sched && !err) | ||
| 682 | trace__fprintf_thread_summary(&trace, stdout); | ||
| 683 | |||
| 684 | return err; | ||
| 591 | } | 685 | } |
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c index 0ae444ef1429..ca9ca285406a 100644 --- a/tools/perf/util/event.c +++ b/tools/perf/util/event.c | |||
| @@ -405,16 +405,15 @@ int perf_event__synthesize_threads(struct perf_tool *tool, | |||
| 405 | 405 | ||
| 406 | if (*end) /* only interested in proper numerical dirents */ | 406 | if (*end) /* only interested in proper numerical dirents */ |
| 407 | continue; | 407 | continue; |
| 408 | 408 | /* | |
| 409 | if (__event__synthesize_thread(comm_event, mmap_event, pid, 1, | 409 | * We may race with exiting thread, so don't stop just because |
| 410 | process, tool, machine) != 0) { | 410 | * one thread couldn't be synthesized. |
| 411 | err = -1; | 411 | */ |
| 412 | goto out_closedir; | 412 | __event__synthesize_thread(comm_event, mmap_event, pid, 1, |
| 413 | } | 413 | process, tool, machine); |
| 414 | } | 414 | } |
| 415 | 415 | ||
| 416 | err = 0; | 416 | err = 0; |
| 417 | out_closedir: | ||
| 418 | closedir(proc); | 417 | closedir(proc); |
| 419 | out_free_mmap: | 418 | out_free_mmap: |
| 420 | free(mmap_event); | 419 | free(mmap_event); |
