perf diff: Fix indentation of stalled backend cycle

PATCH In review Namhyung Kim 4 participants 10 messages May 13, 2016 – May 20, 2016 perf events

Share & tools

Namhyung Kim

author maintainer

2016-05-13 06:01 UTC #0 lore raw

PATCH 1/3 perf diff: Fix indentation of stalled backend cycle

The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed way to print shadow metrics, but it missed to update the width of stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:

Performance counter stats for 'pwd':

          0.638313      task-clock (msec)         #    0.567 CPUs utilized
                 0      context-switches          #    0.000 K/sec
                 0      cpu-migrations            #    0.000 K/sec
                54      page-faults               #    0.085 M/sec
           885,600      cycles                    #    1.387 GHz
           558,438      stalled-cycles-frontend   #   63.06% frontend cycles idle
           431,355      stalled-cycles-backend    #  48.71% backend cycles idle
           674,956      instructions              #    0.76  insn per cycle

# 0.83 stalled cycles per insn
130,380 branches # 204.257 M/sec
<not counted> branch-misses

0.001125426 seconds time elapsed

Cc Andi Kleen <[email protected]>

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/util/stat-shadow.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/util/stat-shadow.c +1 -1

index fdb71961143e..61200fcac5ef 100644
@@ -188,7 +188,7 @@ static void print_stalled_cycles_backend(int cpu,
 
 	color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio);
 
-	out->print_metric(out->ctx, color, "%6.2f%%", "backend cycles idle", ratio);
+	out->print_metric(out->ctx, color, "%7.2f%%", "backend cycles idle", ratio);
 }
 
 static void print_branch_misses(int cpu,

Signature · 1 line

2.8.2

Namhyung Kim

author maintainer

2016-05-13 06:01 UTC #1 lore raw

PATCH 2/3 perf stat: Update runtime using cpu-clock event

Currently only task-clock event updates the runtime_nsec so it cannot show the metric when using cpu-clock events. However cpu clock works basically same as task-clock, so no need to not update the runtime IMHO.

Before:

  # perf stat -a -e cpu-clock,context-switches,page-faults,cycles sleep 0.1

    Performance counter stats for 'system wide':

         1217.759506      cpu-clock (msec)
                  93      context-switches
                  61      page-faults
          18,958,022      cycles

         0.101393794 seconds time elapsed

After:

Performance counter stats for 'system wide':

         1220.471884      cpu-clock (msec)          #   12.013 CPUs utilized
                 118      context-switches          #    0.097 K/sec
                  59      page-faults               #    0.048 K/sec
          17,941,247      cycles                    #    0.015 GHz

         0.101594777 seconds time elapsed

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/util/stat-shadow.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

tools/perf/util/stat-shadow.c +4 -2

index 61200fcac5ef..aa9efe08762b 100644
@@ -94,7 +94,8 @@ void perf_stat__update_shadow_stats(struct perf_evsel *counter, u64 *count,
 {
 	int ctx = evsel_context(counter);
 
-	if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK))
+	if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK) ||
+	    perf_evsel__match(counter, SOFTWARE, SW_CPU_CLOCK))
 		update_stats(&runtime_nsecs_stats[cpu], count[0]);
 	else if (perf_evsel__match(counter, HARDWARE, HW_CPU_CYCLES))
 		update_stats(&runtime_cycles_stats[ctx][cpu], count[0]);

