On 19-Jul-2023, at 7:53 PM, Steven Rostedt rostedt@goodmis.org wrote:
!! External Email
On Wed, 19 Jul 2023 10:25:28 +0000 Ajay Kaher akaher@vmware.com wrote:
- Is it also reproducible on v3?
- Is it manually reproducible or reproducible using any specific script?
Let me know if I can help.
Just tried it against v3, and it gave me the splat that I originally had and starting to fix, which now gives me another splat. I'll spend a couple more days on it and start sharing code and seeing if we can work together on this.
Here's the reproducer (of both v3 splat and the bug I'm hitting now).
~# echo 'p:sock_getattr 0xffffffff9b55cef0 sk=%di' > /sys/kernel/tracing/kprobe_events ~# ls /sys/kernel/debug/tracing/events/kprobes/sock_getattr/ ~# echo '-:sock_getattr 0xffffffff9b55cef0 sk=%di' > /sys/kernel/tracing/kprobe_events
I tried above steps on v4 but couldn’t reproduce:
root@photon-6 [ ~/sdb/linux ]# echo 'p:sock_getattr 0xffffffff9b55cef0 sk=%di' > /sys/kernel/tracing/kprobe_events root@photon-6 [ ~/sdb/linux ]# ls /sys/kernel/debug/tracing/events/kprobes/sock_getattr/ enable filter format id trigger root@photon-6 [ ~/sdb/linux ]# echo '-:sock_getattr 0xffffffff9b55cef0 sk=%di' > /sys/kernel/tracing/kprobe_events -bash: echo: write error: No such file or directory
I have doubt on call_srcu(), it may first end the grace period for parent then for child. If this is true then free_list will have unordered list and could cause problem.
v3 gives me (and my updates too)
====================================================== WARNING: possible circular locking dependency detected 6.5.0-rc1-test+ #576 Not tainted
trace-cmd/840 is trying to acquire lock: ffff8881007e5de0 (&sb->s_type->i_mutex_key#5){++++}-{3:3}, at: dcache_dir_open_wrapper+0xc1/0x1b0
but task is already holding lock: ffff888103ad7e70 (eventfs_rwsem/1){.+.+}-{3:3}, at: dcache_dir_open_wrapper+0x6f/0x1b0
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 (eventfs_rwsem/1){.+.+}-{3:3}: down_read_nested+0x41/0x180 eventfs_root_lookup+0x42/0x120 __lookup_slow+0xff/0x1b0 walk_component+0xdb/0x150 path_lookupat+0x67/0x1a0 filename_lookup+0xe4/0x1f0 vfs_statx+0x9e/0x180 vfs_fstatat+0x51/0x70 __do_sys_newfstatat+0x3f/0x80 do_syscall_64+0x3a/0xc0 entry_SYSCALL_64_after_hwframe+0x6e/0xd8
-> #0 (&sb->s_type->i_mutex_key#5){++++}-{3:3}: __lock_acquire+0x165d/0x2390 lock_acquire+0xd4/0x2d0 down_write+0x3b/0xd0 dcache_dir_open_wrapper+0xc1/0x1b0 do_dentry_open+0x20c/0x510 path_openat+0x7ad/0xc60 do_filp_open+0xaf/0x160 do_sys_openat2+0xab/0xe0 __x64_sys_openat+0x6a/0xa0 do_syscall_64+0x3a/0xc0 entry_SYSCALL_64_after_hwframe+0x6e/0xd8
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1 ---- ----
rlock(eventfs_rwsem/1); lock(&sb->s_type->i_mutex_key#5); lock(eventfs_rwsem/1); lock(&sb->s_type->i_mutex_key#5);
*** DEADLOCK ***
1 lock held by trace-cmd/840: #0: ffff888103ad7e70 (eventfs_rwsem/1){.+.+}-{3:3}, at: dcache_dir_open_wrapper+0x6f/0x1b0
stack backtrace: CPU: 7 PID: 840 Comm: trace-cmd Not tainted 6.5.0-rc1-test+ #576 Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 Call Trace:
<TASK> dump_stack_lvl+0x57/0x90 check_noncircular+0x14b/0x160 __lock_acquire+0x165d/0x2390 lock_acquire+0xd4/0x2d0 ? dcache_dir_open_wrapper+0xc1/0x1b0 down_write+0x3b/0xd0 ? dcache_dir_open_wrapper+0xc1/0x1b0 dcache_dir_open_wrapper+0xc1/0x1b0 ? __pfx_dcache_dir_open_wrapper+0x10/0x10 do_dentry_open+0x20c/0x510 path_openat+0x7ad/0xc60 do_filp_open+0xaf/0x160 do_sys_openat2+0xab/0xe0 __x64_sys_openat+0x6a/0xa0 do_syscall_64+0x3a/0xc0 entry_SYSCALL_64_after_hwframe+0x6e/0xd8 RIP: 0033:0x7f1743267e41 Code: 44 24 18 31 c0 41 83 e2 40 75 3e 89 f0 25 00 00 41 00 3d 00 00 41 00 74 30 89 f2 b8 01 01 00 00 48 89 fe bf 9c ff ff ff 0f 05 <48> 3d 00 f0 ff ff 77 3f 48 8b 54 24 18 64 48 2b 14 25 28 00 00 00 RSP: 002b:00007ffec10ff5d0 EFLAGS: 00000287 ORIG_RAX: 0000000000000101 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f1743267e41 RDX: 0000000000090800 RSI: 00007ffec10ffdb0 RDI: 00000000ffffff9c RBP: 00007ffec10ffda0 R08: 00007ffec11003e0 R09: 0000000000000040 R10: 0000000000000000 R11: 0000000000000287 R12: 00007ffec11003e0 R13: 0000000000000040 R14: 0000000000000000 R15: 00007ffec110034b </TASK>
This is expected from v3 (just ignore as of now), if eventfs_set_ef_status_free crash not reproduced on v3 then it’s v4 issue.
-Ajay
I moved the code around a bit, and it appears that kprobes is getting dput() more than once.
I moved the d_invalidate() and dput() into the workqueue function, and on kprobes going away, d_invalidate() frees it, and dput() is now corrupted.
Still investigating. The VFS layer is a magic box that needs the right wizard hat to deal with, but I unfortunately am waiting on back order to retrieve that specific hat :-p
-- Steve
!! External Email: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender.