bpf.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH bpf-next] bpf: make verifier log more relevant by default
@ 2020-04-21  5:10 Andrii Nakryiko
  2020-04-23  5:41 ` Alexei Starovoitov
  0 siblings, 1 reply; 3+ messages in thread
From: Andrii Nakryiko @ 2020-04-21  5:10 UTC (permalink / raw)
  To: bpf, netdev, ast, daniel; +Cc: andrii.nakryiko, kernel-team, Andrii Nakryiko

To make BPF verifier verbose log more releavant and easier to use to debug
verification failures, "pop" parts of log that were successfully verified.
This has effect of leaving only verifier logs that correspond to code branches
that lead to verification failure, which in practice should result in much
shorter and more relevant verifier log dumps. This behavior is made the
default behavior and can be overriden to do exhaustive logging by specifying
BPF_LOG_LEVEL2 log level.

Using BPF_LOG_LEVEL2 to disable this behavior is not ideal, because in some
cases it's good to have BPF_LOG_LEVEL2 per-instruction register dump
verbosity, but still have only relevant verifier branches logged. But for this
patch, I didn't want to add any new flags. It might be worth-while to just
rethink how BPF verifier logging is performed and requested and streamline it
a bit. But this trimming of successfully verified branches seems to be useful
and a good default behavior.

To test this, I modified runqslower slightly to introduce read of
uninitialized stack variable. Log (**truncated in the middle** to save many
lines out of this commit message) BEFORE this change:

; int handle__sched_switch(u64 *ctx)
0: (bf) r6 = r1
; struct task_struct *prev = (struct task_struct *)ctx[1];
1: (79) r1 = *(u64 *)(r6 +8)
func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
2: (b7) r2 = 0
; struct event event = {};
3: (7b) *(u64 *)(r10 -24) = r2
last_idx 3 first_idx 0
regs=4 stack=0 before 2: (b7) r2 = 0
4: (7b) *(u64 *)(r10 -32) = r2
5: (7b) *(u64 *)(r10 -40) = r2
6: (7b) *(u64 *)(r10 -48) = r2
; if (prev->state == TASK_RUNNING)

[ ... instructions from insn #7 through #50 are cut out ... ]

51: (b7) r2 = 16
52: (85) call bpf_get_current_comm#16
last_idx 52 first_idx 42
regs=4 stack=0 before 51: (b7) r2 = 16
; bpf_perf_event_output(ctx, &events, BPF_F_CURRENT_CPU,
53: (bf) r1 = r6
54: (18) r2 = 0xffff8881f3868800
56: (18) r3 = 0xffffffff
58: (bf) r4 = r7
59: (b7) r5 = 32
60: (85) call bpf_perf_event_output#25
last_idx 60 first_idx 53
regs=20 stack=0 before 59: (b7) r5 = 32
61: (bf) r2 = r10
; event.pid = pid;
62: (07) r2 += -16
; bpf_map_delete_elem(&start, &pid);
63: (18) r1 = 0xffff8881f3868000
65: (85) call bpf_map_delete_elem#3
; }
66: (b7) r0 = 0
67: (95) exit

from 44 to 66: safe

from 34 to 66: safe

from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
; bpf_map_update_elem(&start, &pid, &ts, 0);
28: (bf) r2 = r10
;
29: (07) r2 += -16
; tsp = bpf_map_lookup_elem(&start, &pid);
30: (18) r1 = 0xffff8881f3868000
32: (85) call bpf_map_lookup_elem#1
invalid indirect read from stack off -16+0 size 4
processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4

Notice how there is a successful code path from instruction 0 through 67, few
successfully verified jumps (44->66, 34->66), and only after that 11->28 jump
plus error on instruction #32.

AFTER this change (full verifier log, **no truncation**):

; int handle__sched_switch(u64 *ctx)
0: (bf) r6 = r1
; struct task_struct *prev = (struct task_struct *)ctx[1];
1: (79) r1 = *(u64 *)(r6 +8)
func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
2: (b7) r2 = 0
; struct event event = {};
3: (7b) *(u64 *)(r10 -24) = r2
last_idx 3 first_idx 0
regs=4 stack=0 before 2: (b7) r2 = 0
4: (7b) *(u64 *)(r10 -32) = r2
5: (7b) *(u64 *)(r10 -40) = r2
6: (7b) *(u64 *)(r10 -48) = r2
; if (prev->state == TASK_RUNNING)
7: (79) r2 = *(u64 *)(r1 +16)
; if (prev->state == TASK_RUNNING)
8: (55) if r2 != 0x0 goto pc+19
 R1_w=ptr_task_struct(id=0,off=0,imm=0) R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
; trace_enqueue(prev->tgid, prev->pid);
9: (61) r1 = *(u32 *)(r1 +1184)
10: (63) *(u32 *)(r10 -4) = r1
; if (!pid || (targ_pid && targ_pid != pid))
11: (15) if r1 == 0x0 goto pc+16

from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
; bpf_map_update_elem(&start, &pid, &ts, 0);
28: (bf) r2 = r10
;
29: (07) r2 += -16
; tsp = bpf_map_lookup_elem(&start, &pid);
30: (18) r1 = 0xffff8881db3ce800
32: (85) call bpf_map_lookup_elem#1
invalid indirect read from stack off -16+0 size 4
processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4

Notice how in this case, there are 0-11 instructions + jump from 11 to
28 is recorded + 28-32 instructions with error on insn #32.

Signed-off-by: Andrii Nakryiko <andriin@fb.com>
---
 kernel/bpf/verifier.c | 26 ++++++++++++++++++++++----
 1 file changed, 22 insertions(+), 4 deletions(-)

diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index 38cfcf701eeb..c797bc3dbc69 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -168,6 +168,8 @@ struct bpf_verifier_stack_elem {
 	int insn_idx;
 	int prev_insn_idx;
 	struct bpf_verifier_stack_elem *next;
+	/* length of verifier log at the time this state was pushed on stack */
+	u32 log_pos;
 };
 
 #define BPF_COMPLEXITY_LIMIT_JMP_SEQ	8192
@@ -283,6 +285,18 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt,
 		log->ubuf = NULL;
 }
 
+static void bpf_vlog_reset(struct bpf_verifier_log *log, u32 new_pos)
+{
+	char zero = 0;
+
+	if (!bpf_verifier_log_needed(log))
+		return;
+
+	log->len_used = new_pos;
+	if (put_user(zero, log->ubuf + new_pos))
+		log->ubuf = NULL;
+}
+
 /* log_level controls verbosity level of eBPF verifier.
  * bpf_verifier_log_write() is used to dump the verification trace to the log,
  * so the user can figure out what's wrong with the program
@@ -846,7 +860,7 @@ static void update_branch_counts(struct bpf_verifier_env *env, struct bpf_verifi
 }
 
 static int pop_stack(struct bpf_verifier_env *env, int *prev_insn_idx,
-		     int *insn_idx)
+		     int *insn_idx, bool pop_log)
 {
 	struct bpf_verifier_state *cur = env->cur_state;
 	struct bpf_verifier_stack_elem *elem, *head = env->head;
@@ -860,6 +874,8 @@ static int pop_stack(struct bpf_verifier_env *env, int *prev_insn_idx,
 		if (err)
 			return err;
 	}
+	if (pop_log)
+		bpf_vlog_reset(&env->log, head->log_pos);
 	if (insn_idx)
 		*insn_idx = head->insn_idx;
 	if (prev_insn_idx)
@@ -887,6 +903,7 @@ static struct bpf_verifier_state *push_stack(struct bpf_verifier_env *env,
 	elem->insn_idx = insn_idx;
 	elem->prev_insn_idx = prev_insn_idx;
 	elem->next = env->head;
+	elem->log_pos = env->log.len_used;
 	env->head = elem;
 	env->stack_size++;
 	err = copy_verifier_state(&elem->st, cur);
@@ -915,7 +932,7 @@ static struct bpf_verifier_state *push_stack(struct bpf_verifier_env *env,
 	free_verifier_state(env->cur_state, true);
 	env->cur_state = NULL;
 	/* pop all elements and return */
-	while (!pop_stack(env, NULL, NULL));
+	while (!pop_stack(env, NULL, NULL, false));
 	return NULL;
 }
 
@@ -8399,6 +8416,7 @@ static bool reg_type_mismatch(enum bpf_reg_type src, enum bpf_reg_type prev)
 
 static int do_check(struct bpf_verifier_env *env)
 {
+	bool pop_log = !(env->log.level & BPF_LOG_LEVEL2);
 	struct bpf_verifier_state *state = env->cur_state;
 	struct bpf_insn *insns = env->prog->insnsi;
 	struct bpf_reg_state *regs;
@@ -8675,7 +8693,7 @@ static int do_check(struct bpf_verifier_env *env)
 process_bpf_exit:
 				update_branch_counts(env, env->cur_state);
 				err = pop_stack(env, &prev_insn_idx,
-						&env->insn_idx);
+						&env->insn_idx, pop_log);
 				if (err < 0) {
 					if (err != -ENOENT)
 						return err;
@@ -10260,7 +10278,7 @@ static int do_check_common(struct bpf_verifier_env *env, int subprog)
 		free_verifier_state(env->cur_state, true);
 		env->cur_state = NULL;
 	}
-	while (!pop_stack(env, NULL, NULL));
+	while (!pop_stack(env, NULL, NULL, false));
 	free_states(env);
 	if (ret)
 		/* clean aux data in case subprog was rejected */
-- 
2.24.1


^ permalink raw reply related	[flat|nested] 3+ messages in thread

* Re: [PATCH bpf-next] bpf: make verifier log more relevant by default
  2020-04-21  5:10 [PATCH bpf-next] bpf: make verifier log more relevant by default Andrii Nakryiko
@ 2020-04-23  5:41 ` Alexei Starovoitov
  2020-04-23 18:32   ` Andrii Nakryiko
  0 siblings, 1 reply; 3+ messages in thread
From: Alexei Starovoitov @ 2020-04-23  5:41 UTC (permalink / raw)
  To: Andrii Nakryiko
  Cc: bpf, Network Development, Alexei Starovoitov, Daniel Borkmann,
	Andrii Nakryiko, Kernel Team

On Mon, Apr 20, 2020 at 10:11 PM Andrii Nakryiko <andriin@fb.com> wrote:
>
> To make BPF verifier verbose log more releavant and easier to use to debug
> verification failures, "pop" parts of log that were successfully verified.
> This has effect of leaving only verifier logs that correspond to code branches
> that lead to verification failure, which in practice should result in much
> shorter and more relevant verifier log dumps. This behavior is made the
> default behavior and can be overriden to do exhaustive logging by specifying
> BPF_LOG_LEVEL2 log level.
>
> Using BPF_LOG_LEVEL2 to disable this behavior is not ideal, because in some
> cases it's good to have BPF_LOG_LEVEL2 per-instruction register dump
> verbosity, but still have only relevant verifier branches logged. But for this
> patch, I didn't want to add any new flags. It might be worth-while to just
> rethink how BPF verifier logging is performed and requested and streamline it
> a bit. But this trimming of successfully verified branches seems to be useful
> and a good default behavior.
>
> To test this, I modified runqslower slightly to introduce read of
> uninitialized stack variable. Log (**truncated in the middle** to save many
> lines out of this commit message) BEFORE this change:
>
> ; int handle__sched_switch(u64 *ctx)
> 0: (bf) r6 = r1
> ; struct task_struct *prev = (struct task_struct *)ctx[1];
> 1: (79) r1 = *(u64 *)(r6 +8)
> func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
> 2: (b7) r2 = 0
> ; struct event event = {};
> 3: (7b) *(u64 *)(r10 -24) = r2
> last_idx 3 first_idx 0
> regs=4 stack=0 before 2: (b7) r2 = 0
> 4: (7b) *(u64 *)(r10 -32) = r2
> 5: (7b) *(u64 *)(r10 -40) = r2
> 6: (7b) *(u64 *)(r10 -48) = r2
> ; if (prev->state == TASK_RUNNING)
>
> [ ... instructions from insn #7 through #50 are cut out ... ]
>
> 51: (b7) r2 = 16
> 52: (85) call bpf_get_current_comm#16
> last_idx 52 first_idx 42
> regs=4 stack=0 before 51: (b7) r2 = 16
> ; bpf_perf_event_output(ctx, &events, BPF_F_CURRENT_CPU,
> 53: (bf) r1 = r6
> 54: (18) r2 = 0xffff8881f3868800
> 56: (18) r3 = 0xffffffff
> 58: (bf) r4 = r7
> 59: (b7) r5 = 32
> 60: (85) call bpf_perf_event_output#25
> last_idx 60 first_idx 53
> regs=20 stack=0 before 59: (b7) r5 = 32
> 61: (bf) r2 = r10
> ; event.pid = pid;
> 62: (07) r2 += -16
> ; bpf_map_delete_elem(&start, &pid);
> 63: (18) r1 = 0xffff8881f3868000
> 65: (85) call bpf_map_delete_elem#3
> ; }
> 66: (b7) r0 = 0
> 67: (95) exit
>
> from 44 to 66: safe
>
> from 34 to 66: safe
>
> from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> ; bpf_map_update_elem(&start, &pid, &ts, 0);
> 28: (bf) r2 = r10
> ;
> 29: (07) r2 += -16
> ; tsp = bpf_map_lookup_elem(&start, &pid);
> 30: (18) r1 = 0xffff8881f3868000
> 32: (85) call bpf_map_lookup_elem#1
> invalid indirect read from stack off -16+0 size 4
> processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4
>
> Notice how there is a successful code path from instruction 0 through 67, few
> successfully verified jumps (44->66, 34->66), and only after that 11->28 jump
> plus error on instruction #32.
>
> AFTER this change (full verifier log, **no truncation**):
>
> ; int handle__sched_switch(u64 *ctx)
> 0: (bf) r6 = r1
> ; struct task_struct *prev = (struct task_struct *)ctx[1];
> 1: (79) r1 = *(u64 *)(r6 +8)
> func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
> 2: (b7) r2 = 0
> ; struct event event = {};
> 3: (7b) *(u64 *)(r10 -24) = r2
> last_idx 3 first_idx 0
> regs=4 stack=0 before 2: (b7) r2 = 0
> 4: (7b) *(u64 *)(r10 -32) = r2
> 5: (7b) *(u64 *)(r10 -40) = r2
> 6: (7b) *(u64 *)(r10 -48) = r2
> ; if (prev->state == TASK_RUNNING)
> 7: (79) r2 = *(u64 *)(r1 +16)
> ; if (prev->state == TASK_RUNNING)
> 8: (55) if r2 != 0x0 goto pc+19
>  R1_w=ptr_task_struct(id=0,off=0,imm=0) R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> ; trace_enqueue(prev->tgid, prev->pid);
> 9: (61) r1 = *(u32 *)(r1 +1184)
> 10: (63) *(u32 *)(r10 -4) = r1
> ; if (!pid || (targ_pid && targ_pid != pid))
> 11: (15) if r1 == 0x0 goto pc+16
>
> from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> ; bpf_map_update_elem(&start, &pid, &ts, 0);
> 28: (bf) r2 = r10
> ;
> 29: (07) r2 += -16
> ; tsp = bpf_map_lookup_elem(&start, &pid);
> 30: (18) r1 = 0xffff8881db3ce800
> 32: (85) call bpf_map_lookup_elem#1
> invalid indirect read from stack off -16+0 size 4
> processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4
>
> Notice how in this case, there are 0-11 instructions + jump from 11 to
> 28 is recorded + 28-32 instructions with error on insn #32.
>
> Signed-off-by: Andrii Nakryiko <andriin@fb.com>

This is great idea!

But two test_verifier tests failed:
#722/p precise: ST insn causing spi > allocated_stack FAIL
Unexpected verifier log in successful load!
EXP: 5: (2d) if r4 > r0 goto pc+0
RES:
0: (bf) r3 = r10
1: (55) if r3 != 0x7b goto pc+0

from 1 to 2: safe
processed 8 insns (limit 1000000) max_states_per_insn 0 total_states 4
peak_states 4 mark_read 1

Please fix them up.

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [PATCH bpf-next] bpf: make verifier log more relevant by default
  2020-04-23  5:41 ` Alexei Starovoitov
