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
Looking into the kernel commit, it seems that the user space visible
uapi change is intentional; even though it might break existing user
space.
To reproduce:
git clone https://gitlab.com/strace/strace.git
cd strace
./bootstrap
./configure
make -j $(nproc)
cd tests
make -j $(nproc) check
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
The strace's bpf-obj_get_info_by_fd-prog-v test did fail. However,
I failed to see how 7337224fc150 broke it. How do you trace down to
commit 7337224fc150 and can you share your test output?
The failure I can reproduce is EFAULT. It should have been failing
as early as "nr_jited_ksyms" is added to "struct bpf_prog_info"
in linux/bpf.h.
The sys_bpf(BPF_OBJ_GET_INFO_BY_FD, &bpf_prog_get_info_attr, ...) is called
in a loop. The bpf_prog_get_info_attr.info object is in size 104 but
bpf_prog_get_info_attr.info_len is in size 168. Hence,
if the prog is jited, the second iteraton onwards will have nr_jited_ksyms == 1
which is asking the kernel to fill the bpf_prog_get_info_attr.info.jited_ksyms
and it is NULL.
This fix the strace's test program:
diff --git i/tests/bpf-obj_get_info_by_fd.c w/tests/bpf-obj_get_info_by_fd.c
index e95afda27b3d..953083720822 100644
--- i/tests/bpf-obj_get_info_by_fd.c
+++ w/tests/bpf-obj_get_info_by_fd.c
@@ -19,6 +19,7 @@
#include <stdint.h>
#include <stdlib.h>
#include <unistd.h>
+#include <string.h>
#include <sys/sysmacros.h>
#include <asm/unistd.h>
@@ -341,6 +342,7 @@ main(void)
size_t old_prog_info_len = PROG_INFO_SZ;
for (unsigned int i = 0; i < 4; i++) {
+ memset(prog_info + 1, 0, PROG_INFO_SZ - sizeof(*prog_info));
prog_info->jited_prog_len = 0;
switch (i) {
case 1:
After the above change:
[root@arch-fb-vm1 tests]# ./bpf-obj_get_info_by_fd-prog-v
bpf(BPF_MAP_CREATE, {map_type=BPF_MAP_TYPE_ARRAY, key_size=4, value_size=8, max_entries=1, map_flags=0, inner_map_fd=0</dev/null>, map_name="test_map", map_ifindex=0}, 48) = 3<anon_inode:bpf-map>
bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_SOCKET_FILTER, insn_cnt=9, insns=[{code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_1, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_STX|BPF_W|BPF_MEM, dst_reg=BPF_REG_10, src_reg=BPF_REG_1, off=-4, imm=0}, {code=BPF_ALU64|BPF_X|BPF_MOV, dst_reg=BPF_REG_2, src_reg=BPF_REG_10, off=0, imm=0}, {code=BPF_ALU64|BPF_K|BPF_ADD, dst_reg=BPF_REG_2, src_reg=BPF_REG_0, off=0, imm=0xfffffffc}, {code=BPF_LD|BPF_DW|BPF_IMM, dst_reg=BPF_REG_1, src_reg=BPF_REG_1, off=0, imm=0x3}, {code=BPF_LD|BPF_W|BPF_IMM, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_CALL, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0x1}, {code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_EXIT, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}], license="BSD", log_level=42, log_size=4096, log_buf="", kern_version=KERNEL_VERSION(57005, 192, 222), prog_flags=0, prog_name="test_prog", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 72) = 4<anon_inode:bpf-prog>
bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=3<anon_inode:bpf-map>, info_len=128 => 80, info={type=BPF_MAP_TYPE_ARRAY, id=13, key_size=4, value_size=8, max_entries=1, map_flags=0, name="test_map", 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=12, 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=NULL, load_time=1360454956729, created_by_uid=0, nr_map_ids=0 => 1, map_ids=NULL, 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=12, tag="\xda\xbf\x02\x07\xd1\x99\x24\x86", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=336, xlated_prog_insns=0x7fda42a02000, load_time=1360454956729, created_by_uid=0, nr_map_ids=2, map_ids=0x7fda429f5000, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = -1 EFAULT (Bad address)
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=12, 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=1360454956729, 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=12, 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=1360454956729, created_by_uid=0, nr_map_ids=2 => 1, map_ids=[13], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = 0
+++ exited with 0 +++
>
> Looking into the kernel commit, it seems that the user space visible
> uapi change is intentional; even though it might break existing user
> space.
>
> To reproduce:
>
> git clone https://urldefense.proofpoint.com/v2/url?u=https-3A__gitlab.com_strace_strace.git&d=DwIDAg&c=5VD0RTtNlTh3ycd41b3MUw&r=VQnoQ7LvghIj0gVEaiQSUw&m=0KV2Bnx31aCm6v7x7mYMZ26wy_rnRwk6QrpXEXP0CIE&s=c7S2IRhn_p6FF1Z2HrhC8mAMvncVDYMPpLxhvftDlV8&e=
> cd strace
> ./bootstrap
> ./configure
> make -j $(nproc)
> cd tests
> make -j $(nproc) check
>
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
> The strace's bpf-obj_get_info_by_fd-prog-v test did fail. However,
> I failed to see how 7337224fc150 broke it. How do you trace down to
> commit 7337224fc150 and can you share your test output?
>
> The failure I can reproduce is EFAULT. It should have been failing
> as early as "nr_jited_ksyms" is added to "struct bpf_prog_info"
> in linux/bpf.h.
Ah, sorry(!), I forgot to mention an important detail: the test
failure happens only if executed as normal (non-root) user.
With 7337224fc150 ("bpf: Improve the info.func_info and
info.func_info_rec_size behavior") the failure happens. With commit
30da46b5dc3a ("tools: bpftool: add a command to dump the trace pipe")
it passes; which is one commit earlier.
FAIL: bpf-obj_get_info_by_fd-prog-v.gen
=======================================
--- exp 2019-01-03 23:31:49.576949303 +0100
+++ log 2019-01-03 23:31:49.576949303 +0100
@@ -1,8 +1,8 @@
bpf(BPF_MAP_CREATE, {map_type=BPF_MAP_TYPE_ARRAY, key_size=4, value_size=8, max_entries=1, map_flags=0, inner_map_fd=0</dev/null>, map_name="test_map", map_ifindex=0}, 48) = 3<anon_inode:bpf-map>
bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_SOCKET_FILTER, insn_cnt=9, insns=[{code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_1, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_STX|BPF_W|BPF_MEM, dst_reg=BPF_REG_10, src_reg=BPF_REG_1, off=-4, imm=0}, {code=BPF_ALU64|BPF_X|BPF_MOV, dst_reg=BPF_REG_2, src_reg=BPF_REG_10, off=0, imm=0}, {code=BPF_ALU64|BPF_K|BPF_ADD, dst_reg=BPF_REG_2, src_reg=BPF_REG_0, off=0, imm=0xfffffffc}, {code=BPF_LD|BPF_DW|BPF_IMM, dst_reg=BPF_REG_1, src_reg=BPF_REG_1, off=0, imm=0x3}, {code=BPF_LD|BPF_W|BPF_IMM, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_CALL, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0x1}, {code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_EXIT, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}], license="BSD", log_level=42, log_size=4096, log_buf="", kern_version=KERNEL_VERSION(57005, 192, 222), prog_flags=0, prog_name="test_prog", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 72) = 4<anon_inode:bpf-prog>
bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=3<anon_inode:bpf-map>, info_len=128 => 80, info={type=BPF_MAP_TYPE_ARRAY, id=15, key_size=4, value_size=8, max_entries=1, map_flags=0, name="test_map", 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 => 152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=NULL, load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=NULL, 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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=336, xlated_prog_insns=0x3ff8d6f7000, load_time=28281352029, created_by_uid=1000, nr_map_ids=2, map_ids=0x3ff8d6f1000, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = -1 EFAULT (Bad address)
-bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, 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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=2 => 1, map_ids=[15], 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 => 152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=NULL, load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=NULL, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=336, xlated_prog_insns=0x3ff8d6f7000, load_time=28281352029, created_by_uid=1000, nr_map_ids=2, map_ids=0x3ff8d6f1000, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = -1 EFAULT (Bad address)
+bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=[], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=2 => 1, map_ids=[15], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = 0
+++ exited with 0 +++
bpf-obj_get_info_by_fd-prog-v.gen.test: failed test: ../../strace -a20 -y -v -e trace=bpf ../bpf-obj_get_info_by_fd-prog-v output mismatch
FAIL bpf-obj_get_info_by_fd-prog-v.gen.test (exit status: 1)
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
> > The strace's bpf-obj_get_info_by_fd-prog-v test did fail. However,
> > I failed to see how 7337224fc150 broke it. How do you trace down to
> > commit 7337224fc150 and can you share your test output?
> >
> > The failure I can reproduce is EFAULT. It should have been failing
> > as early as "nr_jited_ksyms" is added to "struct bpf_prog_info"
> > in linux/bpf.h.
>
> Ah, sorry(!), I forgot to mention an important detail: the test
> failure happens only if executed as normal (non-root) user.
>
> With 7337224fc150 ("bpf: Improve the info.func_info and
> info.func_info_rec_size behavior") the failure happens. With commit
> 30da46b5dc3a ("tools: bpftool: add a command to dump the trace pipe")
> it passes; which is one commit earlier.
>
> FAIL: bpf-obj_get_info_by_fd-prog-v.gen
> =======================================
>
> --- exp 2019-01-03 23:31:49.576949303 +0100
> +++ log 2019-01-03 23:31:49.576949303 +0100
> @@ -1,8 +1,8 @@
> bpf(BPF_MAP_CREATE, {map_type=BPF_MAP_TYPE_ARRAY, key_size=4, value_size=8, max_entries=1, map_flags=0, inner_map_fd=0</dev/null>, map_name="test_map", map_ifindex=0}, 48) = 3<anon_inode:bpf-map>
> bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_SOCKET_FILTER, insn_cnt=9, insns=[{code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_1, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_STX|BPF_W|BPF_MEM, dst_reg=BPF_REG_10, src_reg=BPF_REG_1, off=-4, imm=0}, {code=BPF_ALU64|BPF_X|BPF_MOV, dst_reg=BPF_REG_2, src_reg=BPF_REG_10, off=0, imm=0}, {code=BPF_ALU64|BPF_K|BPF_ADD, dst_reg=BPF_REG_2, src_reg=BPF_REG_0, off=0, imm=0xfffffffc}, {code=BPF_LD|BPF_DW|BPF_IMM, dst_reg=BPF_REG_1, src_reg=BPF_REG_1, off=0, imm=0x3}, {code=BPF_LD|BPF_W|BPF_IMM, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_CALL, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0x1}, {code=BPF_ALU64|BPF_K|BPF_MOV, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}, {code=BPF_JMP|BPF_K|BPF_EXIT, dst_reg=BPF_REG_0, src_reg=BPF_REG_0, off=0, imm=0}], license="BSD", log_level=42, log_size=4096, log_buf="", kern_version=KERNEL_VERSION(57005, 192, 222), prog_flags=0, prog_name="test_prog", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 72) = 4<anon_inode:bpf-prog>
> bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=3<anon_inode:bpf-map>, info_len=128 => 80, info={type=BPF_MAP_TYPE_ARRAY, id=15, key_size=4, value_size=8, max_entries=1, map_flags=0, name="test_map", 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 => 152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=NULL, load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=NULL, 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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=336, xlated_prog_insns=0x3ff8d6f7000, load_time=28281352029, created_by_uid=1000, nr_map_ids=2, map_ids=0x3ff8d6f1000, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0}}}, 16) = -1 EFAULT (Bad address)
> -bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, 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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=2 => 1, map_ids=[15], 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 => 152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=NULL, load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=NULL, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=336, xlated_prog_insns=0x3ff8d6f7000, load_time=28281352029, created_by_uid=1000, nr_map_ids=2, map_ids=0x3ff8d6f1000, name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = -1 EFAULT (Bad address)
> +bpf(BPF_OBJ_GET_INFO_BY_FD, {info={bpf_fd=4<anon_inode:bpf-prog>, info_len=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=0 => 1, map_ids=[], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\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=152, info={type=BPF_PROG_TYPE_SOCKET_FILTER, id=8, tag="\xde\x90\x83\x18\xfb\x16\xd8\x9c", jited_prog_len=0, jited_prog_insns=NULL, xlated_prog_len=0, xlated_prog_insns=[], load_time=28281352029, created_by_uid=1000, nr_map_ids=2 => 1, map_ids=[15], name="test_prog", ifindex=0, netns_dev=makedev(0, 0), netns_ino=0, /* bytes 104..151 */ "\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\x08\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"}}}, 16) = 0
> +++ exited with 0 +++
> bpf-obj_get_info_by_fd-prog-v.gen.test: failed test: ../../strace -a20 -y -v -e trace=bpf ../bpf-obj_get_info_by_fd-prog-v output mismatch
> FAIL bpf-obj_get_info_by_fd-prog-v.gen.test (exit status: 1)
>
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?
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.
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?
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