[PATCH bpf-next v5 0/3] Improve stack depth verification stats output

[PATCH bpf-next v5 0/3] Improve stack depth verification stats output

[Kumar Kartikeya Dwivedi]

Some improvements for more clarity in the stack depth verification
statistics output. See commit logs for details.

Changelog:
----------
v4 -> v5
v4: https://lore.kernel.org/bpf/20260803072733.191502-1-memxor@gmail.com

 * Change the format to combine instruction counts and stack depths into
   per-program records. (Andrii)
 * Adjust veristat for the new format while retaining support for the legacy format.
 * Explain why the legacy stack parsing buffer is zero-initialized. (BPF CI Bot)

v3 -> v4
v3: https://lore.kernel.org/bpf/20260803031457.3115812-1-memxor@gmail.com

 * Read names from subprog_info directly to avoid an out-of-bounds access
   when func_info validation fails. (BPF CI Bot)

v2 -> v3
v2: https://lore.kernel.org/bpf/20260802225209.2511758-1-memxor@gmail.com

 * Reuse subprog_name() to fetch subprogram names. (BPF CI Bot)

v1 -> v2
v1: https://lore.kernel.org/bpf/20260801230400.850271-1-memxor@gmail.com

 * Use multi-line format. (Eduard)
 * Adjust veristat to work with old and new format.
 * Adjust selftest log_level without new option. (Eduard)

Kumar Kartikeya Dwivedi (3):
  bpf: Show more useful info in stack depth stats
  selftests/bpf: Adjust veristat stack depth parsing
  selftests/bpf: Test stack depth stats without BTF subprog names

 kernel/bpf/verifier.c                         | 24 ++++++++++++-------
 .../bpf/progs/verifier_basic_stack.c          |  4 ++--
 .../bpf/progs/verifier_bpf_fastcall.c         | 23 +++++++++++-------
 .../bpf/progs/verifier_global_subprogs.c      |  2 +-
 .../bpf/progs/verifier_private_stack.c        | 15 +++++++++---
 .../selftests/bpf/progs/verifier_var_off.c    |  4 ++--
 tools/testing/selftests/bpf/test_verifier.c   |  2 +-
 tools/testing/selftests/bpf/verifier/calls.c  |  9 ++++++-
 tools/testing/selftests/bpf/veristat.c        | 17 +++++++++----
 9 files changed, 69 insertions(+), 31 deletions(-)


base-commit: 457d4ecb47aaf7a2cb46aaadd76e8c812e4f3c9e
-- 
2.53.0

[PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats

[Kumar Kartikeya Dwivedi]

Stack depth statistics list captured depths in subprogram-number order,
while per-verification instruction counts are reported separately. Since
libbpf determines subprogram numbers, it is hard to associate either
statistic with its subprogram name or see where verifier work is spent.

Keep the combined maximum stack depth on its own line, then print a record
for the main program and each subprogram:

stack depth max <depth>
prog (<name>) insns <count> stack <depth>
subprog <number> (<name>) insns <count> stack <depth>

When no subprogram name is available, print <unknown>. Keep the existing
aggregate "processed ... insns" record unchanged for compatibility.

Suggested-by: Andrii Nakryiko <andrii@kernel.org>
Signed-off-by: Kumar Kartikeya Dwivedi <memxor@gmail.com>
---
 kernel/bpf/verifier.c                         | 24 ++++++++++++-------
 .../bpf/progs/verifier_basic_stack.c          |  4 ++--
 .../bpf/progs/verifier_bpf_fastcall.c         | 23 +++++++++++-------
 .../bpf/progs/verifier_global_subprogs.c      |  2 +-
 .../bpf/progs/verifier_private_stack.c        | 15 +++++++++---
 .../selftests/bpf/progs/verifier_var_off.c    |  4 ++--
 6 files changed, 47 insertions(+), 25 deletions(-)

diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index b274004fccfd..80c249906fd3 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -18777,15 +18777,21 @@ static void print_verification_stats(struct bpf_verifier_env *env)
 	if (env->log.level & BPF_LOG_STATS) {
 		verbose(env, "verification time %lld usec\n",
 			div_u64(env->verification_time, 1000));
-		verbose(env, "stack depth %d", env->subprog_info[0].stack_depth);
-		for (i = 1; i < subprog_cnt; i++)
-			verbose(env, "+%d", env->subprog_info[i].stack_depth);
-		verbose(env, " max %d\n", env->max_stack_depth);
-		verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
-		for (i = 1; i < subprog_cnt; i++)
-			if (bpf_subprog_is_global(env, i))
-				verbose(env, "+%d", env->subprog_info[i].insn_processed);
-		verbose(env, "\n");
+		verbose(env, "stack depth max %d\n", env->max_stack_depth);
+		for (i = 0; i < subprog_cnt; i++) {
+			const char *name = env->subprog_info[i].name;
+
+			if (!name || !name[0])
+				name = "<unknown>";
+			if (i == 0)
+				verbose(env, "prog (%s) insns %d stack %d\n", name,
+					env->subprog_info[i].insn_processed,
+					env->subprog_info[i].stack_depth);
+			else
+				verbose(env, "subprog %d (%s) insns %d stack %d\n", i, name,
+					env->subprog_info[i].insn_processed,
+					env->subprog_info[i].stack_depth);
+		}
 	}
 	verbose(env, "processed %d insns (limit %d) max_states_per_insn %d "
 		"total_states %d peak_states %d mark_read %d\n",
diff --git a/tools/testing/selftests/bpf/progs/verifier_basic_stack.c b/tools/testing/selftests/bpf/progs/verifier_basic_stack.c
index fb62e09f2114..47b12c6f8efd 100644
--- a/tools/testing/selftests/bpf/progs/verifier_basic_stack.c
+++ b/tools/testing/selftests/bpf/progs/verifier_basic_stack.c
@@ -27,7 +27,7 @@ __naked void stack_out_of_bounds(void)
 
 SEC("socket")
 __description("uninitialized stack1")
-__success __log_level(4) __msg("stack depth 8")
+__success __log_level(4) __msg("prog (uninitialized_stack1) insns {{[0-9]+}} stack 8")
 __failure_unpriv __msg_unpriv("invalid read from stack")
 __naked void uninitialized_stack1(void)
 {
@@ -45,7 +45,7 @@ __naked void uninitialized_stack1(void)
 
 SEC("socket")
 __description("uninitialized stack2")
-__success __log_level(4) __msg("stack depth 8")
+__success __log_level(4) __msg("prog (uninitialized_stack2) insns {{[0-9]+}} stack 8")
 __failure_unpriv __msg_unpriv("invalid read from stack")
 __naked void uninitialized_stack2(void)
 {
diff --git a/tools/testing/selftests/bpf/progs/verifier_bpf_fastcall.c b/tools/testing/selftests/bpf/progs/verifier_bpf_fastcall.c
index 83707faea049..43ce0bd8e4eb 100644
--- a/tools/testing/selftests/bpf/progs/verifier_bpf_fastcall.c
+++ b/tools/testing/selftests/bpf/progs/verifier_bpf_fastcall.c
@@ -10,7 +10,7 @@
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 8")
+__log_level(4) __msg("prog (simple) insns {{[0-9]+}} stack 8")
 __xlated("4: r5 = 5")
 __xlated("5: r0 = ")
 __xlated("6: r0 = &(void __percpu *)(r0)")
@@ -96,7 +96,7 @@ __naked void canary_zero_spills(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 16")
+__log_level(4) __msg("prog (wrong_reg_in_pattern1) insns {{[0-9]+}} stack 16")
 __xlated("1: *(u64 *)(r10 -16) = r1")
 __xlated("...")
 __xlated("3: r0 = &(void __percpu *)(r0)")
@@ -598,7 +598,7 @@ __naked static void subprogs_use_independent_offsets_aux(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 8")
+__log_level(4) __msg("prog (helper_call_does_not_prevent_bpf_fastcall) insns {{[0-9]+}} stack 8")
 __xlated("2: r0 = &(void __percpu *)(r0)")
 __success
 __naked void helper_call_does_not_prevent_bpf_fastcall(void)
@@ -620,7 +620,7 @@ __naked void helper_call_does_not_prevent_bpf_fastcall(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 24")
+__log_level(4) __msg("prog (may_goto_interaction_x86_64) insns {{[0-9]+}} stack 24")
 /* may_goto counter at -24 */
 __xlated("0: *(u64 *)(r10 -24) =")
 /* may_goto timestamp at -16 */
@@ -661,7 +661,7 @@ __naked void may_goto_interaction_x86_64(void)
 SEC("raw_tp")
 __arch_arm64
 __arch_riscv64
-__log_level(4) __msg("stack depth 24")
+__log_level(4) __msg("prog (may_goto_interaction) insns {{[0-9]+}} stack 24")
 /* may_goto counter at -24 */
 __xlated("0: *(u64 *)(r10 -24) =")
 /* may_goto timestamp at -16 */
@@ -708,7 +708,9 @@ __naked static void dummy_loop_callback(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 32+0")
+__log_level(4)
+__msg("prog (bpf_loop_interaction1) insns {{[0-9]+}} stack 32")
+__msg("subprog 1 (dummy_loop_callback) insns {{[0-9]+}} stack 0")
 __xlated("2: r1 = 1")
 __xlated("3: r0 =")
 __xlated("4: r0 = &(void __percpu *)(r0)")
@@ -756,7 +758,9 @@ __naked int bpf_loop_interaction1(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 40+0")
+__log_level(4)
+__msg("prog (bpf_loop_interaction2) insns {{[0-9]+}} stack 40")
+__msg("subprog 1 (dummy_loop_callback) insns {{[0-9]+}} stack 0")
 /* call bpf_get_smp_processor_id */
 __xlated("2: r1 = 42")
 __xlated("3: r0 =")
@@ -800,7 +804,10 @@ __naked int bpf_loop_interaction2(void)
 
 SEC("raw_tp")
 __arch_x86_64
-__log_level(4) __msg("stack depth 512+0 max 512")
+__log_level(4)
+__msg("stack depth max 512")
+__msg("prog (cumulative_stack_depth) insns {{[0-9]+}} stack 512")
+__msg("subprog 1 (cumulative_stack_depth_subprog) insns {{[0-9]+}} stack 0")
 /* just to print xlated version when debugging */
 __xlated("r0 = &(void __percpu *)(r0)")
 __success
diff --git a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
index 67dc352addfd..1755f133f020 100644
--- a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
+++ b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
@@ -52,7 +52,7 @@ __msg("('global_calls_good_only') is global and assumed valid.")
 /* eventually global_good() is transitively validated as well */
 __msg("Validating global_good() func")
 __msg("('global_good') is safe for any args that match its prototype")
-__msg("insns processed {{[0-9]+\\+[0-9]+\\+[0-9]+$}}")
+__msg("prog (chained_global_func_calls_success) insns {{[0-9]+}} stack")
 int chained_global_func_calls_success(void)
 {
 	int sum = 0;
diff --git a/tools/testing/selftests/bpf/progs/verifier_private_stack.c b/tools/testing/selftests/bpf/progs/verifier_private_stack.c
index bb8206e10880..ab5c53c30a0c 100644
--- a/tools/testing/selftests/bpf/progs/verifier_private_stack.c
+++ b/tools/testing/selftests/bpf/progs/verifier_private_stack.c
@@ -86,7 +86,9 @@ __naked static void cumulative_stack_depth_subprog(void)
 SEC("kprobe")
 __description("Private stack, subtree > MAX_BPF_STACK")
 __success
-__log_level(4) __msg("stack depth 512+32 max 512")
+__log_level(4) __msg("stack depth max 512")
+__msg("prog (private_stack_nested_1) insns {{[0-9]+}} stack 512")
+__msg("subprog 1 (cumulative_stack_depth_subprog) insns {{[0-9]+}} stack 32")
 __arch_x86_64
 /* private stack fp for the main prog */
 __jited("	movabsq	$0x{{.*}}, %r9")
@@ -331,7 +333,11 @@ SEC("fentry/bpf_fentry_test9")
 __description("Private stack, async callback, potential nesting")
 __success __retval(0)
 __load_if_JITed()
-__log_level(4) __msg("stack depth 8+0+256+0 max 272")
+__log_level(4) __msg("stack depth max 272")
+__msg("prog (private_stack_async_callback_2) insns {{[0-9]+}} stack 8")
+__msg("subprog 1 (timer_cb1) insns {{[0-9]+}} stack 0")
+__msg("subprog 2 (subprog1) insns {{[0-9]+}} stack 256")
+__msg("subprog 3 (subprog2) insns {{[0-9]+}} stack 0")
 __arch_x86_64
 __jited("	subq	$0x100, %rsp")
 __arch_arm64
@@ -355,7 +361,10 @@ int private_stack_async_callback_2(void)
 SEC("fentry/bpf_fentry_test9")
 __description("private stack, max stack depth is private stack")
 __success
-__log_level(4) __msg("stack depth 8+256+0 max 256")
+__log_level(4) __msg("stack depth max 256")
+__msg("prog (private_stack_max_depth) insns {{[0-9]+}} stack 8")
+__msg("subprog 1 (subprog1) insns {{[0-9]+}} stack 256")
+__msg("subprog 2 (subprog2) insns {{[0-9]+}} stack 0")
 int private_stack_max_depth(void)
 {
 	int x = 0;
diff --git a/tools/testing/selftests/bpf/progs/verifier_var_off.c b/tools/testing/selftests/bpf/progs/verifier_var_off.c
index 24cd0a763673..6eb7d3ae49e8 100644
--- a/tools/testing/selftests/bpf/progs/verifier_var_off.c
+++ b/tools/testing/selftests/bpf/progs/verifier_var_off.c
@@ -198,7 +198,7 @@ __success
 /* Check that the maximum stack depth is correctly maintained according to the
  * maximum possible variable offset.
  */
-__log_level(4) __msg("stack depth 16")
+__log_level(4) __msg("prog (stack_write_priv_vs_unpriv) insns {{[0-9]+}} stack 16")
 __failure_unpriv
 /* Variable stack access is rejected for unprivileged.
  */
@@ -238,7 +238,7 @@ __success
 /* Check that the maximum stack depth is correctly maintained according to the
  * maximum possible variable offset.
  */
-__log_level(4) __msg("stack depth 16")
+__log_level(4) __msg("prog (stack_write_followed_by_read) insns {{[0-9]+}} stack 16")
 __failure_unpriv
 __msg_unpriv("R2 variable stack access prohibited for !root")
 __retval(0)
-- 
2.53.0

[PATCH bpf-next v5 2/3] selftests/bpf: Adjust veristat stack depth parsing

[Kumar Kartikeya Dwivedi]

The verifier now reports instruction and stack depth statistics using one
record per program. Teach veristat to parse the new prog and subprog records
while retaining support for the legacy one-line stack depth format used by
older kernels. Match only through the stack value so that additional fields
can be appended without breaking parsing.

Increase the bounded backward scan so it can include all 256 per-subprogram
records.

Zero-initialize the legacy stack buffer because logs using the new format do
not populate it before the trailing tokenizer loop. This makes the loop see
an empty string instead of reading uninitialized data.

Signed-off-by: Kumar Kartikeya Dwivedi <memxor@gmail.com>
---
 tools/testing/selftests/bpf/veristat.c | 17 +++++++++++++----
 1 file changed, 13 insertions(+), 4 deletions(-)

diff --git a/tools/testing/selftests/bpf/veristat.c b/tools/testing/selftests/bpf/veristat.c
index c9c257784ee3..92424771679f 100644
--- a/tools/testing/selftests/bpf/veristat.c
+++ b/tools/testing/selftests/bpf/veristat.c
@@ -993,13 +993,15 @@ static void free_verif_stats(struct verif_stats *stats, size_t stat_cnt)
 
 static char verif_log_buf[64 * 1024];
 
-#define MAX_PARSED_LOG_LINES 100
+/* Keep room for all 256 subprogram records and trailing statistics. */
+#define MAX_PARSED_LOG_LINES 300
 
 static int parse_verif_log(char * const buf, size_t buf_sz, struct verif_stats *s)
 {
 	const char *cur;
-	int pos, lines, sub_stack, cnt = 0;
-	char *state = NULL, *token, stack[512];
+	long sub_stack;
+	int pos, lines, cnt = 0;
+	char *state = NULL, *token, stack[512] = {};
 
 	buf[buf_sz - 1] = '\0';
 
@@ -1025,11 +1027,18 @@ static int parse_verif_log(char * const buf, size_t buf_sz, struct verif_stats *
 				&s->stats[MARK_READ_MAX_LEN]))
 			continue;
 
+		if (1 == sscanf(cur, "stack depth max %ld", &s->stats[MAX_STACK]))
+			continue;
+		if (1 == sscanf(cur, "prog %*s insns %*d stack %ld", &sub_stack) ||
+		    1 == sscanf(cur, "subprog %*d %*s insns %*d stack %ld", &sub_stack)) {
+			s->stats[STACK] += sub_stack;
+			continue;
+		}
 		if (2 == sscanf(cur, "stack depth %511s max %ld", stack, &s->stats[MAX_STACK]))
 			continue;
 	}
 	while ((token = strtok_r(cnt++ ? NULL : stack, "+", &state))) {
-		if (sscanf(token, "%d", &sub_stack) == 0)
+		if (sscanf(token, "%ld", &sub_stack) == 0)
 			break;
 		s->stats[STACK] += sub_stack;
 	}
-- 
2.53.0

[PATCH bpf-next v5 3/3] selftests/bpf: Test stack depth stats without BTF subprog names

[Kumar Kartikeya Dwivedi]

Test the per-program instruction and stack depth statistics emitted when BTF
function info does not provide subprogram names.

Make VERBOSE_ACCEPT request verifier statistics so the raw-insn test can
validate the <unknown> output without a test-specific log level.

Signed-off-by: Kumar Kartikeya Dwivedi <memxor@gmail.com>
---
 tools/testing/selftests/bpf/test_verifier.c  | 2 +-
 tools/testing/selftests/bpf/verifier/calls.c | 9 ++++++++-
 2 files changed, 9 insertions(+), 2 deletions(-)

diff --git a/tools/testing/selftests/bpf/test_verifier.c b/tools/testing/selftests/bpf/test_verifier.c
index a8ae03c57bba..bffb7360434c 100644
--- a/tools/testing/selftests/bpf/test_verifier.c
+++ b/tools/testing/selftests/bpf/test_verifier.c
@@ -1560,7 +1560,7 @@ static void do_test_single(struct bpf_test *test, bool unpriv,
 
 	opts.expected_attach_type = test->expected_attach_type;
 	if (expected_ret == VERBOSE_ACCEPT)
-		opts.log_level = 2;
+		opts.log_level = 2 | 4;
 	else if (verbose)
 		opts.log_level = verif_log_level | 4; /* force stats */
 	else
diff --git a/tools/testing/selftests/bpf/verifier/calls.c b/tools/testing/selftests/bpf/verifier/calls.c
index 8cd626e04551..6bf9ca5c5600 100644
--- a/tools/testing/selftests/bpf/verifier/calls.c
+++ b/tools/testing/selftests/bpf/verifier/calls.c
@@ -1091,7 +1091,14 @@
 	/* stack_main=32, stack_A=256, stack_B=64
 	 * and max(main+A, main+A+B) < 512
 	 */
-	.result = ACCEPT,
+	.result = VERBOSE_ACCEPT,
+	.errstr = "stack depth max 352\t"
+		  "prog (<unknown>) insns \t"
+		  " stack 32\t"
+		  "subprog 1 (<unknown>) insns \t"
+		  " stack 256\t"
+		  "subprog 2 (<unknown>) insns \t"
+		  " stack 64",
 },
 {
 	"calls: stack depth check using three frames. test2",
-- 
2.53.0

Re: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats

[sashiko-bot]

Thank you for your contribution! Sashiko AI review found 2 potential issue(s) to consider:
- [Medium] Unconditionally printing the instruction count for all subprograms outputs `insns 0` for all static (non-global) subprograms, defeating the stated goal of showing "where verifier work is spent".
- [Medium] The new verifier stack depth log format silently breaks the `veristat` tool, causing it to fail to parse both `MAX_STACK` and `STACK` statistics.
--

--- Patch [1]: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats ---
commit a5f11407b8ca52d1698171e4ae37a0d5f859eb2f
Author: Kumar Kartikeya Dwivedi <memxor@gmail.com>

bpf: Show more useful info in stack depth stats
    
This commit updates the verifier log to print stack depth statistics
in a new format, listing the main program and each subprogram on
separate lines with their name, instruction count, and stack depth.
It also updates the BPF selftests to match the new output format.

> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> --- a/kernel/bpf/verifier.c
> +++ b/kernel/bpf/verifier.c
> @@ -18777,15 +18777,21 @@ static void print_verification_stats(struct bpf_verifier_env *env)
>  	if (env->log.level & BPF_LOG_STATS) {
>  		verbose(env, "verification time %lld usec\n",
>  			div_u64(env->verification_time, 1000));
> -		verbose(env, "stack depth %d", env->subprog_info[0].stack_depth);
> -		for (i = 1; i < subprog_cnt; i++)
> -			verbose(env, "+%d", env->subprog_info[i].stack_depth);
> -		verbose(env, " max %d\n", env->max_stack_depth);
> -		verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
> -		for (i = 1; i < subprog_cnt; i++)
> -			if (bpf_subprog_is_global(env, i))
> -				verbose(env, "+%d", env->subprog_info[i].insn_processed);
> -		verbose(env, "\n");
> +		verbose(env, "stack depth max %d\n", env->max_stack_depth);

[Severity: Medium]
Does this new output format break the veristat tool?

In tools/testing/selftests/bpf/veristat.c:parse_verif_log(), the tool uses 
sscanf to parse the legacy format:

    if (2 == sscanf(cur, "stack depth %511s max %ld", stack,
                    &s->stats[MAX_STACK]))

When presented with the new format "stack depth max %d", the %511s token
greedily matches the string "max", causing the literal " max " check to fail.
This would cause sscanf to return 1, silently leaving the MAX_STACK and STACK
counters unpopulated (reporting 0) for all analyzed programs.

> +		for (i = 0; i < subprog_cnt; i++) {
> +			const char *name = env->subprog_info[i].name;
> +
> +			if (!name || !name[0])
> +				name = "<unknown>";
> +			if (i == 0)
> +				verbose(env, "prog (%s) insns %d stack %d\n", name,
> +					env->subprog_info[i].insn_processed,
> +					env->subprog_info[i].stack_depth);
> +			else
> +				verbose(env, "subprog %d (%s) insns %d stack %d\n", i, name,
> +					env->subprog_info[i].insn_processed,
> +					env->subprog_info[i].stack_depth);

[Severity: Medium]
Since the bpf_subprog_is_global(env, i) check was removed here, does this
print misleading instruction counts for static subprograms?

The verifier only calculates insn_processed for global subprograms and the
main program, as static subprograms are verified inline and their cost is
attributed to their callers. By removing the bpf_subprog_is_global() check,
are we now unconditionally outputting "insns 0" for all static (non-global)
subprograms?

> +		}
>  	}
>  	verbose(env, "processed %d insns (limit %d) max_states_per_insn %d "

-- 
Sashiko AI review · https://sashiko.dev/#/patchset/20260804081114.3871564-1-memxor@gmail.com?part=1

Re: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats

[Kumar Kartikeya Dwivedi]

On Tue Aug 4, 2026 at 10:22 AM CEST, sashiko-bot wrote:
> Thank you for your contribution! Sashiko AI review found 2 potential issue(s) to consider:
> - [Medium] Unconditionally printing the instruction count for all subprograms outputs `insns 0` for all static (non-global) subprograms, defeating the stated goal of showing "where verifier work is spent".
> - [Medium] The new verifier stack depth log format silently breaks the `veristat` tool, causing it to fail to parse both `MAX_STACK` and `STACK` statistics.
> --
>
> --- Patch [1]: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats ---
> commit a5f11407b8ca52d1698171e4ae37a0d5f859eb2f
> Author: Kumar Kartikeya Dwivedi <memxor@gmail.com>
>
> bpf: Show more useful info in stack depth stats
>
> This commit updates the verifier log to print stack depth statistics
> in a new format, listing the main program and each subprogram on
> separate lines with their name, instruction count, and stack depth.
> It also updates the BPF selftests to match the new output format.
>
>> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
>> --- a/kernel/bpf/verifier.c
>> +++ b/kernel/bpf/verifier.c
>> @@ -18777,15 +18777,21 @@ static void print_verification_stats(struct bpf_verifier_env *env)
>>  	if (env->log.level & BPF_LOG_STATS) {
>>  		verbose(env, "verification time %lld usec\n",
>>  			div_u64(env->verification_time, 1000));
>> -		verbose(env, "stack depth %d", env->subprog_info[0].stack_depth);
>> -		for (i = 1; i < subprog_cnt; i++)
>> -			verbose(env, "+%d", env->subprog_info[i].stack_depth);
>> -		verbose(env, " max %d\n", env->max_stack_depth);
>> -		verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
>> -		for (i = 1; i < subprog_cnt; i++)
>> -			if (bpf_subprog_is_global(env, i))
>> -				verbose(env, "+%d", env->subprog_info[i].insn_processed);
>> -		verbose(env, "\n");
>> +		verbose(env, "stack depth max %d\n", env->max_stack_depth);
>
> [Severity: Medium]
> Does this new output format break the veristat tool?
>
> In tools/testing/selftests/bpf/veristat.c:parse_verif_log(), the tool uses
> sscanf to parse the legacy format:
>
>     if (2 == sscanf(cur, "stack depth %511s max %ld", stack,
>                     &s->stats[MAX_STACK]))
>
> When presented with the new format "stack depth max %d", the %511s token
> greedily matches the string "max", causing the literal " max " check to fail.
> This would cause sscanf to return 1, silently leaving the MAX_STACK and STACK
> counters unpopulated (reporting 0) for all analyzed programs.
>
>> +		for (i = 0; i < subprog_cnt; i++) {
>> +			const char *name = env->subprog_info[i].name;
>> +
>> +			if (!name || !name[0])
>> +				name = "<unknown>";
>> +			if (i == 0)
>> +				verbose(env, "prog (%s) insns %d stack %d\n", name,
>> +					env->subprog_info[i].insn_processed,
>> +					env->subprog_info[i].stack_depth);
>> +			else
>> +				verbose(env, "subprog %d (%s) insns %d stack %d\n", i, name,
>> +					env->subprog_info[i].insn_processed,
>> +					env->subprog_info[i].stack_depth);
>
> [Severity: Medium]
> Since the bpf_subprog_is_global(env, i) check was removed here, does this
> print misleading instruction counts for static subprograms?
>
> The verifier only calculates insn_processed for global subprograms and the
> main program, as static subprograms are verified inline and their cost is
> attributed to their callers. By removing the bpf_subprog_is_global() check,
> are we now unconditionally outputting "insns 0" for all static (non-global)
> subprograms?
>

This is legit, but it is based on how we account insns processed. It is done for
main subprogs and global subprogs. It might not even make sense to do per static
subprog accounting, given it can be called in various ways that affect the insns
processed of the CFG rooted at it throughout the program.

So we can leave it as insns 0, or do something different, but I don't have
better ideas on what that would be.

>> +		}
>>  	}
>>  	verbose(env, "processed %d insns (limit %d) max_states_per_insn %d "

Re: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats

[bot+bpf-ci]

[-- Attachment #1: Type: text/plain, Size: 6413 bytes --]

> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
> index b274004fccfd9..80c249906fd39 100644
> --- a/kernel/bpf/verifier.c
> +++ b/kernel/bpf/verifier.c
> @@ -18777,15 +18777,21 @@ static void print_verification_stats(struct bpf_verifier_env *env)
>  	if (env->log.level & BPF_LOG_STATS) {
>  		verbose(env, "verification time %lld usec\n",
>  			div_u64(env->verification_time, 1000));
> -		verbose(env, "stack depth %d", env->subprog_info[0].stack_depth);
> -		for (i = 1; i < subprog_cnt; i++)
> -			verbose(env, "+%d", env->subprog_info[i].stack_depth);
> -		verbose(env, " max %d\n", env->max_stack_depth);
> -		verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
> -		for (i = 1; i < subprog_cnt; i++)
> -			if (bpf_subprog_is_global(env, i))
> -				verbose(env, "+%d", env->subprog_info[i].insn_processed);
> -		verbose(env, "\n");
> +		verbose(env, "stack depth max %d\n", env->max_stack_depth);
> +		for (i = 0; i < subprog_cnt; i++) {
> +			const char *name = env->subprog_info[i].name;
> +
> +			if (!name || !name[0])
> +				name = "<unknown>";
> +			if (i == 0)
> +				verbose(env, "prog (%s) insns %d stack %d\n", name,
> +					env->subprog_info[i].insn_processed,
> +					env->subprog_info[i].stack_depth);
> +			else
> +				verbose(env, "subprog %d (%s) insns %d stack %d\n", i, name,
> +					env->subprog_info[i].insn_processed,
> +					env->subprog_info[i].stack_depth);
> +		}
>  	}

The new loop prints insns %d for every subprogram, but
subprog_info[i].insn_processed is only ever written for the main program
and for global subprograms. The old code encoded exactly that with an
explicit filter:

kernel/bpf/verifier.c (old):
    verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
    for (i = 1; i < subprog_cnt; i++)
        if (bpf_subprog_is_global(env, i))          /* <-- filter removed */
            verbose(env, "+%d", env->subprog_info[i].insn_processed);

The only two writers are do_check_main() and do_check_subprogs(). The
latter is reached only after:

kernel/bpf/verifier.c:18711
    if (!bpf_subprog_is_global(env, i))
        continue;

and the whole function returns early at:

kernel/bpf/check_btf.c:1070
    if (!aux->func_info)
        return 0;

env is kvzalloc'd, so for every static subprogram, callback (bpf_loop,
timer), and every subprogram of a program loaded without BTF func_info,
insn_processed is structurally always 0. Those instructions were counted
into the caller's record, because static subprogs are verified inline as
part of the calling frame.

Does this mean that for any program using static subprograms or callbacks
the new per-subprog insns field shows 0 rather than where verifier work is
actually spent?

The patch's own new expectations confirm this. Every "subprog N (...) insns"
line added in this commit is for a non-global subprogram (dummy_loop_callback,
cumulative_stack_depth_subprog, timer_cb1, subprog1, subprog2), and each
uses the permissive {{[0-9]+}} regex that matches 0.

This directly contradicts the stated purpose: "it is hard to see where
verifier work is spent". Either the bpf_subprog_is_global() filter should
be kept (omit the field, or the whole record, for subprograms that are not
independently verified), or the field should be marked as not-measured
(e.g. insns -) so that 0 is not mistaken for a real measurement.

Related coverage loss from the same root cause:

> diff --git a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
> index 67dc352addfd7..1755f133f0205 100644
> --- a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
> +++ b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
> @@ -52,7 +52,7 @@ __msg("('global_calls_good_only') is global and assumed valid.")
>  /* eventually global_good() is transitively validated as well */
>  __msg("Validating global_good() func")
>  __msg("('global_good') is safe for any args that match its prototype")
> -__msg("insns processed {{[0-9]+\\+[0-9]+\\+[0-9]+$}}")
> +__msg("prog (chained_global_func_calls_success) insns {{[0-9]+}} stack")

The old anchored pattern asserted that exactly three independent counts
were emitted (main + global_calls_good_only + global_good). The
replacement checks only the main-program record and asserts nothing about
the two global subprogram records. Could the one test that actually
validated per-global-subprog instruction accounting be preserved?


The BPF_LOG_STATS payload grows roughly an order of magnitude per
subprogram, which can turn a previously-succeeding program load into
-ENOSPC for callers that pass their own fixed log buffer.

Old stats output scaled at about 4 bytes per subprogram ("+%d" for the
stack chain, plus "+%d" only for global subprogs). New output emits a full
line per subprogram: "subprog %d (%s) insns %d stack %d\n", roughly 40-50
bytes plus the BTF name, which btf_name_valid_identifier() bounds only by
KSYM_NAME_LEN == 512. With BPF_MAX_SUBPROGS == 256 permitted subprograms
the stats section goes from under ~2 KB to well over ~12 KB, and far more
with long function names.

Does this matter? Looking at the load path:

kernel/bpf/log.c:45-58 bpf_vlog_update_len_max()
    tracks the required size in log->len_max.

kernel/bpf/log.c:295 bpf_vlog_finalize()
    returns -ENOSPC when log->ubuf && log->len_max > log->len_total.

kernel/bpf/verifier.c:20397-20402 bpf_check()
    err = bpf_log_attr_finalize(attr_log, &env->log);
    if (err) ret = err;
    if (ret) goto err_release_maps;

so the successful verification is turned into a failed BPF_PROG_LOAD.

A userspace loader that sets log_level = 4 (stats only) with a modest,
fixed log_buf sized against the old output will start failing to load
multi-subprogram programs after this change. libbpf only auto-retries with
a larger buffer when it owns the buffer:

tools/lib/bpf/libbpf.c:8064-8071
    if (own_log_buf && errno == ENOSPC ...)

so callers supplying their own log_buf get the failure.

Could the number of per-subprog records be bounded, or emitted only above
some log level, to avoid the behaviour change for stats-only callers?


---
AI reviewed your patch. Please fix the bug or email reply why it's not a bug.
See: https://github.com/kernel-patches/vmtest/blob/master/ci/claude/README.md

CI run summary: https://github.com/kernel-patches/bpf/actions/runs/30891720984

Re: [PATCH bpf-next v5 1/3] bpf: Show more useful info in stack depth stats

[Kumar Kartikeya Dwivedi]

On Tue Aug 4, 2026 at 11:31 AM CEST, bot+bpf-ci wrote:
>> diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
>> index b274004fccfd9..80c249906fd39 100644
>> --- a/kernel/bpf/verifier.c
>> +++ b/kernel/bpf/verifier.c
>> @@ -18777,15 +18777,21 @@ static void print_verification_stats(struct bpf_verifier_env *env)
>>  	if (env->log.level & BPF_LOG_STATS) {
>>  		verbose(env, "verification time %lld usec\n",
>>  			div_u64(env->verification_time, 1000));
>> -		verbose(env, "stack depth %d", env->subprog_info[0].stack_depth);
>> -		for (i = 1; i < subprog_cnt; i++)
>> -			verbose(env, "+%d", env->subprog_info[i].stack_depth);
>> -		verbose(env, " max %d\n", env->max_stack_depth);
>> -		verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
>> -		for (i = 1; i < subprog_cnt; i++)
>> -			if (bpf_subprog_is_global(env, i))
>> -				verbose(env, "+%d", env->subprog_info[i].insn_processed);
>> -		verbose(env, "\n");
>> +		verbose(env, "stack depth max %d\n", env->max_stack_depth);
>> +		for (i = 0; i < subprog_cnt; i++) {
>> +			const char *name = env->subprog_info[i].name;
>> +
>> +			if (!name || !name[0])
>> +				name = "<unknown>";
>> +			if (i == 0)
>> +				verbose(env, "prog (%s) insns %d stack %d\n", name,
>> +					env->subprog_info[i].insn_processed,
>> +					env->subprog_info[i].stack_depth);
>> +			else
>> +				verbose(env, "subprog %d (%s) insns %d stack %d\n", i, name,
>> +					env->subprog_info[i].insn_processed,
>> +					env->subprog_info[i].stack_depth);
>> +		}
>>  	}
>
> The new loop prints insns %d for every subprogram, but
> subprog_info[i].insn_processed is only ever written for the main program
> and for global subprograms. The old code encoded exactly that with an
> explicit filter:
>
> kernel/bpf/verifier.c (old):
>     verbose(env, "insns processed %d", env->subprog_info[0].insn_processed);
>     for (i = 1; i < subprog_cnt; i++)
>         if (bpf_subprog_is_global(env, i))          /* <-- filter removed */
>             verbose(env, "+%d", env->subprog_info[i].insn_processed);
>
> The only two writers are do_check_main() and do_check_subprogs(). The
> latter is reached only after:
>
> kernel/bpf/verifier.c:18711
>     if (!bpf_subprog_is_global(env, i))
>         continue;
>
> and the whole function returns early at:
>
> kernel/bpf/check_btf.c:1070
>     if (!aux->func_info)
>         return 0;
>
> env is kvzalloc'd, so for every static subprogram, callback (bpf_loop,
> timer), and every subprogram of a program loaded without BTF func_info,
> insn_processed is structurally always 0. Those instructions were counted
> into the caller's record, because static subprogs are verified inline as
> part of the calling frame.
>
> Does this mean that for any program using static subprograms or callbacks
> the new per-subprog insns field shows 0 rather than where verifier work is
> actually spent?
>
> The patch's own new expectations confirm this. Every "subprog N (...) insns"
> line added in this commit is for a non-global subprogram (dummy_loop_callback,
> cumulative_stack_depth_subprog, timer_cb1, subprog1, subprog2), and each
> uses the permissive {{[0-9]+}} regex that matches 0.
>
> This directly contradicts the stated purpose: "it is hard to see where
> verifier work is spent". Either the bpf_subprog_is_global() filter should
> be kept (omit the field, or the whole record, for subprograms that are not
> independently verified), or the field should be marked as not-measured
> (e.g. insns -) so that 0 is not mistaken for a real measurement.
>

This is valid, and should be considered.

> Related coverage loss from the same root cause:
>
>> diff --git a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
>> index 67dc352addfd7..1755f133f0205 100644
>> --- a/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
>> +++ b/tools/testing/selftests/bpf/progs/verifier_global_subprogs.c
>> @@ -52,7 +52,7 @@ __msg("('global_calls_good_only') is global and assumed valid.")
>>  /* eventually global_good() is transitively validated as well */
>>  __msg("Validating global_good() func")
>>  __msg("('global_good') is safe for any args that match its prototype")
>> -__msg("insns processed {{[0-9]+\\+[0-9]+\\+[0-9]+$}}")
>> +__msg("prog (chained_global_func_calls_success) insns {{[0-9]+}} stack")
>
> The old anchored pattern asserted that exactly three independent counts
> were emitted (main + global_calls_good_only + global_good). The
> replacement checks only the main-program record and asserts nothing about
> the two global subprogram records. Could the one test that actually
> validated per-global-subprog instruction accounting be preserved?
>
>
> The BPF_LOG_STATS payload grows roughly an order of magnitude per
> subprogram, which can turn a previously-succeeding program load into
> -ENOSPC for callers that pass their own fixed log buffer.
>
> Old stats output scaled at about 4 bytes per subprogram ("+%d" for the
> stack chain, plus "+%d" only for global subprogs). New output emits a full
> line per subprogram: "subprog %d (%s) insns %d stack %d\n", roughly 40-50
> bytes plus the BTF name, which btf_name_valid_identifier() bounds only by
> KSYM_NAME_LEN == 512. With BPF_MAX_SUBPROGS == 256 permitted subprograms
> the stats section goes from under ~2 KB to well over ~12 KB, and far more
> with long function names.
>
> Does this matter? Looking at the load path:
>
> kernel/bpf/log.c:45-58 bpf_vlog_update_len_max()
>     tracks the required size in log->len_max.
>
> kernel/bpf/log.c:295 bpf_vlog_finalize()
>     returns -ENOSPC when log->ubuf && log->len_max > log->len_total.
>
> kernel/bpf/verifier.c:20397-20402 bpf_check()
>     err = bpf_log_attr_finalize(attr_log, &env->log);
>     if (err) ret = err;
>     if (ret) goto err_release_maps;
>
> so the successful verification is turned into a failed BPF_PROG_LOAD.
>
> A userspace loader that sets log_level = 4 (stats only) with a modest,
> fixed log_buf sized against the old output will start failing to load
> multi-subprogram programs after this change. libbpf only auto-retries with
> a larger buffer when it owns the buffer:
>
> tools/lib/bpf/libbpf.c:8064-8071
>     if (own_log_buf && errno == ENOSPC ...)
>
> so callers supplying their own log_buf get the failure.
>
> Could the number of per-subprog records be bounded, or emitted only above
> some log level, to avoid the behaviour change for stats-only callers?
>

This is a stretch. In practice, we won't have such small buffers.

>
> ---
> AI reviewed your patch. Please fix the bug or email reply why it's not a bug.
> See: https://github.com/kernel-patches/vmtest/blob/master/ci/claude/README.md
>
> CI run summary: https://github.com/kernel-patches/bpf/actions/runs/30891720984