@@ -444,7 +445,8 @@ void perf_stat__print_shadow_stats(struct perf_evsel *evsel,
 			ratio = total / avg;
 
 		print_metric(ctxp, NULL, "%8.0f", "cycles / elision", ratio);
-	} else if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK)) {
+	} else if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK) ||
+		   perf_evsel__match(evsel, SOFTWARE, SW_CPU_CLOCK)) {
 		if ((ratio = avg_stats(&walltime_nsecs_stats)) != 0)
 			print_metric(ctxp, NULL, "%8.3f", "CPUs utilized",
 				     avg / ratio);

Signature · 1 line

2.8.2

tip-bot for Namhyung Kim

merge bot

2016-05-20 06:44 UTC #2 lore raw

[tip:perf/urgent] perf stat: Update runtime using cpu-clock event

perf stat: Update runtime using cpu-clock event

Commit-ID:  daf4f4786e8af371048e72cb37ac05190e89198a
Gitweb:     http://git.kernel.org/tip/daf4f4786e8af371048e72cb37ac05190e89198a
Author:     Namhyung Kim <[email protected]>
AuthorDate: Fri, 13 May 2016 15:01:02 +0900
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 16 May 2016 23:11:46 -0300

perf stat: Update runtime using cpu-clock event

Currently only the task-clock event updates the runtime_nsec so it cannot show the metric when using cpu-clock events. However cpu clock works basically same as task-clock, so no need to not update the runtime IMHO.

Before:

  # perf stat -a -e cpu-clock,context-switches,page-faults,cycles sleep 0.1

    Performance counter stats for 'system wide':

         1217.759506      cpu-clock (msec)
                  93      context-switches
                  61      page-faults
          18,958,022      cycles

         0.101393794 seconds time elapsed

After:

Performance counter stats for 'system wide':

         1220.471884      cpu-clock (msec)          #   12.013 CPUs utilized
                 118      context-switches          #    0.097 K/sec
                  59      page-faults               #    0.048 K/sec
          17,941,247      cycles                    #    0.015 GHz

         0.101594777 seconds time elapsed

Signed-off-by Namhyung Kim <[email protected]>

Tested-by Arnaldo Carvalho de Melo <[email protected]>

Cc Andi Kleen <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Peter Zijlstra <[email protected]>

Link http://lkml.kernel.org/r/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/util/stat-shadow.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

tools/perf/util/stat-shadow.c +4 -2

index 61200fc..aa9efe0 100644
@@ -94,7 +94,8 @@ void perf_stat__update_shadow_stats(struct perf_evsel *counter, u64 *count,
 {
 	int ctx = evsel_context(counter);
 
-	if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK))
+	if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK) ||
+	    perf_evsel__match(counter, SOFTWARE, SW_CPU_CLOCK))
 		update_stats(&runtime_nsecs_stats[cpu], count[0]);
 	else if (perf_evsel__match(counter, HARDWARE, HW_CPU_CYCLES))
 		update_stats(&runtime_cycles_stats[ctx][cpu], count[0]);

@@ -444,7 +445,8 @@ void perf_stat__print_shadow_stats(struct perf_evsel *evsel,
 			ratio = total / avg;
 
 		print_metric(ctxp, NULL, "%8.0f", "cycles / elision", ratio);
-	} else if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK)) {
+	} else if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK) ||
+		   perf_evsel__match(evsel, SOFTWARE, SW_CPU_CLOCK)) {
 		if ((ratio = avg_stats(&walltime_nsecs_stats)) != 0)
 			print_metric(ctxp, NULL, "%8.3f", "CPUs utilized",
 				     avg / ratio);

Namhyung Kim

author maintainer

2016-05-13 06:01 UTC #3 lore raw

PATCH 3/3 perf stat: Use cpu-clock event for cpu targets

In reply to Namhyung Kim

Currently perf stat always counts task-clock event by default. But it's somewhat confusing for system-wide targets (especially with 'sleep N' as the 'sleep' task just sleeps and doesn't use cputime). Changing to cpu-clock event instead for that case makes more sense IMHO.

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/builtin-stat.c | 3 +++
 1 file changed, 3 insertions(+)

tools/perf/builtin-stat.c +3 -0

