On 6/15/21 7:21 PM, Tony Ambardar wrote:

On Sun, 13 Jun 2021 at 23:14, Yonghong Song [off-list ref] wrote:

quoted

On 6/12/21 5:07 PM, Tony Ambardar wrote:

quoted

On Fri, 11 Jun 2021 at 08:57, Yonghong Song [off-list ref] wrote:

quoted

On 6/10/21 6:02 PM, Tony Ambardar wrote:

quoted

Hello,

I encountered an NPE and kernel Oops [1] while running the
'test_verifier' selftest on MIPS32 with LTS kernel 5.10.41. This was
observed during development of a MIPS32 JIT but is verifier-related.

Initial troubleshooting [2] points to an unchecked NULL dereference in
btf_type_by_id(), with an unexpected BTF type ID. The root cause is
unclear, whether source of the ID or a potential underlying BTF
problem.

Do you know what is the faulty btf ID number? What is the maximum id
for vmlinux BTF?

Thanks for the suggestions, Yonghong.

I had built/packaged bpftool for the target, which shows the maximum as:

    root@OpenWrt:~# bpftool btf dump file /sys/kernel/btf/vmlinux format
raw|tail -5
    [43179] FUNC 'pci_load_of_ranges' type_id=43178 linkage=static
    [43180] ARRAY '(anon)' type_id=23 index_type_id=23 nr_elems=16
    [43181] FUNC 'pcibios_plat_dev_init' type_id=29264 linkage=static
    [43182] FUNC 'pcibios_map_irq' type_id=29815 linkage=static
    [43183] FUNC 'mips_pcibios_init' type_id=115 linkage=static

After adding NULL handling and debug pr_err() to kernel_type_name(), I next see:

    root@OpenWrt:~# ./test_verifier_eb 828
    [   87.196692] btf_type_by_id(btf_vmlinux, 3062497280) returns NULL
    [   87.196958] btf_type_by_id(btf_vmlinux, 2936995840) returns NULL
    #828/p reference tracking: bpf_sk_release(btf_tcp_sock) FAIL

Those large type ids make me suspect an endianness issue, even though bpftool
can still properly access the vmlinux BTF. Changing byte order and
looking up the
resulting type ids seems to confirm this:

    Check endianness:
      3062497280 -> 0xB68A0000 --swap endian--> 0x00008AB6 -> 35510
    bpftool btf dump file /sys/kernel/btf/vmlinux format raw|fgrep "[35510]":
      [35510] STRUCT 'tcp_sock' size=1752 vlen=136

    Check endianness:
      2936995840 -> 0xAF0F0000 --swap endian--> 0x00000FAF -> 4015
    bpftool btf dump file /sys/kernel/btf/vmlinux format raw|fgrep "[4015]":
      [4015] STRUCT 'sock_common' size=112 vlen=25

As a further test, I repeated "test_verifier 828" across mips{32,64}{be,le}
systems and confirm seeing the problem only with the big-endian ones.

  From the above information, looks like vmlinux BTF is correct.
Below resolve_btfids command output seems indicating the btf_id list
is also correct.

The kernel_type_name is used in a few places for verifier verbose output.

$ grep kernel_type_name kernel/bpf/verifier.c
static const char *kernel_type_name(const struct btf* btf, u32 id)
                                  verbose(env, "%s",
kernel_type_name(reg->btf, reg->btf_id));
                                  regno, kernel_type_name(reg->btf,
reg->btf_id),
                                  kernel_type_name(btf_vmlinux,
*arg_btf_id));

The most suspicous target is reg->btf_id, which is propagated from
the result of bpf_sk_lookup_tcp() helper.

quoted

quoted

The involved helper is bpf_sk_release.

static const struct bpf_func_proto bpf_sk_release_proto = {
           .func           = bpf_sk_release,
           .gpl_only       = false,
           .ret_type       = RET_INTEGER,
           .arg1_type      = ARG_PTR_TO_BTF_ID_SOCK_COMMON,
};

Eventually, the btf_id is taken from btf_sock_ids[6] where
btf_sock_ids is a kernel global variable.

Could you check btf_sock_ids[6] to see whether the number
makes sense?

What I see matches the second btf_type_by_id() NULL call above:
    [   56.556121] btf_sock_ids[6]: 2936995840

quoted

