Re: [PATCH 9/9] perf stat: Display user and system time

From: Jiri Olsa
Date: Mon Apr 23 2018 - 11:30:52 EST


On Mon, Apr 23, 2018 at 11:51:20AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Mon, Apr 23, 2018 at 11:08:23AM +0200, Jiri Olsa escreveu:
> > Adding the support to read rusage data once the
> > workload is finished and display the system/user
> > time values:
> >
> > $ perf stat --null ./perf bench sched pipe
> > ...
> >
> > Performance counter stats for './perf bench sched pipe':
> >
> > 5.342599256 seconds time elapsed
> >
> > 2.544434000 seconds user
> > 4.549691000 seconds sys
>
> Please write a setence or two explaining the above three timings, do it
> nicely so that we can add it to the man page and avoid people scratching
> heads :-)

will do ;-)

>
> All the other patches were applied, some to perf/urgent (fixes) the
> remaining ones, new features, added to perf/core, up to Ingo to decide
> where to merge when I get to ask him to pull.

cool, thanks

jirka

>
> - Arnaldo
>
> > It works only in non -r mode.
> >
> > Suggested-by: Ingo Molnar <mingo@xxxxxxxxxx>
> > Link: http://lkml.kernel.org/n/tip-t8k6d3gs8sz8zqnz3aslk5ro@xxxxxxxxxxxxxx
> > Signed-off-by: Jiri Olsa <jolsa@xxxxxxxxxx>
> > ---
> > tools/perf/builtin-stat.c | 28 +++++++++++++++++++++++++++-
> > 1 file changed, 27 insertions(+), 1 deletion(-)
> >
> > diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> > index 2137c7d11767..9c987617c8e7 100644
> > --- a/tools/perf/builtin-stat.c
> > +++ b/tools/perf/builtin-stat.c
> > @@ -80,6 +80,9 @@
> > #include <sys/stat.h>
> > #include <sys/wait.h>
> > #include <unistd.h>
> > +#include <sys/time.h>
> > +#include <sys/resource.h>
> > +#include <sys/wait.h>
> >
> > #include "sane_ctype.h"
> >
> > @@ -174,6 +177,8 @@ static const char *output_name;
> > static int output_fd;
> > static int print_free_counters_hint;
> > static u64 *walltime_run;
> > +static bool ru_display = false;
> > +static struct rusage ru_data;
> >
> > struct perf_stat {
> > bool record;
> > @@ -725,7 +730,7 @@ static int __run_perf_stat(int argc, const char **argv, int run_idx)
> > break;
> > }
> > }
> > - waitpid(child_pid, &status, 0);
> > + wait4(child_pid, &status, 0, &ru_data);
> >
> > if (workload_exec_errno) {
> > const char *emsg = str_error_r(workload_exec_errno, msg, sizeof(msg));
> > @@ -1773,6 +1778,11 @@ static void print_table(FILE *output, int precision, double avg)
> > fprintf(output, "\n%*s# Final result:\n", indent, "");
> > }
> >
> > +static double timeval2double(struct timeval *t)
> > +{
> > + return t->tv_sec + (double) t->tv_usec/USEC_PER_SEC;
> > +}
> > +
> > static void print_footer(void)
> > {
> > double avg = avg_stats(&walltime_nsecs_stats) / NSEC_PER_SEC;
> > @@ -1784,6 +1794,15 @@ static void print_footer(void)
> >
> > if (run_count == 1) {
> > fprintf(output, " %17.9f seconds time elapsed", avg);
> > +
> > + if (ru_display) {
> > + double utime = timeval2double(&ru_data.ru_utime);
> > + double stime = timeval2double(&ru_data.ru_stime);
> > +
> > + fprintf(output, "\n\n");
> > + fprintf(output, " %17.9f seconds user\n", utime);
> > + fprintf(output, " %17.9f seconds sys\n", stime);
> > + }
> > } else {
> > double sd = stddev_stats(&walltime_nsecs_stats) / NSEC_PER_SEC;
> > /*
> > @@ -2869,6 +2888,13 @@ int cmd_stat(int argc, const char **argv)
> > goto out;
> > }
> >
> > + /*
> > + * Display user/system times only for single
> > + * run and when there's specified tracee.
> > + */
> > + if ((run_count == 1) && target__none(&target))
> > + ru_display = true;
> > +
> > if (output_fd < 0) {
> > fprintf(stderr, "argument to --log-fd must be a > 0\n");
> > parse_options_usage(stat_usage, stat_options, "log-fd", 0);
> > --
> > 2.13.6