perf tests: Fix switch tracking test for P4

PATCH In review Jiri Olsa 4 participants 5 messages May 26, 2017 – Jun 4, 2017 perf events

lore

Share & tools

lore

Jiri Olsa

author reviewer

2017-05-26 12:31 UTC #0 lore raw

PATCH 1/2 perf tests: Fix switch tracking test for P4

The switch tracking test keeps failing on P4 cpu, when NMI watchdog is enabled.

The reason is that P4 pmu uses substitute event for cycles when it's already taken (in our case by NMI watchdog), but this event does not give even results like cycles, and we could end up with no samples at all for our short measuring period.

Fixing this by using "instructions:u" event instead, which seems to be stable enough.

Cc Michael Petlan <[email protected]>

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

Signed-off-by Jiri Olsa <[email protected]>

---
 tools/perf/tests/switch-tracking.c | 27 +++++++++++++++++++++++++--
 1 file changed, 25 insertions(+), 2 deletions(-)

tools/perf/tests/switch-tracking.c +25 -2

index 65474fd80da7..e519819ea2e5 100644
@@ -10,6 +10,7 @@
 #include "thread_map.h"
 #include "cpumap.h"
 #include "tests.h"
+#include "header.h"
 
 static int spin_sleep(void)
 {

@@ -298,6 +299,27 @@ static int process_events(struct perf_evlist *evlist,
 	return ret;
 }
 
+static const char *get_hw_counter(void)
+{
+	const char *counter = "cycles:u";
+	char *cpuid;
+
+	cpuid = get_cpuid_str();
+
+	/*
+	 * P4 pmu uses substitute event for cycles if it's already
+	 * taken, but it does not give even results like cycles,
+	 * and we could end up with no samples at all for our short
+	 * measuring period. Using "instructions:u" event instead,
+	 * which seems to be stable enough.
+	 */
+	if (!strcmp("GenuineIntel-15-4", cpuid))
+		counter = "instructions:u";
+
+	pr_debug("using '%s' HW counter");
+	return counter;
+}
+
 /**
  * test__switch_tracking - test using sched_switch and tracking events.
  *

@@ -308,6 +330,7 @@ static int process_events(struct perf_evlist *evlist,
  */
 int test__switch_tracking(int subtest __maybe_unused)
 {
+	const char *hw_counter = get_hw_counter();
 	const char *sched_switch = "sched:sched_switch";
 	struct switch_tracking switch_tracking = { .tids = NULL, };
 	struct record_opts opts = {

@@ -357,9 +380,9 @@ int test__switch_tracking(int subtest __maybe_unused)
 	cpu_clocks_evsel = perf_evlist__last(evlist);
 
 	/* Second event */
-	err = parse_events(evlist, "cycles:u", NULL);
+	err = parse_events(evlist, hw_counter, NULL);
 	if (err) {
-		pr_debug("Failed to parse event cycles:u\n");
+		pr_debug("Failed to parse event %s\n", hw_counter);
 		goto out_err;
 	}

Signature · 1 line

2.9.4

Jiri Olsa

author reviewer

2017-05-26 12:31 UTC #1 lore raw

PATCH 2/2 perf tests: Rename cycles event to HW event

The 'hardware' suits better now when we could also use instructions event in addition to cycles.

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

Signed-off-by Jiri Olsa <[email protected]>

---
 tools/perf/tests/switch-tracking.c | 64 +++++++++++++++++++-------------------
 1 file changed, 32 insertions(+), 32 deletions(-)

tools/perf/tests/switch-tracking.c +32 ~~-32~~

index e519819ea2e5..bce1056ecdde 100644
@@ -52,13 +52,13 @@ static int spin_sleep(void)
 
 struct switch_tracking {
 	struct perf_evsel *switch_evsel;
-	struct perf_evsel *cycles_evsel;
+	struct perf_evsel *hw_evsel;
 	pid_t *tids;
 	int nr_tids;
 	int comm_seen[4];
-	int cycles_before_comm_1;
-	int cycles_between_comm_2_and_comm_3;
-	int cycles_after_comm_4;
+	int hw_before_comm_1;
+	int hw_between_comm_2_and_comm_3;
+	int hw_after_comm_4;
 };
 
 static int check_comm(struct switch_tracking *switch_tracking,

@@ -148,15 +148,15 @@ static int process_sample_event(struct perf_evlist *evlist,
 		switch_tracking->tids[cpu] = next_tid;
 	}
 
-	if (evsel == switch_tracking->cycles_evsel) {
-		pr_debug3("cycles event\n");
+	if (evsel == switch_tracking->hw_evsel) {
+		pr_debug3("hw event\n");
 		if (!switch_tracking->comm_seen[0])
-			switch_tracking->cycles_before_comm_1 = 1;
+			switch_tracking->hw_before_comm_1 = 1;
 		if (switch_tracking->comm_seen[1] &&
 		    !switch_tracking->comm_seen[2])
-			switch_tracking->cycles_between_comm_2_and_comm_3 = 1;
+			switch_tracking->hw_between_comm_2_and_comm_3 = 1;
 		if (switch_tracking->comm_seen[3])
-			switch_tracking->cycles_after_comm_4 = 1;
+			switch_tracking->hw_after_comm_4 = 1;
 	}
 
 	return 0;

@@ -316,7 +316,7 @@ static const char *get_hw_counter(void)
 	if (!strcmp("GenuineIntel-15-4", cpuid))
 		counter = "instructions:u";
 
-	pr_debug("using '%s' HW counter");
+	pr_debug("using '%s' as HW counter", counter);
 	return counter;
 }

@@ -345,7 +345,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 	struct thread_map *threads = NULL;
 	struct cpu_map *cpus = NULL;
 	struct perf_evlist *evlist = NULL;
-	struct perf_evsel *evsel, *cpu_clocks_evsel, *cycles_evsel;
+	struct perf_evsel *evsel, *cpu_clocks_evsel, *hw_evsel;
 	struct perf_evsel *switch_evsel, *tracking_evsel;
 	const char *comm;
 	int err = -1;

@@ -386,7 +386,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 		goto out_err;
 	}
 
-	cycles_evsel = perf_evlist__last(evlist);
+	hw_evsel = perf_evlist__last(evlist);
 
 	/* Third event */
 	if (!perf_evlist__can_select_event(evlist, sched_switch)) {

@@ -411,18 +411,18 @@ int test__switch_tracking(int subtest __maybe_unused)
 	switch_evsel->immediate = true;
 
 	/* Test moving an event to the front */
-	if (cycles_evsel == perf_evlist__first(evlist)) {
-		pr_debug("cycles event already at front");
+	if (hw_evsel == perf_evlist__first(evlist)) {
+		pr_debug("HW event already at front");
 		goto out_err;
 	}
-	perf_evlist__to_front(evlist, cycles_evsel);
-	if (cycles_evsel != perf_evlist__first(evlist)) {
-		pr_debug("Failed to move cycles event to front");
+	perf_evlist__to_front(evlist, hw_evsel);
+	if (hw_evsel != perf_evlist__first(evlist)) {
+		pr_debug("Failed to move HW event to front");
 		goto out_err;
 	}
 
-	perf_evsel__set_sample_bit(cycles_evsel, CPU);
-	perf_evsel__set_sample_bit(cycles_evsel, TIME);
+	perf_evsel__set_sample_bit(hw_evsel, CPU);
+	perf_evsel__set_sample_bit(hw_evsel, TIME);
 
 	/* Fourth event */
 	err = parse_events(evlist, "dummy:u", NULL);

@@ -444,7 +444,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 	perf_evlist__config(evlist, &opts, NULL);
 
 	/* Check moved event is still at the front */
-	if (cycles_evsel != perf_evlist__first(evlist)) {
+	if (hw_evsel != perf_evlist__first(evlist)) {
 		pr_debug("Front event no longer at front");
 		goto out_err;
 	}

@@ -498,7 +498,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 		goto out_err;
 	}
 
-	err = perf_evsel__disable(cycles_evsel);
+	err = perf_evsel__disable(hw_evsel);
 	if (err) {
 		pr_debug("perf_evlist__disable_event failed!\n");
 		goto out_err;

@@ -524,7 +524,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 		goto out_err;
 	}
 
-	err = perf_evsel__enable(cycles_evsel);
+	err = perf_evsel__enable(hw_evsel);
 	if (err) {
 		pr_debug("perf_evlist__disable_event failed!\n");
 		goto out_err;

@@ -546,7 +546,7 @@ int test__switch_tracking(int subtest __maybe_unused)
 	perf_evlist__disable(evlist);
 
 	switch_tracking.switch_evsel = switch_evsel;
-	switch_tracking.cycles_evsel = cycles_evsel;
+	switch_tracking.hw_evsel     = hw_evsel;
 
 	err = process_events(evlist, &switch_tracking);

@@ -562,21 +562,21 @@ int test__switch_tracking(int subtest __maybe_unused)
 		goto out_err;
 	}
 
-	/* Check cycles event got enabled */
-	if (!switch_tracking.cycles_before_comm_1) {
-		pr_debug("Missing cycles events\n");
+	/* Check HW event got enabled */
+	if (!switch_tracking.hw_before_comm_1) {
+		pr_debug("Missing HW events\n");
 		goto out_err;
 	}
 
-	/* Check cycles event got disabled */
-	if (switch_tracking.cycles_between_comm_2_and_comm_3) {
-		pr_debug("cycles events even though event was disabled\n");
+	/* Check HW event got disabled */
+	if (switch_tracking.hw_between_comm_2_and_comm_3) {
+		pr_debug("HW events even though event was disabled\n");
 		goto out_err;
 	}
 
-	/* Check cycles event got enabled again */
-	if (!switch_tracking.cycles_after_comm_4) {
-		pr_debug("Missing cycles events\n");
+	/* Check HW event got enabled again */
+	if (!switch_tracking.hw_after_comm_4) {
+		pr_debug("Missing HW events\n");
 		goto out_err;
 	}
 out:

Signature · 1 line

2.9.4

Arnaldo Carvalho de Melo

maintainer

2017-06-01 13:11 UTC #2 lore raw

In reply to Jiri Olsa

Em Fri, May 26, 2017 at 02:31:40PM +0200, Jiri Olsa escreveu:

Quoted 11 lines

The switch tracking test keeps failing on P4 cpu, when NMI watchdog is enabled.
The reason is that P4 pmu uses substitute event for cycles when it's already taken (in our case by NMI watchdog), but this event does not give even results like cycles, and we could end up with no samples at all for our short measuring period.
Fixing this by using "instructions:u" event instead, which seems to be stable enough.

The original author of this test entry is Adrian, so would be nice for him to take a look and give his Ack, Adrian?

- Arnaldo

Quoted 69 lines

Cc Michael Petlan <[email protected]>

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

Signed-off-by Jiri Olsa <[email protected]>

---
 tools/perf/tests/switch-tracking.c | 27 +++++++++++++++++++++++++--
 1 file changed, 25 insertions(+), 2 deletions(-)

tools/perf/tests/switch-tracking.c +25 -2

index 65474fd80da7..e519819ea2e5 100644
@@ -10,6 +10,7 @@
 #include "thread_map.h"
 #include "cpumap.h"
 #include "tests.h"
+#include "header.h"
 
 static int spin_sleep(void)
 {

@@ -298,6 +299,27 @@ static int process_events(struct perf_evlist *evlist,
 	return ret;
 }
 
+static const char *get_hw_counter(void)
+{
+	const char *counter = "cycles:u";
+	char *cpuid;
+
+	cpuid = get_cpuid_str();
+
+	/*
+	 * P4 pmu uses substitute event for cycles if it's already
+	 * taken, but it does not give even results like cycles,
+	 * and we could end up with no samples at all for our short
+	 * measuring period. Using "instructions:u" event instead,
+	 * which seems to be stable enough.
+	 */
+	if (!strcmp("GenuineIntel-15-4", cpuid))
+		counter = "instructions:u";
+
+	pr_debug("using '%s' HW counter");
+	return counter;
+}
+
 /**
  * test__switch_tracking - test using sched_switch and tracking events.
  *

@@ -308,6 +330,7 @@ static int process_events(struct perf_evlist *evlist,
  */
 int test__switch_tracking(int subtest __maybe_unused)
 {
+	const char *hw_counter = get_hw_counter();
 	const char *sched_switch = "sched:sched_switch";
 	struct switch_tracking switch_tracking = { .tids = NULL, };
 	struct record_opts opts = {

@@ -357,9 +380,9 @@ int test__switch_tracking(int subtest __maybe_unused)
 	cpu_clocks_evsel = perf_evlist__last(evlist);
 
 	/* Second event */
-	err = parse_events(evlist, "cycles:u", NULL);
+	err = parse_events(evlist, hw_counter, NULL);
 	if (err) {
-		pr_debug("Failed to parse event cycles:u\n");
+		pr_debug("Failed to parse event %s\n", hw_counter);
 		goto out_err;
 	}

Signature · 1 line

2.9.4

Adrian Hunter

reviewer

2017-06-02 11:41 UTC #3 lore raw

Quoted 9 lines · Arnaldo Carvalho de Melo

Em Fri, May 26, 2017 at 02:31:40PM +0200, Jiri Olsa escreveu:
Quoted 8 lines
The switch tracking test keeps failing on P4 cpu, when NMI watchdog is enabled.
The reason is that P4 pmu uses substitute event for cycles when it's already taken (in our case by NMI watchdog), but this event does not give even results like cycles, and we could end up with no samples at all for our short measuring period.

Did you consider increasing the measuring period?

Quoted 32 lines

Quoted 3 lines
Fixing this by using "instructions:u" event instead, which seems to be stable enough.
The original author of this test entry is Adrian, so would be nice for him to take a look and give his Ack, Adrian?
- Arnaldo
Quoted 23 lines
Cc Michael Petlan <[email protected]>
Link http://lkml.kernel.org/n/[email protected] open here
Signed-off-by Jiri Olsa <[email protected]>
---
 tools/perf/tests/switch-tracking.c | 27 +++++++++++++++++++++++++--
 1 file changed, 25 insertions(+), 2 deletions(-)
tools/perf/tests/switch-tracking.c +1 -0
index 65474fd80da7..e519819ea2e5 100644
@@ -10,6 +10,7 @@
 #include "thread_map.h"
 #include "cpumap.h"
 #include "tests.h"
+#include "header.h"
 
 static int spin_sleep(void)
 {
@@ -298,6 +299,27 @@ static int process_events(struct perf_evlist *evlist,
 	return ret;
 }
 

Quoted 15 lines

Quoted 5 lines

tools/perf/tests/switch-tracking.c +5 -0

+static const char *get_hw_counter(void)
+{
+	const char *counter = "cycles:u";
+	char *cpuid;
+

tools/perf/tests/switch-tracking.c static int process_events(struct perf_evlist *evlist, · line 316

Quoted 10 lines

tools/perf/tests/switch-tracking.c +10 -0

+	cpuid = get_cpuid_str();
+
+	/*
+	 * P4 pmu uses substitute event for cycles if it's already
+	 * taken, but it does not give even results like cycles,
+	 * and we could end up with no samples at all for our short
+	 * measuring period. Using "instructions:u" event instead,
+	 * which seems to be stable enough.
+	 */
+	if (!strcmp("GenuineIntel-15-4", cpuid))

Why just model 4? Isn't all family 15 P4?

Quoted 3 lines

tools/perf/tests/switch-tracking.c static int process_events(struct perf_evlist *evlist, · line 319
Quoted 3 lines
tools/perf/tests/switch-tracking.c +3 -0
+		counter = "instructions:u";
+
+	pr_debug("using '%s' HW counter");

tests/switch-tracking.c: In function ‘get_hw_counter’:
tests/switch-tracking.c:319:2: error: format ‘%s’ expects a matching ‘char *’ argument [-Werror=format=]

Quoted 29 lines

Quoted 28 lines

tools/perf/tests/switch-tracking.c +6 -2

+	return counter;
+}
+
 /**
  * test__switch_tracking - test using sched_switch and tracking events.
  *

@@ -308,6 +330,7 @@ static int process_events(struct perf_evlist *evlist,
  */
 int test__switch_tracking(int subtest __maybe_unused)
 {
+	const char *hw_counter = get_hw_counter();
 	const char *sched_switch = "sched:sched_switch";
 	struct switch_tracking switch_tracking = { .tids = NULL, };
 	struct record_opts opts = {

@@ -357,9 +380,9 @@ int test__switch_tracking(int subtest __maybe_unused)
 	cpu_clocks_evsel = perf_evlist__last(evlist);
 
 	/* Second event */
-	err = parse_events(evlist, "cycles:u", NULL);
+	err = parse_events(evlist, hw_counter, NULL);
 	if (err) {
-		pr_debug("Failed to parse event cycles:u\n");
+		pr_debug("Failed to parse event %s\n", hw_counter);
 		goto out_err;
 	}

Signature · 1 line

2.9.4

Jiri Olsa

2017-06-04 19:10 UTC #4 lore raw

Quoted 5 lines · Adrian Hunter

Quoted 4 lines · Arnaldo Carvalho de Melo
Em Fri, May 26, 2017 at 02:31:40PM +0200, Jiri Olsa escreveu:
Quoted 3 lines
The switch tracking test keeps failing on P4 cpu, when NMI watchdog is enabled.

Quoted 7 lines

Quoted 5 lines
Quoted 5 lines
The reason is that P4 pmu uses substitute event for cycles when it's already taken (in our case by NMI watchdog), but this event does not give even results like cycles, and we could end up with no samples at all for our short measuring period.
Did you consider increasing the measuring period?

not really, in some cases I saw no samples generated for bigger periods for another workloads, so I did not think of that in here, but I'll check

SNIP

Quoted 16 lines

static int spin_sleep(void)
{

tools/perf/tests/switch-tracking.c +9 -0

@@ -298,6 +299,27 @@ static int process_events(struct perf_evlist *evlist,
 	return ret;
 }
 
+static const char *get_hw_counter(void)
+{
+	const char *counter = "cycles:u";
+	char *cpuid;
+
+	cpuid = get_cpuid_str();
+
+	/*
+	 * P4 pmu uses substitute event for cycles if it's already

Quoted 8 lines

Quoted 6 lines
tools/perf/tests/switch-tracking.c static int process_events(struct perf_evlist *evlist, · line 316
Quoted 6 lines
tools/perf/tests/switch-tracking.c +6 -0
+	 * taken, but it does not give even results like cycles,
+	 * and we could end up with no samples at all for our short
+	 * measuring period. Using "instructions:u" event instead,
+	 * which seems to be stable enough.
+	 */
+	if (!strcmp("GenuineIntel-15-4", cpuid))
Why just model 4? Isn't all family 15 P4?

I thought there's just one model.. but just based on the kernel code

Quoted 8 lines

Quoted 4 lines
tools/perf/tests/switch-tracking.c static int process_events(struct perf_evlist *evlist, · line 319
Quoted 4 lines
tools/perf/tests/switch-tracking.c +3 -0
+		counter = "instructions:u";
+
+	pr_debug("using '%s' HW counter");
tests/switch-tracking.c: In function ‘get_hw_counter’:
tests/switch-tracking.c:319:2: error: format ‘%s’ expects a matching ‘char *’ argument [-Werror=format=]

omg.. sure ;-)

thanks,
jirka