index 5645a8361de6..d602e9e93dc1 100644
@@ -1904,6 +1904,9 @@ static int add_default_attributes(void)
 	}
 
 	if (!evsel_list->nr_entries) {
+		if (target__has_cpu(&target))
+			default_attrs0[0].config = PERF_COUNT_SW_CPU_CLOCK;
+
 		if (perf_evlist__add_default_attrs(evsel_list, default_attrs0) < 0)
 			return -1;
 		if (pmu_have_event("cpu", "stalled-cycles-frontend")) {

Signature · 1 line

2.8.2

tip-bot for Namhyung Kim

merge bot

2016-05-20 06:44 UTC #4 lore raw

[tip:perf/urgent] perf stat: Use cpu-clock event for cpu targets

perf stat: Use cpu-clock event for cpu targets

Commit-ID:  a1f3d56761df31f0ffeb215b974e26d5613e92a4
Gitweb:     http://git.kernel.org/tip/a1f3d56761df31f0ffeb215b974e26d5613e92a4
Author:     Namhyung Kim <[email protected]>
AuthorDate: Fri, 13 May 2016 15:01:03 +0900
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 16 May 2016 23:11:47 -0300

perf stat: Use cpu-clock event for cpu targets

Currently 'perf stat' always counts task-clock event by default. But it's somewhat confusing for system-wide targets (especially with 'sleep N' as the 'sleep' task just sleeps and doesn't use cputime). Changing to cpu-clock event instead for that case makes more sense IMHO.

Before:

  # perf stat -a sleep 0.1

Performance counter stats for 'system wide':

        403.038603      task-clock (msec)     #    4.001 CPUs utilized
               150      context-switches      #    0.372 K/sec
                 7      cpu-migrations        #    0.017 K/sec
                71      page-faults           #    0.176 K/sec
        23,705,169      cycles                #    0.059 GHz
        15,888,166      instructions          #    0.67  insn per cycle
         3,326,078      branches              #    8.253 M/sec
            87,643      branch-misses         #    2.64% of all branches

       0.100737009 seconds time elapsed

After:

  # perf stat -a sleep 0.1

Performance counter stats for 'system wide':

        404.271182      cpu-clock (msec)      #    4.000 CPUs utilized
               143      context-switches      #    0.354 K/sec
                13      cpu-migrations        #    0.032 K/sec
                73      page-faults           #    0.181 K/sec
        22,119,220      cycles                #    0.055 GHz
        13,622,065      instructions          #    0.62  insn per cycle
         2,918,769      branches              #    7.220 M/sec
            85,033      branch-misses         #    2.91% of all branches

       0.101073089 seconds time elapsed

Signed-off-by Namhyung Kim <[email protected]>

Tested-by Arnaldo Carvalho de Melo <[email protected]>

Cc Andi Kleen <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Peter Zijlstra <[email protected]>

Link http://lkml.kernel.org/r/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/builtin-stat.c | 3 +++
 1 file changed, 3 insertions(+)

tools/perf/builtin-stat.c +3 -0

index 16a923c..efdd232 100644
@@ -1905,6 +1905,9 @@ static int add_default_attributes(void)
 	}
 
 	if (!evsel_list->nr_entries) {
+		if (target__has_cpu(&target))
+			default_attrs0[0].config = PERF_COUNT_SW_CPU_CLOCK;
+
 		if (perf_evlist__add_default_attrs(evsel_list, default_attrs0) < 0)
 			return -1;
 		if (pmu_have_event("cpu", "stalled-cycles-frontend")) {

Arnaldo Carvalho de Melo

maintainer

2016-05-13 11:48 UTC #5 lore raw

In reply to Namhyung Kim

Em Fri, May 13, 2016 at 03:01:01PM +0900, Namhyung Kim escreveu:

Quoted 4 lines

The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed way to print shadow metrics, but it missed to update the width of stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:

Thanks for pointing out the cset that introduced the problem, helps in reviewing! Next time please consider adding it right before your Signed-off-by line as:

Fixes 140aeadc1fb5 ("perf stat: Abstract stat metrics printing")

Thanks!

- Arnaldo

Quoted 37 lines

Performance counter stats for 'pwd':

          0.638313      task-clock (msec)         #    0.567 CPUs utilized
                 0      context-switches          #    0.000 K/sec
                 0      cpu-migrations            #    0.000 K/sec
                54      page-faults               #    0.085 M/sec
           885,600      cycles                    #    1.387 GHz
           558,438      stalled-cycles-frontend   #   63.06% frontend cycles idle
           431,355      stalled-cycles-backend    #  48.71% backend cycles idle
           674,956      instructions              #    0.76  insn per cycle

# 0.83 stalled cycles per insn
130,380 branches # 204.257 M/sec
<not counted> branch-misses

0.001125426 seconds time elapsed

Cc Andi Kleen <[email protected]>

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/util/stat-shadow.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/util/stat-shadow.c +1 -1

index fdb71961143e..61200fcac5ef 100644
@@ -188,7 +188,7 @@ static void print_stalled_cycles_backend(int cpu,
 
 	color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio);
 
-	out->print_metric(out->ctx, color, "%6.2f%%", "backend cycles idle", ratio);
+	out->print_metric(out->ctx, color, "%7.2f%%", "backend cycles idle", ratio);
 }
 
 static void print_branch_misses(int cpu,

Signature · 1 line

2.8.2

Namhyung Kim

author maintainer

2016-05-13 13:42 UTC #6 lore raw

Hi Arnaldo,

Quoted 6 lines · Arnaldo Carvalho de Melo

Em Fri, May 13, 2016 at 03:01:01PM +0900, Namhyung Kim escreveu:
Quoted 4 lines
The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed way to print shadow metrics, but it missed to update the width of stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:

Quoted 7 lines

Thanks for pointing out the cset that introduced the problem, helps in reviewing! Next time please consider adding it right before your Signed-off-by line as:
Fixes 140aeadc1fb5 ("perf stat: Abstract stat metrics printing")
Thanks!

Ok, will do it later. Btw I found the subject line should start with 'perf stat' instead of 'perf diff'..

Thanks,
Namhyung

Quoted 38 lines

Performance counter stats for 'pwd':

          0.638313      task-clock (msec)         #    0.567 CPUs utilized
                 0      context-switches          #    0.000 K/sec
                 0      cpu-migrations            #    0.000 K/sec
                54      page-faults               #    0.085 M/sec
           885,600      cycles                    #    1.387 GHz
           558,438      stalled-cycles-frontend   #   63.06% frontend cycles idle
           431,355      stalled-cycles-backend    #  48.71% backend cycles idle
           674,956      instructions              #    0.76  insn per cycle

# 0.83 stalled cycles per insn
130,380 branches # 204.257 M/sec
<not counted> branch-misses

0.001125426 seconds time elapsed

Cc Andi Kleen <[email protected]>

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/util/stat-shadow.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/util/stat-shadow.c +1 -1

index fdb71961143e..61200fcac5ef 100644
@@ -188,7 +188,7 @@ static void print_stalled_cycles_backend(int cpu,
 
 	color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio);
 
-	out->print_metric(out->ctx, color, "%6.2f%%", "backend cycles idle", ratio);
+	out->print_metric(out->ctx, color, "%7.2f%%", "backend cycles idle", ratio);
 }
 
 static void print_branch_misses(int cpu,

Signature · 1 line

2.8.2

Arnaldo Carvalho de Melo

maintainer

2016-05-13 17:57 UTC #7 lore raw

Em Fri, May 13, 2016 at 10:42:24PM +0900, Namhyung Kim escreveu:

Quoted 13 lines

Hi Arnaldo,
Quoted 10 lines · Arnaldo Carvalho de Melo
Em Fri, May 13, 2016 at 03:01:01PM +0900, Namhyung Kim escreveu:
Quoted 4 lines
The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed way to print shadow metrics, but it missed to update the width of stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:
Thanks for pointing out the cset that introduced the problem, helps in reviewing! Next time please consider adding it right before your Signed-off-by line as:

Quoted 5 lines

Quoted 3 lines
Fixes 140aeadc1fb5 ("perf stat: Abstract stat metrics printing")
Thanks!
Ok, will do it later. Btw I found the subject line should start with

No need, I did it already, and also renamed the subject to "perf stat:
..."

Quoted 1 line

'perf stat' instead of 'perf diff'..

Fixed,

thanks,

- Arnaldo

Quoted 42 lines

Thanks,
Namhyung

Quoted 38 lines

Performance counter stats for 'pwd':

          0.638313      task-clock (msec)         #    0.567 CPUs utilized
                 0      context-switches          #    0.000 K/sec
                 0      cpu-migrations            #    0.000 K/sec
                54      page-faults               #    0.085 M/sec
           885,600      cycles                    #    1.387 GHz
           558,438      stalled-cycles-frontend   #   63.06% frontend cycles idle
           431,355      stalled-cycles-backend    #  48.71% backend cycles idle
           674,956      instructions              #    0.76  insn per cycle

# 0.83 stalled cycles per insn
130,380 branches # 204.257 M/sec
<not counted> branch-misses

0.001125426 seconds time elapsed

Cc Andi Kleen <[email protected]>

Signed-off-by Namhyung Kim <[email protected]>

---
 tools/perf/util/stat-shadow.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/util/stat-shadow.c +1 -1

index fdb71961143e..61200fcac5ef 100644
@@ -188,7 +188,7 @@ static void print_stalled_cycles_backend(int cpu,
 
 	color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio);
 
-	out->print_metric(out->ctx, color, "%6.2f%%", "backend cycles idle", ratio);
+	out->print_metric(out->ctx, color, "%7.2f%%", "backend cycles idle", ratio);
 }
 
 static void print_branch_misses(int cpu,

Signature · 1 line

2.8.2

Andi Kleen

2016-05-13 14:01 UTC #8 lore raw

In reply to Namhyung Kim

Quoted 4 lines · Namhyung Kim

The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed way to print shadow metrics, but it missed to update the width of stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:

Thanks.

My preferred action would be actually kill
stalled-cycles-frontend/backend.
I don't know any CPU where it is accurate.

TopDown is much better.

But as long as it is kept it is better to align it right.

-Andi

tip-bot for Namhyung Kim

merge bot

2016-05-20 06:44 UTC #9 lore raw

[tip:perf/urgent] perf stat: Fix indentation of stalled backend cycle

In reply to Namhyung Kim

perf stat: Fix indentation of stalled backend cycle

Commit-ID:  b0404be8d6186f9f3c23e2b5ff247e667be90652
Gitweb:     http://git.kernel.org/tip/b0404be8d6186f9f3c23e2b5ff247e667be90652
Author:     Namhyung Kim <[email protected]>
AuthorDate: Fri, 13 May 2016 15:01:01 +0900
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 16 May 2016 23:11:45 -0300

perf stat: Fix indentation of stalled backend cycle

The commit 140aeadc1fb5 ("perf stat: Abstract stat metrics printing") changed how shadow metrics are printed, but it missed to update the width of the stalled backend cycles event to 7.2% like others. This resulted in misaligned output like below:

Performance counter stats for 'pwd':

          0.638313      task-clock (msec)         #    0.567 CPUs utilized
                 0      context-switches          #    0.000 K/sec
                 0      cpu-migrations            #    0.000 K/sec
                54      page-faults               #    0.085 M/sec
           885,600      cycles                    #    1.387 GHz
           558,438      stalled-cycles-frontend   #   63.06% frontend cycles idle
           431,355      stalled-cycles-backend    #  48.71% backend cycles idle
           674,956      instructions              #    0.76  insn per cycle

# 0.83 stalled cycles per insn
130,380 branches # 204.257 M/sec
<not counted> branch-misses

0.001125426 seconds time elapsed

Signed-off-by Namhyung Kim <[email protected]>

Cc Andi Kleen <[email protected]>

Cc Jiri Olsa <[email protected]>

Cc Peter Zijlstra <[email protected]>

Fixes 140aeadc1fb5 ("perf stat: Abstract stat metrics printing")

Link http://lkml.kernel.org/r/[email protected] open here

Signed-off-by Arnaldo Carvalho de Melo <[email protected]>

---
 tools/perf/util/stat-shadow.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/util/stat-shadow.c +1 -1

index fdb7196..61200fc 100644
@@ -188,7 +188,7 @@ static void print_stalled_cycles_backend(int cpu,
 
 	color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio);
 
-	out->print_metric(out->ctx, color, "%6.2f%%", "backend cycles idle", ratio);
+	out->print_metric(out->ctx, color, "%7.2f%%", "backend cycles idle", ratio);
 }
 
 static void print_branch_misses(int cpu,