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

[Arnaldo Carvalho de Melo <acme@kernel.org>]

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 :-)

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.

- Arnaldo
 
> It works only in non -r mode.
> 
> Suggested-by: Ingo Molnar <mingo@kernel.org>
> Link: http://lkml.kernel.org/n/tip-t8k6d3gs8sz8zqnz3aslk5ro@git.kernel.org
> Signed-off-by: Jiri Olsa <jolsa@kernel.org>
> ---
>  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