From b97b59b93d10a54022afb06d5725d7aa55d98dd7 Mon Sep 17 00:00:00 2001 From: Stanislav Fomichev Date: Tue, 8 Jul 2014 20:03:41 +0400 Subject: perf timechart: Implement IO mode Currently, timechart records only scheduler and CPU events (task switches, running times, CPU power states, etc); this commit adds IO mode which makes it possible to record IO (disk, network) activity. In this mode perf timechart will generate SVG with IO charts (writes, reads, tx, rx, polls). Signed-off-by: Stanislav Fomichev Acked-by: Namhyung Kim Link: http://lkml.kernel.org/n/1404835423-23098-3-git-send-email-stfomichev@yandex-team.ru Signed-off-by: Jiri Olsa --- tools/perf/Documentation/perf-timechart.txt | 25 +++++++++++++++++++++++-- 1 file changed, 23 insertions(+), 2 deletions(-) (limited to 'tools/perf/Documentation/perf-timechart.txt') diff --git a/tools/perf/Documentation/perf-timechart.txt b/tools/perf/Documentation/perf-timechart.txt index 5e0f986dff38..ec6b46c7bca0 100644 --- a/tools/perf/Documentation/perf-timechart.txt +++ b/tools/perf/Documentation/perf-timechart.txt @@ -15,10 +15,20 @@ DESCRIPTION There are two variants of perf timechart: 'perf timechart record ' to record the system level events - of an arbitrary workload. + of an arbitrary workload. By default timechart records only scheduler + and CPU events (task switches, running times, CPU power states, etc), + but it's possible to record IO (disk, network) activity using -I argument. 'perf timechart' to turn a trace into a Scalable Vector Graphics file, - that can be viewed with popular SVG viewers such as 'Inkscape'. + that can be viewed with popular SVG viewers such as 'Inkscape'. Depending + on the events in the perf.data file, timechart will contain scheduler/cpu + events or IO events. + + In IO mode, every bar has two charts: upper and lower. + Upper bar shows incoming events (disk reads, ingress network packets). + Lower bar shows outgoing events (disk writes, egress network packets). + There are also poll bars which show how much time application spent + in poll/epoll/select syscalls. TIMECHART OPTIONS ----------------- @@ -63,6 +73,9 @@ RECORD OPTIONS -T:: --tasks-only:: Record only tasks-related events +-I:: +--io-only:: + Record only io-related events -g:: --callchain:: Do call-graph (stack chain/backtrace) recording @@ -87,6 +100,14 @@ Record system-wide timechart: $ perf timechart --highlight gcc +Record system-wide IO events: + + $ perf timechart record -I + + then generate timechart: + + $ perf timechart + SEE ALSO -------- linkperf:perf-record[1] -- cgit v1.2.3 From d243144af0b52fc5164a0823194f29a5979e236c Mon Sep 17 00:00:00 2001 From: Stanislav Fomichev Date: Tue, 8 Jul 2014 20:03:43 +0400 Subject: perf timechart: Add more options to IO mode --io-skip-eagain - don't show EAGAIN errors --io-min-time - make small io bursts visible --io-merge-dist - merge adjacent events Signed-off-by: Stanislav Fomichev Acked-by: Namhyung Kim Link: http://lkml.kernel.org/n/1404835423-23098-5-git-send-email-stfomichev@yandex-team.ru Signed-off-by: Jiri Olsa --- tools/perf/Documentation/perf-timechart.txt | 13 +++++ tools/perf/builtin-timechart.c | 75 ++++++++++++++++++++++++++++- 2 files changed, 86 insertions(+), 2 deletions(-) (limited to 'tools/perf/Documentation/perf-timechart.txt') diff --git a/tools/perf/Documentation/perf-timechart.txt b/tools/perf/Documentation/perf-timechart.txt index ec6b46c7bca0..df98d1c82688 100644 --- a/tools/perf/Documentation/perf-timechart.txt +++ b/tools/perf/Documentation/perf-timechart.txt @@ -64,6 +64,19 @@ TIMECHART OPTIONS duration or tasks with given name. If number is given it's interpreted as number of nanoseconds. If non-numeric string is given it's interpreted as task name. +--io-skip-eagain:: + Don't draw EAGAIN IO events. +--io-min-time=:: + Draw small events as if they lasted min-time. Useful when you need + to see very small and fast IO. It's possible to specify ms or us + suffix to specify time in milliseconds or microseconds. + Default value is 1ms. +--io-merge-dist=:: + Merge events that are merge-dist nanoseconds apart. + Reduces number of figures on the SVG and makes it more render-friendly. + It's possible to specify ms or us suffix to specify time in + milliseconds or microseconds. + Default value is 1us. RECORD OPTIONS -------------- diff --git a/tools/perf/builtin-timechart.c b/tools/perf/builtin-timechart.c index 37bf1eb0755f..04c9c53becad 100644 --- a/tools/perf/builtin-timechart.c +++ b/tools/perf/builtin-timechart.c @@ -62,7 +62,10 @@ struct timechart { topology; /* IO related settings */ u64 io_events; - bool io_only; + bool io_only, + skip_eagain; + u64 min_time, + merge_dist; }; struct per_pidcomm; @@ -761,7 +764,7 @@ static int pid_end_io_sample(struct timechart *tchart, int pid, int type, { struct per_pid *p = find_create_pid(tchart, pid); struct per_pidcomm *c = p->current; - struct io_sample *sample; + struct io_sample *sample, *prev; if (!c) { pr_warning("Invalid pidcomm!\n"); @@ -785,6 +788,18 @@ static int pid_end_io_sample(struct timechart *tchart, int pid, int type, } sample->end_time = end; + prev = sample->next; + + /* we want to be able to see small and fast transfers, so make them + * at least min_time long, but don't overlap them */ + if (sample->end_time - sample->start_time < tchart->min_time) + sample->end_time = sample->start_time + tchart->min_time; + if (prev && sample->start_time < prev->end_time) { + if (prev->err) /* try to make errors more visible */ + sample->start_time = prev->end_time; + else + prev->end_time = sample->start_time; + } if (ret < 0) { sample->err = ret; @@ -799,6 +814,24 @@ static int pid_end_io_sample(struct timechart *tchart, int pid, int type, sample->bytes = ret; } + /* merge two requests to make svg smaller and render-friendly */ + if (prev && + prev->type == sample->type && + prev->err == sample->err && + prev->fd == sample->fd && + prev->end_time + tchart->merge_dist >= sample->start_time) { + + sample->bytes += prev->bytes; + sample->merges += prev->merges + 1; + + sample->start_time = prev->start_time; + sample->next = prev->next; + free(prev); + + if (!sample->err && sample->bytes > c->max_bytes) + c->max_bytes = sample->bytes; + } + tchart->io_events++; return 0; @@ -1119,6 +1152,10 @@ static void draw_io_bars(struct timechart *tchart) for (sample = c->io_samples; sample; sample = sample->next) { double h = (double)sample->bytes / c->max_bytes; + if (tchart->skip_eagain && + sample->err == -EAGAIN) + continue; + if (sample->err) h = 1; @@ -1849,6 +1886,30 @@ parse_highlight(const struct option *opt __maybe_unused, const char *arg, return 0; } +static int +parse_time(const struct option *opt, const char *arg, int __maybe_unused unset) +{ + char unit = 'n'; + u64 *value = opt->value; + + if (sscanf(arg, "%" PRIu64 "%cs", value, &unit) > 0) { + switch (unit) { + case 'm': + *value *= 1000000; + break; + case 'u': + *value *= 1000; + break; + case 'n': + break; + default: + return -1; + } + } + + return 0; +} + int cmd_timechart(int argc, const char **argv, const char *prefix __maybe_unused) { @@ -1861,6 +1922,8 @@ int cmd_timechart(int argc, const char **argv, .ordered_samples = true, }, .proc_num = 15, + .min_time = 1000000, + .merge_dist = 1000, }; const char *output_name = "output.svg"; const struct option timechart_options[] = { @@ -1882,6 +1945,14 @@ int cmd_timechart(int argc, const char **argv, "min. number of tasks to print"), OPT_BOOLEAN('t', "topology", &tchart.topology, "sort CPUs according to topology"), + OPT_BOOLEAN(0, "io-skip-eagain", &tchart.skip_eagain, + "skip EAGAIN errors"), + OPT_CALLBACK(0, "io-min-time", &tchart.min_time, "time", + "all IO faster than min-time will visually appear longer", + parse_time), + OPT_CALLBACK(0, "io-merge-dist", &tchart.merge_dist, "time", + "merge events that are merge-dist us apart", + parse_time), OPT_END() }; const char * const timechart_usage[] = { -- cgit v1.2.3