[PATCH 1/1] perf,stat: reduce interval-print to 10ms

[PATCH 1/1] perf,stat: reduce interval-print to 10ms

[kan.liang]

From: Kan Liang <kan.liang@intel.com>

The interval-print used to be limited to 100ms. However, for example,
10ms is required to do sophisticated bandwidth analysis using uncore
event.
The test shows that the overhead of the system-wide uncore monitoring
with 10ms interval is only ~2%. So this patch reduces interval-print to
10ms.
But 10ms may not work well for all cases. For example, when the
cpus/threads number is very large, for system-wide core event monitoring
the overhead could be high. To handle this issue, a warning will be
displayed when the interval-print is set between 10ms to 100ms. So the
users can make a decision according to their specific cases.

 #perf stat -e uncore_imc_1/cas_count_read/ -a --interval-print 10 --
 sleep 1

 print interval < 100ms. The overhead percentage could be high in some
 cases. Please proceed with caution.
 #           time             counts unit events
      0.010200451               0.10 MiB  uncore_imc_1/cas_count_read/
      0.020475117               0.02 MiB  uncore_imc_1/cas_count_read/
      0.030692800               0.01 MiB  uncore_imc_1/cas_count_read/
      0.040948161               0.02 MiB  uncore_imc_1/cas_count_read/
      0.051159564               0.00 MiB  uncore_imc_1/cas_count_read/

Signed-off-by: Kan Liang <kan.liang@intel.com>
---
 tools/perf/Documentation/perf-stat.txt |  2 +-
 tools/perf/builtin-stat.c              | 13 +++++++++----
 2 files changed, 10 insertions(+), 5 deletions(-)

diff --git a/tools/perf/Documentation/perf-stat.txt b/tools/perf/Documentation/perf-stat.txt
index 47469ab..7586fe0 100644
--- a/tools/perf/Documentation/perf-stat.txt
+++ b/tools/perf/Documentation/perf-stat.txt
@@ -128,7 +128,7 @@ perf stat --repeat 10 --null --sync --pre 'make -s O=defconfig-build/clean' -- m
 
 -I msecs::
 --interval-print msecs::
-	Print count deltas every N milliseconds (minimum: 100ms)
+	Print count deltas every N milliseconds (minimum: 10ms)
 	example: perf stat -I 1000 -e cycles -a sleep 5
 
 --per-socket::
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index a96fb5c..5ef88f7 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -1179,7 +1179,7 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
 	OPT_STRING(0, "post", &post_cmd, "command",
 			"command to run after to the measured command"),
 	OPT_UINTEGER('I', "interval-print", &stat_config.interval,
-		    "print counts at regular interval in ms (>= 100)"),
+		    "print counts at regular interval in ms (>= 10)"),
 	OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode,
 		     "aggregate counts per processor socket", AGGR_SOCKET),
 	OPT_SET_UINT(0, "per-core", &stat_config.aggr_mode,
@@ -1332,9 +1332,14 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
 		thread_map__read_comms(evsel_list->threads);
 
 	if (interval && interval < 100) {
-		pr_err("print interval must be >= 100ms\n");
-		parse_options_usage(stat_usage, options, "I", 1);
-		goto out;
+		if (interval < 10) {
+			pr_err("print interval must be >= 10ms\n");
+			parse_options_usage(stat_usage, options, "I", 1);
+			goto out;
+		} else
+			pr_warning("print interval < 100ms. "
+				   "The overhead percentage could be high in some cases. "
+				   "Please proceed with caution.\n");
 	}
 
 	if (perf_evlist__alloc_stats(evsel_list, interval))
-- 
1.8.3.1

Re: [PATCH 1/1] perf,stat: reduce interval-print to 10ms

[Jiri Olsa]

On Fri, Oct 02, 2015 at 05:04:34AM -0400, kan.liang@intel.com wrote:
> From: Kan Liang <kan.liang@intel.com>
> 

SNIP

> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> index a96fb5c..5ef88f7 100644
> --- a/tools/perf/builtin-stat.c
> +++ b/tools/perf/builtin-stat.c
> @@ -1179,7 +1179,7 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
>  	OPT_STRING(0, "post", &post_cmd, "command",
>  			"command to run after to the measured command"),
>  	OPT_UINTEGER('I', "interval-print", &stat_config.interval,
> -		    "print counts at regular interval in ms (>= 100)"),
> +		    "print counts at regular interval in ms (>= 10)"),
>  	OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode,
>  		     "aggregate counts per processor socket", AGGR_SOCKET),
>  	OPT_SET_UINT(0, "per-core", &stat_config.aggr_mode,
> @@ -1332,9 +1332,14 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
>  		thread_map__read_comms(evsel_list->threads);
>  
>  	if (interval && interval < 100) {
> -		pr_err("print interval must be >= 100ms\n");
> -		parse_options_usage(stat_usage, options, "I", 1);
> -		goto out;
> +		if (interval < 10) {
> +			pr_err("print interval must be >= 10ms\n");
> +			parse_options_usage(stat_usage, options, "I", 1);
> +			goto out;
> +		} else
> +			pr_warning("print interval < 100ms. "
> +				   "The overhead percentage could be high in some cases. "
> +				   "Please proceed with caution.\n");

with '-I' 10 this warning flies away quite fast ;-)

I guess it's better than nothing, and I'm not sure
about putting some sleep after that warning..

Acked-by: Jiri Olsa <jolsa@kernel.org>

thanks,
jirka

Re: [PATCH 1/1] perf,stat: reduce interval-print to 10ms

[Arnaldo Carvalho de Melo]

Em Fri, Oct 02, 2015 at 06:56:24PM +0200, Jiri Olsa escreveu:
> On Fri, Oct 02, 2015 at 05:04:34AM -0400, kan.liang@intel.com wrote:
> > From: Kan Liang <kan.liang@intel.com>
> > 
> 
> SNIP
> 
> > diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> > index a96fb5c..5ef88f7 100644
> > --- a/tools/perf/builtin-stat.c
> > +++ b/tools/perf/builtin-stat.c
> > @@ -1179,7 +1179,7 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
> >  	OPT_STRING(0, "post", &post_cmd, "command",
> >  			"command to run after to the measured command"),
> >  	OPT_UINTEGER('I', "interval-print", &stat_config.interval,
> > -		    "print counts at regular interval in ms (>= 100)"),
> > +		    "print counts at regular interval in ms (>= 10)"),
> >  	OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode,
> >  		     "aggregate counts per processor socket", AGGR_SOCKET),
> >  	OPT_SET_UINT(0, "per-core", &stat_config.aggr_mode,
> > @@ -1332,9 +1332,14 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
> >  		thread_map__read_comms(evsel_list->threads);
> >  
> >  	if (interval && interval < 100) {
> > -		pr_err("print interval must be >= 100ms\n");
> > -		parse_options_usage(stat_usage, options, "I", 1);
> > -		goto out;
> > +		if (interval < 10) {
> > +			pr_err("print interval must be >= 10ms\n");
> > +			parse_options_usage(stat_usage, options, "I", 1);
> > +			goto out;
> > +		} else
> > +			pr_warning("print interval < 100ms. "
> > +				   "The overhead percentage could be high in some cases. "
> > +				   "Please proceed with caution.\n");
> 
> with '-I' 10 this warning flies away quite fast ;-)
> 
> I guess it's better than nothing, and I'm not sure
> about putting some sleep after that warning..
> 
> Acked-by: Jiri Olsa <jolsa@kernel.org>

Right, this should appear in the man page as well, I added the patch
below, we could also print that warning when the workload ends.

- Arnaldo

diff --git a/tools/perf/Documentation/perf-stat.txt b/tools/perf/Documentation/perf-stat.txt
index 7586fe08ac9a..641caf66ff26 100644
--- a/tools/perf/Documentation/perf-stat.txt
+++ b/tools/perf/Documentation/perf-stat.txt
@@ -130,6 +130,8 @@ perf stat --repeat 10 --null --sync --pre 'make -s O=defconfig-build/clean' -- m
 --interval-print msecs::
 	Print count deltas every N milliseconds (minimum: 10ms)
 	example: perf stat -I 1000 -e cycles -a sleep 5
+	The overhead percentage could be high in some cases, for instance
+	with small, sub 100ms intervals.  Use with caution.
 
 --per-socket::
 Aggregate counts per processor socket for system-wide mode measurements.  This

RE: [PATCH 1/1] perf,stat: reduce interval-print to 10ms

[Liang, Kan]

> > SNIP
> >
> > > diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> > > index a96fb5c..5ef88f7 100644
> > > --- a/tools/perf/builtin-stat.c
> > > +++ b/tools/perf/builtin-stat.c
> > > @@ -1179,7 +1179,7 @@ int cmd_stat(int argc, const char **argv, const
> char *prefix __maybe_unused)
> > >  	OPT_STRING(0, "post", &post_cmd, "command",
> > >  			"command to run after to the measured
> command"),
> > >  	OPT_UINTEGER('I', "interval-print", &stat_config.interval,
> > > -		    "print counts at regular interval in ms (>= 100)"),
> > > +		    "print counts at regular interval in ms (>= 10)"),
> > >  	OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode,
> > >  		     "aggregate counts per processor socket",
> AGGR_SOCKET),
> > >  	OPT_SET_UINT(0, "per-core", &stat_config.aggr_mode, @@ -
> 1332,9
> > > +1332,14 @@ int cmd_stat(int argc, const char **argv, const char
> *prefix __maybe_unused)
> > >  		thread_map__read_comms(evsel_list->threads);
> > >
> > >  	if (interval && interval < 100) {
> > > -		pr_err("print interval must be >= 100ms\n");
> > > -		parse_options_usage(stat_usage, options, "I", 1);
> > > -		goto out;
> > > +		if (interval < 10) {
> > > +			pr_err("print interval must be >= 10ms\n");
> > > +			parse_options_usage(stat_usage, options, "I", 1);
> > > +			goto out;
> > > +		} else
> > > +			pr_warning("print interval < 100ms. "
> > > +				   "The overhead percentage could be high
> in some cases. "
> > > +				   "Please proceed with caution.\n");
> >
> > with '-I' 10 this warning flies away quite fast ;-)
> >
> > I guess it's better than nothing, and I'm not sure about putting some
> > sleep after that warning..
> >
> > Acked-by: Jiri Olsa <jolsa@kernel.org>
> 
> Right, this should appear in the man page as well, I added the patch below,
> we could also print that warning when the workload ends.
> 

OK. We can print the warning message again at the end as the patch below.

diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index 5ef88f7..01209c7 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -1377,6 +1377,11 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
 	if (!forever && status != -1 && !interval)
 		print_counters(NULL, argc, argv);
 
+	if (interval && interval < 100)
+		pr_warning("print interval < 100ms. "
+			   "The overhead percentage could be high in some cases. "
+			   "Please proceed with caution.\n");
+
 	perf_evlist__free_stats(evsel_list);
 out:
 	perf_evlist__delete(evsel_list);

Thanks,
Kan

> - Arnaldo
> 
> diff --git a/tools/perf/Documentation/perf-stat.txt
> b/tools/perf/Documentation/perf-stat.txt
> index 7586fe08ac9a..641caf66ff26 100644
> --- a/tools/perf/Documentation/perf-stat.txt
> +++ b/tools/perf/Documentation/perf-stat.txt
> @@ -130,6 +130,8 @@ perf stat --repeat 10 --null --sync --pre 'make -s
> O=defconfig-build/clean' -- m  --interval-print msecs::
>  	Print count deltas every N milliseconds (minimum: 10ms)
>  	example: perf stat -I 1000 -e cycles -a sleep 5
> +	The overhead percentage could be high in some cases, for instance
> +	with small, sub 100ms intervals.  Use with caution.
> 
>  --per-socket::
>  Aggregate counts per processor socket for system-wide mode
> measurements.  This

Re: [PATCH 1/1] perf,stat: reduce interval-print to 10ms

[Arnaldo Carvalho de Melo]

Em Fri, Oct 02, 2015 at 08:22:06PM +0000, Liang, Kan escreveu:
> > > > +		if (interval < 10) {
> > > > +			pr_err("print interval must be >= 10ms\n");
> > > > +			parse_options_usage(stat_usage, options, "I", 1);
> > > > +			goto out;
> > > > +		} else
> > > > +			pr_warning("print interval < 100ms. "
> > > > +				   "The overhead percentage could be high
> > in some cases. "
> > > > +				   "Please proceed with caution.\n");
> > >
> > > with '-I' 10 this warning flies away quite fast ;-)
> > >
> > > I guess it's better than nothing, and I'm not sure about putting some
> > > sleep after that warning..
> > >
> > > Acked-by: Jiri Olsa <jolsa@kernel.org>
> > 
> > Right, this should appear in the man page as well, I added the patch below,
> > we could also print that warning when the workload ends.
 
