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@templeofstupid.com 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