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

[Yonghong Song <yonghong.song@linux.dev>]

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@gmail.com>
> ---
>   .../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?

> +		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);
>   	}