@ 2020-04-23 18:32   ` Andrii Nakryiko
  0 siblings, 0 replies; 3+ messages in thread
From: Andrii Nakryiko @ 2020-04-23 18:32 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Andrii Nakryiko, bpf, Network Development, Alexei Starovoitov,
	Daniel Borkmann, Kernel Team

On Wed, Apr 22, 2020 at 10:41 PM Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Mon, Apr 20, 2020 at 10:11 PM Andrii Nakryiko <andriin@fb.com> wrote:
> >
> > To make BPF verifier verbose log more releavant and easier to use to debug
> > verification failures, "pop" parts of log that were successfully verified.
> > This has effect of leaving only verifier logs that correspond to code branches
> > that lead to verification failure, which in practice should result in much
> > shorter and more relevant verifier log dumps. This behavior is made the
> > default behavior and can be overriden to do exhaustive logging by specifying
> > BPF_LOG_LEVEL2 log level.
> >
> > Using BPF_LOG_LEVEL2 to disable this behavior is not ideal, because in some
> > cases it's good to have BPF_LOG_LEVEL2 per-instruction register dump
> > verbosity, but still have only relevant verifier branches logged. But for this
> > patch, I didn't want to add any new flags. It might be worth-while to just
> > rethink how BPF verifier logging is performed and requested and streamline it
> > a bit. But this trimming of successfully verified branches seems to be useful
> > and a good default behavior.
> >
> > To test this, I modified runqslower slightly to introduce read of
> > uninitialized stack variable. Log (**truncated in the middle** to save many
> > lines out of this commit message) BEFORE this change:
> >
> > ; int handle__sched_switch(u64 *ctx)
> > 0: (bf) r6 = r1
> > ; struct task_struct *prev = (struct task_struct *)ctx[1];
> > 1: (79) r1 = *(u64 *)(r6 +8)
> > func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
> > 2: (b7) r2 = 0
> > ; struct event event = {};
> > 3: (7b) *(u64 *)(r10 -24) = r2
> > last_idx 3 first_idx 0
> > regs=4 stack=0 before 2: (b7) r2 = 0
> > 4: (7b) *(u64 *)(r10 -32) = r2
> > 5: (7b) *(u64 *)(r10 -40) = r2
> > 6: (7b) *(u64 *)(r10 -48) = r2
> > ; if (prev->state == TASK_RUNNING)
> >
> > [ ... instructions from insn #7 through #50 are cut out ... ]
> >
> > 51: (b7) r2 = 16
> > 52: (85) call bpf_get_current_comm#16
> > last_idx 52 first_idx 42
> > regs=4 stack=0 before 51: (b7) r2 = 16
> > ; bpf_perf_event_output(ctx, &events, BPF_F_CURRENT_CPU,
> > 53: (bf) r1 = r6
> > 54: (18) r2 = 0xffff8881f3868800
> > 56: (18) r3 = 0xffffffff
> > 58: (bf) r4 = r7
> > 59: (b7) r5 = 32
> > 60: (85) call bpf_perf_event_output#25
> > last_idx 60 first_idx 53
> > regs=20 stack=0 before 59: (b7) r5 = 32
> > 61: (bf) r2 = r10
> > ; event.pid = pid;
> > 62: (07) r2 += -16
> > ; bpf_map_delete_elem(&start, &pid);
> > 63: (18) r1 = 0xffff8881f3868000
> > 65: (85) call bpf_map_delete_elem#3
> > ; }
> > 66: (b7) r0 = 0
> > 67: (95) exit
> >
> > from 44 to 66: safe
> >
> > from 34 to 66: safe
> >
> > from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> > ; bpf_map_update_elem(&start, &pid, &ts, 0);
> > 28: (bf) r2 = r10
> > ;
> > 29: (07) r2 += -16
> > ; tsp = bpf_map_lookup_elem(&start, &pid);
> > 30: (18) r1 = 0xffff8881f3868000
> > 32: (85) call bpf_map_lookup_elem#1
> > invalid indirect read from stack off -16+0 size 4
> > processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4
> >
> > Notice how there is a successful code path from instruction 0 through 67, few
> > successfully verified jumps (44->66, 34->66), and only after that 11->28 jump
> > plus error on instruction #32.
> >
> > AFTER this change (full verifier log, **no truncation**):
> >
> > ; int handle__sched_switch(u64 *ctx)
> > 0: (bf) r6 = r1
> > ; struct task_struct *prev = (struct task_struct *)ctx[1];
> > 1: (79) r1 = *(u64 *)(r6 +8)
> > func 'sched_switch' arg1 has btf_id 151 type STRUCT 'task_struct'
> > 2: (b7) r2 = 0
> > ; struct event event = {};
> > 3: (7b) *(u64 *)(r10 -24) = r2
> > last_idx 3 first_idx 0
> > regs=4 stack=0 before 2: (b7) r2 = 0
> > 4: (7b) *(u64 *)(r10 -32) = r2
> > 5: (7b) *(u64 *)(r10 -40) = r2
> > 6: (7b) *(u64 *)(r10 -48) = r2
> > ; if (prev->state == TASK_RUNNING)
> > 7: (79) r2 = *(u64 *)(r1 +16)
> > ; if (prev->state == TASK_RUNNING)
> > 8: (55) if r2 != 0x0 goto pc+19
> >  R1_w=ptr_task_struct(id=0,off=0,imm=0) R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> > ; trace_enqueue(prev->tgid, prev->pid);
> > 9: (61) r1 = *(u32 *)(r1 +1184)
> > 10: (63) *(u32 *)(r10 -4) = r1
> > ; if (!pid || (targ_pid && targ_pid != pid))
> > 11: (15) if r1 == 0x0 goto pc+16
> >
> > from 11 to 28: R1_w=inv0 R2_w=inv0 R6_w=ctx(id=0,off=0,imm=0) R10=fp0 fp-8=mmmm???? fp-24_w=00000000 fp-32_w=00000000 fp-40_w=00000000 fp-48_w=00000000
> > ; bpf_map_update_elem(&start, &pid, &ts, 0);
> > 28: (bf) r2 = r10
> > ;
> > 29: (07) r2 += -16
> > ; tsp = bpf_map_lookup_elem(&start, &pid);
> > 30: (18) r1 = 0xffff8881db3ce800
> > 32: (85) call bpf_map_lookup_elem#1
> > invalid indirect read from stack off -16+0 size 4
> > processed 65 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 5 mark_read 4
> >
> > Notice how in this case, there are 0-11 instructions + jump from 11 to
> > 28 is recorded + 28-32 instructions with error on insn #32.
> >
> > Signed-off-by: Andrii Nakryiko <andriin@fb.com>
>
> This is great idea!
>

Thanks!

> But two test_verifier tests failed:

My bad, I forget to run test_verifier and test_maps. Will take a look and fix.

> #722/p precise: ST insn causing spi > allocated_stack FAIL
> Unexpected verifier log in successful load!
> EXP: 5: (2d) if r4 > r0 goto pc+0
> RES:
> 0: (bf) r3 = r10
> 1: (55) if r3 != 0x7b goto pc+0
>
> from 1 to 2: safe
> processed 8 insns (limit 1000000) max_states_per_insn 0 total_states 4
> peak_states 4 mark_read 1
>
> Please fix them up.

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2020-04-23 18:32 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-04-21  5:10 [PATCH bpf-next] bpf: make verifier log more relevant by default Andrii Nakryiko
2020-04-23  5:41 ` Alexei Starovoitov
2020-04-23 18:32   ` Andrii Nakryiko

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).