> OK. We can print the warning message again at the end as the patch below.
> 
> +++ b/tools/perf/builtin-stat.c
> @@ -1377,6 +1377,11 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
>  	if (!forever && status != -1 && !interval)
>  		print_counters(NULL, argc, argv);
>  
> +	if (interval && interval < 100)
> +		pr_warning("print interval < 100ms. "
> +			   "The overhead percentage could be high in some cases. "
> +			   "Please proceed with caution.\n");

Yeah, something like that, but the warning then becomes strange,
"proceed"? I guess that something like:

		pr_warning("print interval < 100ms. "
			   "The overhead percentage could have been high. "
			   "Take that into account when interpreting the these numbers.\n");

Right?

- Arnaldo

> +
>  	perf_evlist__free_stats(evsel_list);
>  out:
>  	perf_evlist__delete(evsel_list);

RE: [PATCH 1/1] perf,stat: reduce interval-print to 10ms

[Liang, Kan]

> -----Original Message-----
> From: Arnaldo Carvalho de Melo [mailto:acme@kernel.org]
> Sent: Friday, October 02, 2015 4:40 PM
> To: Liang, Kan
> Cc: Jiri Olsa; jolsa@kernel.org; namhyung@kernel.org; ak@linux.intel.com;
> linux-kernel@vger.kernel.org; Stephane Eranian
> Subject: Re: [PATCH 1/1] perf,stat: reduce interval-print to 10ms
> 
> Em Fri, Oct 02, 2015 at 08:22:06PM +0000, Liang, Kan escreveu:
> > > > > +		if (interval < 10) {
> > > > > +			pr_err("print interval must be >= 10ms\n");
> > > > > +			parse_options_usage(stat_usage, options,
> "I", 1);
> > > > > +			goto out;
> > > > > +		} else
> > > > > +			pr_warning("print interval < 100ms. "
> > > > > +				   "The overhead percentage could
> be high
> > > in some cases. "
> > > > > +				   "Please proceed with caution.\n");
> > > >
> > > > with '-I' 10 this warning flies away quite fast ;-)
> > > >
> > > > I guess it's better than nothing, and I'm not sure about putting
> > > > some sleep after that warning..
> > > >
> > > > Acked-by: Jiri Olsa <jolsa@kernel.org>
> > >
> > > Right, this should appear in the man page as well, I added the patch
> > > below, we could also print that warning when the workload ends.
> 
> > OK. We can print the warning message again at the end as the patch
> below.
> >
> > +++ b/tools/perf/builtin-stat.c
> > @@ -1377,6 +1377,11 @@ int cmd_stat(int argc, const char **argv, const
> char *prefix __maybe_unused)
> >  	if (!forever && status != -1 && !interval)
> >  		print_counters(NULL, argc, argv);
> >
> > +	if (interval && interval < 100)
> > +		pr_warning("print interval < 100ms. "
> > +			   "The overhead percentage could be high in some
> cases. "
> > +			   "Please proceed with caution.\n");
> 
> Yeah, something like that, but the warning then becomes strange,
> "proceed"? I guess that something like:
> 
> 		pr_warning("print interval < 100ms. "
> 			   "The overhead percentage could have been high.
> "
> 			   "Take that into account when interpreting the
> these numbers.\n");
> 
> Right?

Yes.

Thanks,
Kan

> 
> - Arnaldo
> 
> > +
> >  	perf_evlist__free_stats(evsel_list);
> >  out:
> >  	perf_evlist__delete(evsel_list);

[tip:perf/core] perf stat: Reduce min --interval-print to 10ms

[tip-bot for Kan Liang]

Commit-ID:  19afd10410957b1c808c2c49a88e6dd8b23aa894
Gitweb:     http://git.kernel.org/tip/19afd10410957b1c808c2c49a88e6dd8b23aa894
Author:     Kan Liang <kan.liang@intel.com>
AuthorDate: Fri, 2 Oct 2015 05:04:34 -0400
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 2 Oct 2015 17:07:55 -0300

perf stat: Reduce min --interval-print to 10ms

The --interval-print parameter was limited to 100ms. However, for
example, 10ms is required to do sophisticated bandwidth analysis using
uncore events.

The test shows that the overhead of the system-wide uncore monitoring
with 10ms interval is only ~2%. So this patch reduces the minimal
interval-print allowd to 10ms.

But 10ms may not work well for all cases. For example, when the
cpus/threads number is very large, for system-wide core event monitoring
the overhead could be high.

To handle this issue, a warning will be displayed when the
interval-print is set between 10ms to 100ms. So users can make a
decision according to their specific cases.

 # perf stat -e uncore_imc_1/cas_count_read/ -a --interval-print 10 -- sleep 1

 print interval < 100ms. The overhead percentage could be high in some
 cases. Please proceed with caution.
 #           time             counts unit events
      0.010200451               0.10 MiB  uncore_imc_1/cas_count_read/
      0.020475117               0.02 MiB  uncore_imc_1/cas_count_read/
      0.030692800               0.01 MiB  uncore_imc_1/cas_count_read/
      0.040948161               0.02 MiB  uncore_imc_1/cas_count_read/
      0.051159564               0.00 MiB  uncore_imc_1/cas_count_read/

Signed-off-by: Kan Liang <kan.liang@intel.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/1443776674-42511-1-git-send-email-kan.liang@intel.com
[ Added warning about overhead when using sub 100ms intervals to the man page ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/Documentation/perf-stat.txt |  5 +++--
 tools/perf/builtin-stat.c              | 13 +++++++++----
 2 files changed, 12 insertions(+), 6 deletions(-)

diff --git a/tools/perf/Documentation/perf-stat.txt b/tools/perf/Documentation/perf-stat.txt
index 47469ab..4e074a6 100644
--- a/tools/perf/Documentation/perf-stat.txt
+++ b/tools/perf/Documentation/perf-stat.txt
@@ -128,8 +128,9 @@ perf stat --repeat 10 --null --sync --pre 'make -s O=defconfig-build/clean' -- m
 
 -I msecs::
 --interval-print msecs::
-	Print count deltas every N milliseconds (minimum: 100ms)
-	example: perf stat -I 1000 -e cycles -a sleep 5
+Print count deltas every N milliseconds (minimum: 10ms)
+The overhead percentage could be high in some cases, for instance with small, sub 100ms intervals.  Use with caution.
+	example: 'perf stat -I 1000 -e cycles -a sleep 5'
 
 --per-socket::
 Aggregate counts per processor socket for system-wide mode measurements.  This
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index a96fb5c..5ef88f7 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -1179,7 +1179,7 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
 	OPT_STRING(0, "post", &post_cmd, "command",
 			"command to run after to the measured command"),
 	OPT_UINTEGER('I', "interval-print", &stat_config.interval,
-		    "print counts at regular interval in ms (>= 100)"),
+		    "print counts at regular interval in ms (>= 10)"),
 	OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode,
 		     "aggregate counts per processor socket", AGGR_SOCKET),
 	OPT_SET_UINT(0, "per-core", &stat_config.aggr_mode,
@@ -1332,9 +1332,14 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
 		thread_map__read_comms(evsel_list->threads);
 
 	if (interval && interval < 100) {
-		pr_err("print interval must be >= 100ms\n");
-		parse_options_usage(stat_usage, options, "I", 1);
-		goto out;
+		if (interval < 10) {
+			pr_err("print interval must be >= 10ms\n");
+			parse_options_usage(stat_usage, options, "I", 1);
+			goto out;
+		} else
+			pr_warning("print interval < 100ms. "
+				   "The overhead percentage could be high in some cases. "
+				   "Please proceed with caution.\n");
 	}
 
 	if (perf_evlist__alloc_stats(evsel_list, interval))