Subject: Re: "bpf: Improve the info.func_info and info.func_info_rec_size behavior" breaks strace self tests

From: Heiko Carstens <[email-masked]>
Date: Fri, 4 Jan 2019 10:25:24 +0100

On Thu, Jan 03, 2019 at 11:52:51PM +0000, Martin Lau wrote:
> On Thu, Jan 03, 2019 at 11:41:18PM +0100, Heiko Carstens wrote:
> > On Thu, Jan 03, 2019 at 07:12:05PM +0000, Martin Lau wrote:
> > > On Thu, Jan 03, 2019 at 12:46:13PM +0100, Heiko Carstens wrote:
> > > > Hello,
> > > > 
> > > > the kernel commit 7337224fc150 ("bpf: Improve the info.func_info and
> > > > info.func_info_rec_size behavior") breaks one of strace's self tests:
> > > > 
> > > > FAIL: bpf-obj_get_info_by_fd-prog-v.gen
...
> I am running against linux-next.  I don't see how root and non-root affect
> thing here.  I guess the test has been running without jit so far?

Yes, it was disabled. Enabling jit and adding your memset fix leads to
what you report with 2) below.

> 1) root or not, if jit is enabled,
>    without the memset() fix in the bpf-obj_get_info_by_fd.c in my last email,
>    they all failed:
>    [root@arch-fb-vm1 tests]# ./bpf-obj_get_info_by_fd-prog-v.gen.test
>    BPF_OBJ_GET_INFO_BY_FD prog 2 failed: Bad address
>    bpf-obj_get_info_by_fd-prog-v.gen.test: skipped test: ../bpf-obj_get_info_by_fd-prog-v exited with code 77
> 
>    Please fix this first.
> 
> 2) After having the memset fix:
>    Root or not, for jited program, if I run
>    ./bpf-obj_get_info_by_fd-prog-v.gen.test, they failed.  If I read the
>    init.sh correclty, it fails because there is a diff between the
>    ./bpf-obj_get_info_by_fd-prog-v stdout and the "strace -o log".  I think
>    "strace -o log" only has the /* bytes 104..151 */ part if some bytes
>    are non-zero?
> 
>    Regardless, the test program "bpf-obj_get_info_by_fd.c" is telling
>    the kernel that the userspace "info" is in size 168 bytes.
>    The kernel then tells as much details as possible about
>    a bpf prog in "info".  I don't see a ABI breakage here.
> 
>    I believe the test just happens to work so far because it has been running
>    without jit?
> 
>    If I run it with jit enabled:
> -bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=168, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=35, tag="\xda\xbf\x02\x07\xd1\x99\x24\x86", jited_prog_len=0 => 110, jited_prog_insns=NULL, xlated_prog_len=0 => 120, xlated_prog_insns=[], load_time=2476906063975, created_by_uid=0, nr_map_ids=0 => 1, map_ids=[], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = 0
> -bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=168, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=35, tag="\xda\xbf\x02\x07\xd1\x99\x24\x86", jited_prog_len=0 => 110, jited_prog_insns=NULL, xlated_prog_len=0 => 120, xlated_prog_insns=[], load_time=2476906063975, created_by_uid=0, nr_map_ids=2 => 1, map_ids=[36], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = 0
> +bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=168, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=35, tag="\xda\xbf\x02\x07\xd1\x99\x24\x86", jited_prog_len=0 => 110, jited_prog_insns=NULL, xlated_prog_len=0 => 120, xlated_prog_insns=[], load_time=2476906063975, created_by_uid=0, nr_map_ids=0 => 1, map_ids=[], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..167 */ "\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = 0
> +bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=168, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=35, tag="\xda\xbf\x02\x07\xd1\x99\x24\x86", jited_prog_len=0 => 110, jited_prog_insns=NULL, xlated_prog_len=0 => 120, xlated_prog_insns=[], load_time=2476906063975, created_by_uid=0, nr_map_ids=2 => 1, map_ids=[36], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..167 */ "\x01\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = 0
> 
>   The diff comes in as early as byte 104-th which is the nr_jited_ksyms == 1.
> 
>   Please fix the test program.  A protential fix is in bpf-obj_get_info_by_fd.c
>   to printf the non-zero "/* bytes 104..1xx */..." the same way as the
>   "strace -o log" does.

Thanks a lot for looking into this!
Eugene, Dmitry will you take care of fixing this?