[GIT PULL] Re: [PATCH 08/15] perf tools: Introduce timestamp_in_usec()

[Arnaldo Carvalho de Melo]

Em Fri, Oct 28, 2016 at 11:30:41AM -0200, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Oct 28, 2016 at 10:53:38AM -0200, Arnaldo Carvalho de Melo escreveu:
> > Em Thu, Oct 27, 2016 at 04:14:55PM -0700, Joonwoo Park escreveu:
> > > Hmm.. I didn't ACK this patch because of bug I commented at
> > > https://www.mail-archive.com/linux-kernel@xxxxxxxxxxxxxxx/msg1256724.html

> > > s/work_list->max_lat/work_list->max_lat_at/

> > Sorry about that, I took the "thanks for taking care of this" as an ack,
> > now that I re-read that message I saw your points later on in that
> > e-mail.

> > Since Ingo hasn't pulled this, I'll try fixing it, will check that other
> > naming issue,

> So, here is how it ended up, it fixes the problem you pointed out and
> renames the function to follow the scnprintf() convention, as used
> elsewhere in tools/perf (tools/perf/util/annotate.h has several
> examples).

Ingo, I've just signed a perf-core-for-mingo-20161028 with the only
change being the patch below, re-run my tests, I think this doesn't
introduce any bugs and addresses Joonwoo's concerns, please consider
pulling.

Thanks,

- Arnaldo
 
