Re: [PATCH bpf-next] selftests/bpf: relax expected log messages to allow emitting BPF_ST

Yonghong Song <yonghong.song@xxxxxxxxx> · Tue, 8 Aug 2023 16:17:14 -0700

On 8/8/23 4:04 PM, Eduard Zingerman wrote:
On Tue, 2023-08-08 at 15:51 -0700, Yonghong Song wrote:

On 8/8/23 9:27 AM, Eduard Zingerman wrote:
Update [1] to LLVM BPF backend seeks to enable generation of BPF_ST
instruction when CPUv4 is selected. This affects expected log messages
for the following selftests:
- log_fixup/missing_map
- spin_lock/lock_id_mapval_preserve
- spin_lock/lock_id_innermapval_preserve

Expected messages in these tests hard-code instruction numbers for BPF
programs compiled from C. These instruction numbers change when
BPF_ST is allowed because single BPF_ST instruction replaces a pair of
BPF_MOV/BPF_STX instructions, e.g.:

      r1 = 42;
      *(u32 *)(r10 - 8) = r1;  --->  *(u32 *)(r10 - 8) = 42;

This commit updates expected log messages to avoid matching specific
instruction numbers (program position still could be uniquely
identified).

[1] https://reviews.llvm.org/D140804
      "[BPF] support for BPF_ST instruction in codegen"

Signed-off-by: Eduard Zingerman <eddyz87@xxxxxxxxx>
---
   .../selftests/bpf/prog_tests/log_fixup.c      |  2 +-
   .../selftests/bpf/prog_tests/spin_lock.c      | 37 ++++++++++++++++---
   2 files changed, 33 insertions(+), 6 deletions(-)

diff --git a/tools/testing/selftests/bpf/prog_tests/log_fixup.c b/tools/testing/selftests/bpf/prog_tests/log_fixup.c
index dba71d98a227..effd78b2a657 100644
--- a/tools/testing/selftests/bpf/prog_tests/log_fixup.c
+++ b/tools/testing/selftests/bpf/prog_tests/log_fixup.c
@@ -124,7 +124,7 @@ static void missing_map(void)
   	ASSERT_FALSE(bpf_map__autocreate(skel->maps.missing_map), "missing_map_autocreate");
   
   	ASSERT_HAS_SUBSTR(log_buf,
-			  "8: <invalid BPF map reference>\n"
+			  ": <invalid BPF map reference>\n"
   			  "BPF map 'missing_map' is referenced but wasn't created\n",
   			  "log_buf");
   
diff --git a/tools/testing/selftests/bpf/prog_tests/spin_lock.c b/tools/testing/selftests/bpf/prog_tests/spin_lock.c
index d9270bd3d920..f29c08d93beb 100644
--- a/tools/testing/selftests/bpf/prog_tests/spin_lock.c
+++ b/tools/testing/selftests/bpf/prog_tests/spin_lock.c
@@ -1,4 +1,5 @@
   // SPDX-License-Identifier: GPL-2.0
+#include <regex.h>
   #include <test_progs.h>
   #include <network_helpers.h>
   
@@ -19,12 +20,16 @@ static struct {
   	  "; R1_w=map_value(off=0,ks=4,vs=4,imm=0)\n2: (85) call bpf_this_cpu_ptr#154\n"
   	  "R1 type=map_value expected=percpu_ptr_" },
   	{ "lock_id_mapval_preserve",
-	  "8: (bf) r1 = r0                       ; R0_w=map_value(id=1,off=0,ks=4,vs=8,imm=0) "
-	  "R1_w=map_value(id=1,off=0,ks=4,vs=8,imm=0)\n9: (85) call bpf_this_cpu_ptr#154\n"
+	  "[0-9]\\+: (bf) r1 = r0                       ;"
+	  " R0_w=map_value(id=1,off=0,ks=4,vs=8,imm=0)"
+	  " R1_w=map_value(id=1,off=0,ks=4,vs=8,imm=0)\n"
+	  "[0-9]\\+: (85) call bpf_this_cpu_ptr#154\n"
   	  "R1 type=map_value expected=percpu_ptr_" },
   	{ "lock_id_innermapval_preserve",
-	  "13: (bf) r1 = r0                      ; R0=map_value(id=2,off=0,ks=4,vs=8,imm=0) "
-	  "R1_w=map_value(id=2,off=0,ks=4,vs=8,imm=0)\n14: (85) call bpf_this_cpu_ptr#154\n"
+	  "[0-9]\\+: (bf) r1 = r0                      ;"
+	  " R0=map_value(id=2,off=0,ks=4,vs=8,imm=0)"
+	  " R1_w=map_value(id=2,off=0,ks=4,vs=8,imm=0)\n"
+	  "[0-9]\\+: (85) call bpf_this_cpu_ptr#154\n"
   	  "R1 type=map_value expected=percpu_ptr_" },
   	{ "lock_id_mismatch_kptr_kptr", "bpf_spin_unlock of different lock" },
   	{ "lock_id_mismatch_kptr_global", "bpf_spin_unlock of different lock" },
@@ -45,6 +50,24 @@ static struct {
   	{ "lock_id_mismatch_innermapval_mapval", "bpf_spin_unlock of different lock" },
   };
   
+static int match_regex(const char *pattern, const char *string)
+{
+	int err, rc;
+	regex_t re;
+
+	err = regcomp(&re, pattern, REG_NOSUB);
+	if (err) {
+		char errbuf[512];
+
+		regerror(err, &re, errbuf, sizeof(errbuf));
+		PRINT_FAIL("Can't compile regex: %s\n", errbuf);
+		return -1;
+	}
+	rc = regexec(&re, string, 0, NULL, 0);
+	regfree(&re);
+	return rc == 0 ? 1 : 0;
+}
+
   static void test_spin_lock_fail_prog(const char *prog_name, const char *err_msg)
   {
   	LIBBPF_OPTS(bpf_object_open_opts, opts, .kernel_log_buf = log_buf,
@@ -74,7 +97,11 @@ static void test_spin_lock_fail_prog(const char *prog_name, const char *err_msg)
   		goto end;
   	}
   
-	if (!ASSERT_OK_PTR(strstr(log_buf, err_msg), "expected error message")) {
+	ret = match_regex(err_msg, log_buf);
+	if (!ASSERT_GE(ret, 0, "match_regex"))

Should this be ASSERT_GT(ret, 0) or ASSERT_EQ(ret, 1)?
If IIUC, regexec return 0 means a successful match.
So in 'match_regex', a successful match will return 1, right?

Right `match_regex` has three possible return values:
. -1 if regex could not be compiled
.  0 if regex is ok but match fails
.  1 if regex is ok and match is found

I check for -1 in this ASSERT_GE, and for 1 in the ASSERT_TRUE right
below in order to have two separate error messages.

But maybe that is not necessary as I already have PRINT_FAIL in the
match_regex for -1 exit. So it would be possible to figure out what
failed: regcomp or regexec even if I replace ASSERT_GE/ASSERT_TRUE
with a single ASSERT_TRUE (or ASSERT_EQ(ret, 1)) as you suggest.

Sorry, I think I missed the below change. It looks original intention
is to print out expected/actual in case of failure. So your patch
looks good to me.

Acked-by: Yonghong Song <yonghong.song@xxxxxxxxx>



+		goto end;
+
+	if (!ASSERT_TRUE(ret, "no match for expected error message")) {
   		fprintf(stderr, "Expected: %s\n", err_msg);
   		fprintf(stderr, "Verifier: %s\n", log_buf);
   	}








