Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
From:   Hao Sun <sunhao.th@gmail.com>
Date:   Thu, 27 Oct 2022 10:27:28 +0800
Message-ID: <CACkBjsakT_yWxnSWr4r-0TpPvbKm9-OBmVUhJb7hV3hY8fdCkw@mail.gmail.com>
Subject: WARNING in bpf_bprintf_prepare
To:     Linux Kernel Mailing List <linux-kernel@vger.kernel.org>
Cc:     andrii@kernel.org, ast@kernel.org, bpf <bpf@vger.kernel.org>,
        daniel@iogearbox.net, haoluo@google.com, john.fastabend@gmail.com,
        jolsa@kernel.org, kpsingh@kernel.org, martin.lau@linux.dev,
        sdf@google.com, song@kernel.org, yhs@fb.com
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

Hi,

The following warning can be triggered with the C reproducer in the link.
Syzbot also reported this several days ago, Jiri posted a patch that
uses bpf prog `active` field to fix this by 05b24ff9b2cfab (bpf:
Prevent bpf program recursion...) according to syzbot dashboard
(https://syzkaller.appspot.com/bug?id=179313fb375161d50a98311a28b8e2fc5f7350f9).
But this warning can still be triggered on 247f34f7b803
(Linux-v6.1-rc2) that already merged the patch, so it seems that this
still is an issue.

HEAD commit: 247f34f7b803 Linux 6.1-rc2
git tree: upstream
console output: https://pastebin.com/raw/kNw8JCu5
kernel config: https://pastebin.com/raw/sE5QK5HL
C reproducer: https://pastebin.com/raw/X96ASi27

------------[ cut here ]------------
WARNING: CPU: 6 PID: 6850 at kernel/bpf/helpers.c:770
try_get_fmt_tmp_buf kernel/bpf/helpers.c:770 [inline]
WARNING: CPU: 6 PID: 6850 at kernel/bpf/helpers.c:770
bpf_bprintf_prepare+0xf6a/0x1170 kernel/bpf/helpers.c:818
Modules linked in:
CPU: 6 PID: 6850 Comm: a.out Not tainted 6.1.0-rc2-dirty #23
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
RIP: 0010:try_get_fmt_tmp_buf kernel/bpf/helpers.c:770 [inline]
RIP: 0010:bpf_bprintf_prepare+0xf6a/0x1170 kernel/bpf/helpers.c:818
Code: c6 e8 ba 51 00 07 83 c0 01 48 98 48 01 c5 48 89 6c 24 08 e8 b8
0a eb ff 8d 6b 02 83 44 24 10 01 e9 2d f5 ff ff e8 a6 0a eb ff <0f> 0b
65 ff 0d 85 bf 7c 7e bf 01 00 00 00 41 bc f0 ff ff ff e8 2d
RSP: 0018:ffffc90015a96c20 EFLAGS: 00010046
RAX: 0000000000000000 RBX: 0000000000000002 RCX: ffff88814f8057c0
RDX: 0000000000000000 RSI: ffff88814f8057c0 RDI: 0000000000000002
RBP: ffffc90015a96d50 R08: ffffffff818681ba R09: 0000000000000003
R10: 0000000000000005 R11: fffffbfff1a25ab2 R12: 0000000000000003
R13: 0000000000000004 R14: ffffc90015a96e08 R15: 0000000000000003
FS:  00007f012f4d2440(0000) GS:ffff8880b9d80000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f012f19ac28 CR3: 0000000148da3000 CR4: 0000000000350ee0
Call Trace:
 <TASK>
 ____bpf_trace_printk kernel/trace/bpf_trace.c:385 [inline]
 bpf_trace_printk+0xab/0x420 kernel/trace/bpf_trace.c:376
 bpf_prog_0605f9f479290f07+0x2f/0x33
 bpf_dispatcher_nop_func include/linux/bpf.h:963 [inline]
 __bpf_prog_run include/linux/filter.h:600 [inline]
 bpf_prog_run include/linux/filter.h:607 [inline]
 __bpf_trace_run kernel/trace/bpf_trace.c:2254 [inline]
 bpf_trace_run2+0x14d/0x3d0 kernel/trace/bpf_trace.c:2293
 __bpf_trace_contention_begin+0xb5/0xf0 include/trace/events/lock.h:95
 __traceiter_contention_begin+0x56/0x90 include/trace/events/lock.h:95
 trace_contention_begin include/trace/events/lock.h:95 [inline]
 __pv_queued_spin_lock_slowpath+0x542/0xff0 kernel/locking/qspinlock.c:405
 pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:591 [inline]
 queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:51 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:114 [inline]
 do_raw_spin_lock+0x204/0x2d0 kernel/locking/spinlock_debug.c:115
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:111 [inline]
 _raw_spin_lock_irqsave+0x41/0x50 kernel/locking/spinlock.c:162
 ____bpf_trace_printk kernel/trace/bpf_trace.c:390 [inline]
 bpf_trace_printk+0xcf/0x420 kernel/trace/bpf_trace.c:376
 </TASK>

Regards
Hao Sun