Re: [PATCH v2 4/6] perf sched timehist: Add option to specify time window of interest

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

Em Tue, Nov 29, 2016 at 10:15:44AM -0700, David Ahern escreveu:
> Add option to allow user to control analysis window. e.g., collect data
> for time window and analyze a segment of interest within that window.

Trying to test this I got:

[root@jouet ~]# perf sched timehist
No trace sample to read. Did you call 'perf record -R'?
[root@jouet ~]#

Could you please provide a better error message?

The perf.data file had this:

[root@jouet ~]# perf evlist -v
cycles:ppp: size: 112, { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|CALLCHAIN|CPU|PERIOD, disabled: 1, inherit: 1, mmap: 1, comm: 1, freq: 1, task: 1, precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1
[root@jouet ~]# 

- Arnaldo
 
> Signed-off-by: David Ahern <dsahern@gmail.com>
> ---
>  tools/perf/Documentation/perf-sched.txt |  8 ++++++
>  tools/perf/builtin-sched.c              | 51 +++++++++++++++++++++++++++++----
>  2 files changed, 53 insertions(+), 6 deletions(-)
> 
> diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
> index 121c60da03e5..7775b1eb2bee 100644
> --- a/tools/perf/Documentation/perf-sched.txt
> +++ b/tools/perf/Documentation/perf-sched.txt
> @@ -132,6 +132,14 @@ OPTIONS for 'perf sched timehist'
>  --migrations::
>  	Show migration events.
>  
> +--time::
> +	Only analyze samples within given time window: <start>,<stop>. Times
> +	have the format seconds.microseconds. If start is not given (i.e., time
> +	string is ',x.y') then analysis starts at the beginning of the file. If
> +	stop time is not given (i.e, time string is 'x.y,') then analysis goes
> +	to end of file.
> +
> +
>  SEE ALSO
>  --------
>  linkperf:perf-record[1]
> diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> index 4f9e7cba4ebf..870d94cd20ba 100644
> --- a/tools/perf/builtin-sched.c
> +++ b/tools/perf/builtin-sched.c
> @@ -15,6 +15,7 @@
>  #include "util/color.h"
>  #include "util/stat.h"
>  #include "util/callchain.h"
> +#include "util/time-utils.h"
>  
>  #include <subcmd/parse-options.h>
>  #include "util/trace-event.h"
> @@ -205,6 +206,8 @@ struct perf_sched {
>  	bool		show_wakeups;
>  	bool		show_migrations;
>  	u64		skipped_samples;
> +	const char	*time_str;
> +	struct perf_time_interval ptime;
>  };
>  
>  /* per thread run time data */
> @@ -1837,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched)
>  static void timehist_print_sample(struct perf_sched *sched,
>  				  struct perf_sample *sample,
>  				  struct addr_location *al,
> -				  struct thread *thread)
> +				  struct thread *thread,
> +				  u64 t)
>  {
>  	struct thread_runtime *tr = thread__priv(thread);
>  	u32 max_cpus = sched->max_cpu + 1;
>  	char tstr[64];
>  
> -	timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
> +	timestamp__scnprintf_usec(t, tstr, sizeof(tstr));
>  	printf("%15s [%04d] ", tstr, sample->cpu);
>  
>  	if (sched->show_cpu_visual) {
> @@ -2194,7 +2198,8 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool,
>  		tr->ready_to_run = sample->time;
>  
>  	/* show wakeups if requested */
> -	if (sched->show_wakeups)
> +	if (sched->show_wakeups &&
> +	    !perf_time__skip_sample(&sched->ptime, sample->time))
>  		timehist_print_wakeup_event(sched, sample, machine, thread);
>  
>  	return 0;
> @@ -2288,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
>  				       struct machine *machine)
>  {
>  	struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
> +	struct perf_time_interval *ptime = &sched->ptime;
>  	struct addr_location al;
>  	struct thread *thread;
>  	struct thread_runtime *tr = NULL;
> -	u64 tprev;
> +	u64 tprev, t = sample->time;
>  	int rc = 0;
>  
>  	if (machine__resolve(machine, &al, sample) < 0) {
> @@ -2318,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool,
>  
>  	tprev = perf_evsel__get_time(evsel, sample->cpu);
>  
> -	timehist_update_runtime_stats(tr, sample->time, tprev);
> +	/*
> +	 * If start time given:
> +	 * - sample time is under window user cares about - skip sample
> +	 * - tprev is under window user cares about  - reset to start of window
> +	 */
> +	if (ptime->start && ptime->start > t)
> +		goto out;
> +
> +	if (ptime->start > tprev)
> +		tprev = ptime->start;
> +
> +	/*
> +	 * If end time given:
> +	 * - previous sched event is out of window - we are done
> +	 * - sample time is beyond window user cares about - reset it
> +	 *   to close out stats for time window interest
> +	 */
> +	if (ptime->end) {
> +		if (tprev > ptime->end)
> +			goto out;
> +
> +		if (t > ptime->end)
> +			t = ptime->end;
> +	}
> +
> +	timehist_update_runtime_stats(tr, t, tprev);
> +
>  	if (!sched->summary_only)
> -		timehist_print_sample(sched, sample, &al, thread);
> +		timehist_print_sample(sched, sample, &al, thread, t);
>  
>  out:
>  	if (tr) {
> @@ -2583,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched)
>  
>  	symbol__init(&session->header.env);
>  
> +	if (perf_time__parse_str(&sched->ptime, sched->time_str) != 0) {
> +		pr_err("Invalid time string\n");
> +		return -EINVAL;
> +	}
> +
>  	if (timehist_check_attr(sched, evlist) != 0)
>  		goto out;
>  
> @@ -2997,6 +3034,8 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
>  	OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
>  	OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"),
>  	OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
> +	OPT_STRING(0, "time", &sched.time_str, "str",
> +		   "Time span for analysis (start,stop)"),
>  	OPT_PARENT(sched_options)
>  	};
>  
> -- 
> 2.7.4 (Apple Git-66)