On Fri, Jun 09, 2023 at 11:15:18AM -0700, Alexei Starovoitov wrote:
> On Thu, Jun 8, 2023 at 5:11 PM Krister Johansen <kjlx@xxxxxxxxxxxxxxxxxx> wrote:
> > +SEC("fexit/bpf_testmod_return_ptr")
> > +int BPF_PROG(handle_fexit_ret_subprogs, int arg, struct file *ret)
> > +{
> > + *(volatile long *)ret;
> > + *(volatile int *)&ret->f_mode;
> > + bpf_for_each_map_elem(&test_array, test_cb, NULL, 0);
> > + return 0;
> > +}
> > +
> > +SEC("fexit/bpf_testmod_return_ptr")
> > +int BPF_PROG(handle_fexit_ret_subprogs2, int arg, struct file *ret)
> > +{
> > + *(volatile long *)ret;
> > + *(volatile int *)&ret->f_mode;
> > + bpf_for_each_map_elem(&test_array, test_cb, NULL, 0);
> > + return 0;
> > +}
> > +
> > +SEC("fexit/bpf_testmod_return_ptr")
> > +int BPF_PROG(handle_fexit_ret_subprogs3, int arg, struct file *ret)
> > +{
> > + *(volatile long *)ret;
> > + *(volatile int *)&ret->f_mode;
> > + bpf_for_each_map_elem(&test_array, test_cb, NULL, 0);
> > + return 0;
> > +}
>
> What is the point of attaching 3 the same progs to the same hook?
> One would be enough to test it, no?
I thought so too, initially. However, when I went to move this from the
original test case I submitted to the selftest, I found it was fairly
inconsistent about reproducing the problem with a single program. I
believe this is because the kallsyms are stored in a binary tree, and
the prog and func[0] are identical. Depending on where the item is
placed, the func[0] with the extable can sometimes be looked up instead
of the prog without.
Yonghong requested that I make note of this in the patch commit message.
I'll make sure that's included in the next version I send out.
> In other news...
> Looks like this test is triggering a bug on s390.
Not sure if this is worth mentioning, but when I run with
panic_on_oops=0 to capture the stack, I'm seeing some additional
warnings that follow the bpf bug. Is any of this of interest?
BUG: sleeping function called from invalid context at include/linux/percpu-rwsem.h:49
in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 1132, name: test_progs
preempt_count: 0, expected: 0
RCU nest depth: 2, expected: 0
INFO: lockdep is turned off.
CPU: 0 PID: 1132 Comm: test_progs Tainted: G D OE 6.4.0-rc3+ #2
Call Trace:
<TASK>
dump_stack_lvl+0x63/0x90
dump_stack+0x14/0x20
__might_resched+0x21d/0x230
__might_sleep+0x45/0x70
exit_signals+0x35/0x200
do_exit+0xc6/0x920
? rewind_stack_and_make_dead+0x17/0x20
? make_task_dead+0xbe/0x140
? make_task_dead+0xbe/0x140
make_task_dead+0x88/0x140
rewind_stack_and_make_dead+0x17/0x20
RIP: 0033:0x7fb5da00a392
Code: ac 00 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb be 0f 1f 80 00 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24
RSP: 002b:00007ffc5b3cab68 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000055bee7b8b100 RCX: 00007fb5da00a392
RDX: 00000000000001c8 RSI: 0000000000000000 RDI: 0000000000000009
RBP: 00007ffc5b3caba0 R08: 0000000000000000 R09: 0000000000000037
R10: 000055bee7b8c2a7 R11: 0000000000000246 R12: 000055bee78f1f60
R13: 00007ffc5b3cae90 R14: 0000000000000000 R15: 0000000000000000
</TASK>
------------[ cut here ]------------
Voluntary context switch within RCU read-side critical section!
WARNING: CPU: 0 PID: 1132 at kernel/rcu/tree_plugin.h:318 rcu_note_context_switch+0x4c0/0x5f0
Modules linked in: bpf_testmod(OE) nls_iso8859_1 dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua intel_rapl_msr intel_rapl_common intel_uncore_frequency_common ppdev nfit crct10dif_pclmul crc32_pclmul psmouse ghash_clmulni_intel sha512_ssse3 aesni_intel parport_pc crypto_simd cryptd input_leds parport rapl ena i2c_piix4 mac_hid serio_raw ramoops reed_solomon pstore_blk drm pstore_zone efi_pstore autofs4 [last unloaded: bpf_testmod(OE)]
CPU: 0 PID: 1132 Comm: test_progs Tainted: G D W OE 6.4.0-rc3+ #2
RIP: 0010:rcu_note_context_switch+0x4c0/0x5f0
Code: fb ff ff 0f 0b e9 e0 fb ff ff e8 4b dd e3 ff a8 04 75 b5 0f 0b eb b1 c6 05 e4 03 a4 02 01 48 c7 c7 45 4a a1 ab e8 c0 e2 f1 ff <0f> 0b e9 f7 fb ff ff 0f 0b 45 84 f6 0f 84 d6 fb ff ff e9 e7 fb ff
RSP: 0018:ffffb30c4291f9a8 EFLAGS: 00010046
RAX: 4599311900096300 RBX: ffff92e644bf2a40 RCX: 0000000000000027
RDX: 0000000000000000 RSI: ffffb30c4291f830 RDI: ffff92e95ee21948
RBP: ffffb30c4291f9f8 R08: 0000000000000000 R09: ffffb30c4291f7d0
R10: 00000000fffeffff R11: c0000000fffeffff R12: ffff92e95ee36680
R13: ffffb30c4291fc58 R14: 0000000000000000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff92e95ee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000000000000c CR3: 000000000d25e001 CR4: 00000000007706f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
<TASK>
? lock_release+0x46/0x330
__schedule+0x173/0x1730
? trace_hardirqs_on+0x56/0xb0
? irqentry_exit+0x72/0xa0
? sysvec_irq_work+0x4a/0x90
? asm_sysvec_irq_work+0x1f/0x30
schedule+0x6f/0xc0
schedule_timeout+0x35/0x110
? native_write_msr+0xe/0x40
? __pfx_schedule_timeout+0x10/0x10
? trace_hardirqs_on+0x56/0xb0
? __pfx_schedule_timeout+0x10/0x10
do_wait_for_common+0xe9/0x170
? __pfx_schedule_timeout+0x10/0x10
? __pfx_call_rcu+0x10/0x10
wait_for_completion+0x53/0x70
__wait_rcu_gp+0x12f/0x150
synchronize_rcu_tasks_rude+0x67/0xc0
? __pfx_wakeme_after_rcu+0x10/0x10
? mutex_unlock+0x16/0x20
? __pfx_call_rcu_tasks_rude+0x10/0x10
ftrace_shutdown+0x1ea/0x290
? 0xffffffffc04b8000
unregister_ftrace_function+0x30/0x190
? 0xffffffffc04b8000
? 0xffffffffc04b8000
unregister_ftrace_direct+0x51/0xf0
? __pfx_bpf_testmod_return_ptr+0x10/0x10 [bpf_testmod]
? 0xffffffffc04b8000
bpf_trampoline_update+0x273/0x6d0
bpf_trampoline_unlink_prog+0xb4/0x110
bpf_tracing_link_release+0x1d/0x50
bpf_link_put+0xd0/0x100
bpf_link_release+0x19/0x30
__fput+0x107/0x250
____fput+0x12/0x20
task_work_run+0x89/0xd0
do_exit+0x263/0x920
? make_task_dead+0xbe/0x140
? make_task_dead+0xbe/0x140
make_task_dead+0x88/0x140
rewind_stack_and_make_dead+0x17/0x20
RIP: 0033:0x7fb5da00a392
Code: Unable to access opcode bytes at 0x7fb5da00a368.
RSP: 002b:00007ffc5b3cab68 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000055bee7b8b100 RCX: 00007fb5da00a392
RDX: 00000000000001c8 RSI: 0000000000000000 RDI: 0000000000000009
RBP: 00007ffc5b3caba0 R08: 0000000000000000 R09: 0000000000000037
R10: 000055bee7b8c2a7 R11: 0000000000000246 R12: 000055bee78f1f60
R13: 00007ffc5b3cae90 R14: 0000000000000000 R15: 0000000000000000
</TASK>
irq event stamp: 62970
hardirqs last enabled at (62969): [<ffffffffab1e14ba>] syscall_enter_from_user_mode+0x2a/0x1e0
hardirqs last disabled at (62970): [<ffffffffab1e0bb1>] exc_page_fault+0x41/0x210
softirqs last enabled at (62912): [<ffffffffaa2e2ae2>] bpf_link_settle+0x32/0x50
softirqs last disabled at (62910): [<ffffffffaa2e2acd>] bpf_link_settle+0x1d/0x50
---[ end trace 0000000000000000 ]---
-K