The id is computed by resolve_btfids in
tools/bpf/resolve_btfids, you might add verbose mode to your linux build
to get more information.

The verbose build didn't print any details of the btf ids. Was there anything
special to do in invocation? I manually ran "resolve_btfids -v vmlinux" from
the build dir and this, strangely, gave slightly different results than bpftool
but not the huge endian-swapped type ids. Is this expected?

    # ./tools/bpf/resolve_btfids/resolve_btfids -v vmlinux
    ...
    patching addr   116: ID   35522 [tcp_sock]
    ...
    patching addr   112: ID    4021 [sock_common]

Do any of the details above help narrow down things? What do you suggest
for next steps?

We need to identify issues by dumping detailed verifier logs.
Could you apply the following change?

--- a/tools/testing/selftests/bpf/test_verifier.c
+++ b/tools/testing/selftests/bpf/test_verifier.c

@@ -1088,7 +1088,7 @@ static void do_test_single(struct bpf_test *test,

bool unpriv,
          attr.insns_cnt = prog_len;
          attr.license = "GPL";
          if (verbose)
-               attr.log_level = 1;
+               attr.log_level = 3;
          else if (expected_ret == VERBOSE_ACCEPT)
                  attr.log_level = 2;
          else

Run command like `./test_verifier -v 828 828`?

I attached the verifier output for x86_64.
Maybe by comparing x86 output vs. mips32 output, you can
find which insn starts to have *wrong* verifier state
and then we can go from there.

I realized too late your test output must be for a different kernel version as
well as arch, as the test numbering is different and doesn't match my test:
"reference tracking: bpf_sk_release(btf_tcp_sock)".

Given the problem is seen on big-endian and not little-systems, I applied
your patch for both mips32 variant systems and recaptured log output,
which should make for a stricter A/B comparison. I also kept my earlier
patches to catch the NULLs and print debug info.

The logs are identical until insn #18, where the failing MIPS32BE shows:

18: R0_w=ptr_or_null_(null)(id=3,off=0,imm=0)
R6_w=sock(id=0,ref_obj_id=2,off=0,imm=0) R10=fp0 fp-8=????0000
fp-16=0000mmmm fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmmmmmm
fp-48=mmmmmmmm refs=2

while the succeed MIPS32LE test shows:

18: R0_w=ptr_or_null_tcp_sock(id=3,off=0,imm=0)
R6_w=sock(id=0,ref_obj_id=2,off=0,imm=0) R10=fp0 fp-8=????0000
fp-16=0000mmmm fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmmmmmm
fp-48=mmmmmmmm refs=2

There are then further differences you can see in the attached logs. It's
not clear to me what these differences mean however. Any ideas?

The above R0_w is to capture the return value for bpf_skc_to_tcp_sock()

const struct bpf_func_proto bpf_skc_to_tcp_sock_proto = {
         .func                   = bpf_skc_to_tcp_sock,
         .gpl_only               = false,
         .ret_type               = RET_PTR_TO_BTF_ID_OR_NULL,
         .arg1_type              = ARG_PTR_TO_BTF_ID_SOCK_COMMON,
         .ret_btf_id             = &btf_sock_ids[BTF_SOCK_TYPE_TCP],
};

 From the above func_proto, it should return the btf_id for
btf_sock_ids[BTF_SOCK_TYPE_TCP].

It does like the root cause is still endianness of btf_sock_ids
written by resolve_btfids.

Following your earlier comments on the large, endian-swapped values
in btf_sock_ids[6], I noticed this is true of all btf_sock_ids[]
elements, based on debug output:

     btf_sock_ids[0] = 2139684864
     btf_sock_ids[1] = 2794061824
     btf_sock_ids[2] = 2844459008
     btf_sock_ids[3] = 1234305024
     btf_sock_ids[4] = 3809411072
     btf_sock_ids[5] = 1946812416
     btf_sock_ids[6] = 2936995840
     btf_sock_ids[7] = 3062497280
     btf_sock_ids[8] = 2861236224
     btf_sock_ids[9] = 1251082240
     btf_sock_ids[10] = 1334968320
     btf_sock_ids[11] = 1267859456
     btf_sock_ids[12] = 1318191104

If these are populated by resolve_btfids, how could we re-verify that
it's being done properly?

quoted

quoted

Thanks,
Tony

[...]