Re: WARNING in __mark_chain_precision

From: Yonghong Song
Date: Wed Dec 28 2022 - 00:24:26 EST



On 12/20/22 4:30 PM, Andrii Nakryiko wrote:
On Mon, Dec 19, 2022 at 11:13 AM <sdf@xxxxxxxxxx> wrote:

On 12/19, Hao Sun wrote:
Hi,

The following backtracking bug can be triggered on the latest bpf-next and
Linux 6.1 with the C prog provided. I don't have enough knowledge about
this part in the verifier, don't know how to fix this.

Maybe something related to commit be2ef8161572 ("bpf: allow precision
tracking
for programs with subprogs") and/or the related ones?


This can be reproduced on:

HEAD commit: 0e43662e61f2 tools/resolve_btfids: Use pkg-config to locate
libelf
git tree: bpf-next
console log: https://pastebin.com/raw/45hZ7iqm
kernel config: https://pastebin.com/raw/0pu1CHRm
C reproducer: https://pastebin.com/raw/tqsiezvT

func#0 @0
0: R1=ctx(off=0,imm=0) R10=fp0
0: (18) r2 = 0x8000000000000 ; R2_w=2251799813685248
2: (18) r6 = 0xffff888027358000 ;
R6_w=map_ptr(off=0,ks=3032,vs=3664,imm=0)
4: (18) r7 = 0xffff88802735a000 ;
R7_w=map_ptr(off=0,ks=156,vs=2624,imm=0)
6: (18) r8 = 0xffff88802735e000 ;
R8_w=map_ptr(off=0,ks=2396,vs=76,imm=0)
8: (18) r9 = 0x8e9700000000 ; R9_w=156779191205888
10: (36) if w9 >= 0xffffffe3 goto pc+1
last_idx 10 first_idx 0
regs=200 stack=0 before 8: (18) r9 = 0x8e9700000000
11: R9_w=156779191205888
11: (85) call #0
12: (cc) w2 s>>= w7

w2 should have been set to NOT_INIT (because r1-r5 are clobbered by
calls) and rejected here as !read_ok (see check_reg_arg()) before
attempting to mark precision for r2. Can you please try to debug and
understand why that didn't happen here?

The verifier is doing the right thing here and the 'call #0' does
implicitly cleared r1-r5.

So for 'w2 s>>= w7', since w2 is used, the verifier tries to find
its definition by backtracing. It encountered 'call #0', which clears
r1-r5. Since w2 is not defined, the verifier issued the error:
BUG regs 4

The specific verifier code is in backtrack_insn():

} else if (class == BPF_JMP || class == BPF_JMP32) {
if (opcode == BPF_CALL) {
if (insn->src_reg == BPF_PSEUDO_CALL)
return -ENOTSUPP;
/* BPF helpers that invoke callback subprogs are
* equivalent to BPF_PSEUDO_CALL above
*/
if (insn->src_reg == 0 && is_callback_calling_function(insn->imm))
return -ENOTSUPP;
/* regular helper call sets R0 */
*reg_mask &= ~1;
if (*reg_mask & 0x3f) {
/* if backtracing was looking for registers R1-R5
* they should have been found already.
*/
verbose(env, "BUG regs %x\n", *reg_mask);
WARN_ONCE(1, "verifier backtracking bug");
return -EFAULT;
}
}

Note that the above mask '0x3f' which corresponds to registers r1-r5.
If it tries to find the definition for any of them, 'BUG regs <mask>'
will be printed out.




last_idx 12 first_idx 12
parent didn't have regs=4 stack=0 marks: R1=ctx(off=0,imm=0)
R2_rw=P2251799813685248 R6_w=map_ptr(off=0,ks=3032,vs=3664,imm=0)
R7_rw=map_ptr(off=0,ks=156,vs=2624,imm=0)
R8_w=map_ptr(off=0,ks=2396,vs=76,imm=0) R9_w=156779191205888 R10=fp0
last_idx 11 first_idx 0
regs=4 stack=0 before 11: (85) call #0
BUG regs 4
processed 8 insns (limit 1000000) max_states_per_insn 0 total_states 1
peak_states 1 mark_read 1

------------[ cut here ]------------
verifier backtracking bug
WARNING: CPU: 6 PID: 8646 at kernel/bpf/verifier.c:2756 backtrack_insn
kernel/bpf/verifier.c:2756 [inline]
WARNING: CPU: 6 PID: 8646 at kernel/bpf/verifier.c:2756
__mark_chain_precision+0x1baf/0x1d70 kernel/bpf/verifier.c:3065
Modules linked in:
CPU: 6 PID: 8646 Comm: a.out Not tainted 6.1.0-09634-g0e43662e61f2 #146
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Arch Linux
1.16.1-1-1 04/01/2014
RIP: 0010:backtrack_insn kernel/bpf/verifier.c:2756 [inline]
RIP: 0010:__mark_chain_precision+0x1baf/0x1d70 kernel/bpf/verifier.c:3065
Code: 0d 31 ff 89 de e8 91 ec ed ff 84 db 0f 85 ef fe ff ff e8 b4 f0
ed ff 48 c7 c7 e0 8f 53 8a c6 05 28 71 ab 0d 01 e8 83 b3 1e 08 <0f> 0b
e9 50 f8 ff ff 48 8b 74 24 38 48 c7 c7 80 d0 63 8d e8 49 46
RSP: 0018:ffffc9001463f1a0 EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: ffff888020470000 RSI: ffffffff816662c0 RDI: fffff520028c7e26
RBP: 0000000000000004 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000080000000 R11: 0000000000000000 R12: 0000000000000020
R13: dffffc0000000000 R14: 000000000000000b R15: ffff88802be74000
FS: 00007fd3daeb8440(0000) GS:ffff888063980000(0000)
knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000020000240 CR3: 0000000017394000 CR4: 0000000000750ee0
PKRU: 55555554
Call Trace:
<TASK>
mark_chain_precision kernel/bpf/verifier.c:3165 [inline]
adjust_reg_min_max_vals+0x981/0x58d0 kernel/bpf/verifier.c:10715
check_alu_op+0x380/0x1820 kernel/bpf/verifier.c:10928
do_check kernel/bpf/verifier.c:13821 [inline]
do_check_common+0x1c3b/0xe520 kernel/bpf/verifier.c:16289
do_check_main kernel/bpf/verifier.c:16352 [inline]
bpf_check+0x83b4/0xb310 kernel/bpf/verifier.c:16936
bpf_prog_load+0xf7a/0x21a0 kernel/bpf/syscall.c:2619
__sys_bpf+0xf03/0x5840 kernel/bpf/syscall.c:4979
__do_sys_bpf kernel/bpf/syscall.c:5083 [inline]
__se_sys_bpf kernel/bpf/syscall.c:5081 [inline]
__x64_sys_bpf+0x78/0xc0 kernel/bpf/syscall.c:5081
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x38/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fd3da8e4469
Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48
89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d
01 f0 ff ff 73 01 c3 48 8b 0d ff 49 2b 00 f7 d8 64 89 01 48
RSP: 002b:00007fff090c1a78 EFLAGS: 00000246 ORIG_RAX: 0000000000000141
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd3da8e4469
RDX: 0000000000000080 RSI: 0000000020000840 RDI: 0000000000000005
RBP: 00007fff090c2a90 R08: 00007fd3da92e160 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000561aefc006c0
R13: 00007fff090c2b70 R14: 0000000000000000 R15: 0000000000000000
</TASK>