> commit 99620a5d0cc8e2dd9aedb629a6e81825f0db020e
> Author: Namhyung Kim <namhyung@xxxxxxxxxx>
> Date:   Mon Oct 24 11:02:45 2016 +0900
> 
>     perf tools: Introduce timestamp__scnprintf_usec()
>     
>     Joonwoo reported that there's a mismatch between timestamps in script
>     and sched commands.  This was because of difference in printing the
>     timestamp.  Factor out the code and share it so that they can be in
>     sync.  Also I found that sched map has similar problem, fix it too.
>     
>     Committer notes:
>     
>     Fixed the max_lat_at bug introduced by Namhyung's original patch, as
>     pointed out by Joonwoo, and made it a function following the scnprintf()
>     model, i.e. returning the number of bytes formatted, and receiving as
>     the first parameter the object from where the data to the formatting is
>     obtained, renaming it from:
>     
>        char *timestamp_in_usec(char *bf, size_t size, u64 timestamp)
>     
>     to
>     
>        int timestamp__scnprintf_usec(u64 timestamp, char *bf, size_t size)
>     
>     Reported-by: Joonwoo Park <joonwoop@xxxxxxxxxxxxxx>
>     Signed-off-by: Namhyung Kim <namhyung@xxxxxxxxxx>
>     Cc: David Ahern <dsahern@xxxxxxxxx>
>     Cc: Jiri Olsa <jolsa@xxxxxxxxxx>
>     Cc: Peter Zijlstra <a.p.zijlstra@xxxxxxxxx>
>     Link: http://lkml.kernel.org/r/20161024020246.14928-3-namhyung@xxxxxxxxxx
>     Signed-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> 
> diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> index 1f33d15314a5..fb3441211e4b 100644
> --- a/tools/perf/builtin-sched.c
> +++ b/tools/perf/builtin-sched.c
> @@ -1191,6 +1191,7 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
>  	int i;
>  	int ret;
>  	u64 avg;
> +	char max_lat_at[32];
>  
>  	if (!work_list->nb_atoms)
>  		return;
> @@ -1212,12 +1213,13 @@ static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_
>  		printf(" ");
>  
>  	avg = work_list->total_lat / work_list->nb_atoms;
> +	timestamp__scnprintf_usec(work_list->max_lat_at, max_lat_at, sizeof(max_lat_at));
>  
> -	printf("|%11.3f ms |%9" PRIu64 " | avg:%9.3f ms | max:%9.3f ms | max at: %13.6f s\n",
> +	printf("|%11.3f ms |%9" PRIu64 " | avg:%9.3f ms | max:%9.3f ms | max at: %13s s\n",
>  	      (double)work_list->total_runtime / NSEC_PER_MSEC,
>  		 work_list->nb_atoms, (double)avg / NSEC_PER_MSEC,
>  		 (double)work_list->max_lat / NSEC_PER_MSEC,
> -		 (double)work_list->max_lat_at / NSEC_PER_SEC);
> +		 max_lat_at);
>  }
>  
>  static int pid_cmp(struct work_atoms *l, struct work_atoms *r)
> @@ -1402,6 +1404,7 @@ static int map_switch_event(struct perf_sched *sched, struct perf_evsel *evsel,
>  	int cpus_nr;
>  	bool new_cpu = false;
>  	const char *color = PERF_COLOR_NORMAL;
> +	char stimestamp[32];
>  
>  	BUG_ON(this_cpu >= MAX_CPUS || this_cpu < 0);
>  
> @@ -1492,7 +1495,8 @@ static int map_switch_event(struct perf_sched *sched, struct perf_evsel *evsel,
>  	if (sched->map.cpus && !cpu_map__has(sched->map.cpus, this_cpu))
>  		goto out;
>  
> -	color_fprintf(stdout, color, "  %12.6f secs ", (double)timestamp / NSEC_PER_SEC);
> +	timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp));
> +	color_fprintf(stdout, color, "  %12s secs ", stimestamp);
>  	if (new_shortname || (verbose && sched_in->tid)) {
>  		const char *pid_color = color;
>  
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index 412fb6e65ac0..e1daff36d070 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -441,7 +441,6 @@ static void print_sample_start(struct perf_sample *sample,
>  {
>  	struct perf_event_attr *attr = &evsel->attr;
>  	unsigned long secs;
> -	unsigned long usecs;
>  	unsigned long long nsecs;
>  
>  	if (PRINT_FIELD(COMM)) {
> @@ -471,11 +470,14 @@ static void print_sample_start(struct perf_sample *sample,
>  		nsecs = sample->time;
>  		secs = nsecs / NSEC_PER_SEC;
>  		nsecs -= secs * NSEC_PER_SEC;
> -		usecs = nsecs / NSEC_PER_USEC;
> +
>  		if (nanosecs)
>  			printf("%5lu.%09llu: ", secs, nsecs);
> -		else
> -			printf("%5lu.%06lu: ", secs, usecs);
> +		else {
> +			char sample_time[32];
> +			timestamp__scnprintf_usec(sample->time, sample_time, sizeof(sample_time));
> +			printf("%12s: ", sample_time);
> +		}
>  	}
>  }
>  
> diff --git a/tools/perf/util/util.c b/tools/perf/util/util.c
> index 85c56800f17a..5bbd1f609f1f 100644
> --- a/tools/perf/util/util.c
> +++ b/tools/perf/util/util.c
> @@ -433,6 +433,14 @@ int parse_nsec_time(const char *str, u64 *ptime)
>  	return 0;
>  }
>  
> +int timestamp__scnprintf_usec(u64 timestamp, char *buf, size_t sz)
> +{
> +	u64  sec = timestamp / NSEC_PER_SEC;
> +	u64 usec = (timestamp % NSEC_PER_SEC) / NSEC_PER_USEC;
> +
> +	return scnprintf(buf, sz, "%"PRIu64".%06"PRIu64, sec, usec);
> +}
> +
>  unsigned long parse_tag_value(const char *str, struct parse_tag *tags)
>  {
>  	struct parse_tag *i = tags;
> diff --git a/tools/perf/util/util.h b/tools/perf/util/util.h
> index 71b6992f1d98..79662d67891e 100644
> --- a/tools/perf/util/util.h
> +++ b/tools/perf/util/util.h
> @@ -362,4 +362,7 @@ extern int sched_getcpu(void);
>  #endif
>  
>  int is_printable_array(char *p, unsigned int len);
> +
> +int timestamp__scnprintf_usec(u64 timestamp, char *buf, size_t sz);
> +
>  #endif /* GIT_COMPAT_UTIL_H */