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

From: "Dmitry V. Levin" <[email-masked]>
Date: Sat, 5 Jan 2019 02:13:59 +0300

On Fri, Jan 04, 2019 at 10:25:24AM +0100, Heiko Carstens wrote:
> 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?

Thanks for reporting this!

AFAICT, the test in question was specifically designed to check whether
the strace printer of BPF_OBJ_GET_INFO_BY_FD command is up to date with
the kernel, and this failure means strace has to be updated for new
features added after v4.20.  Eugene, please correct me if I'm wrong.

-- 
ldv