Thread (26 messages) 26 messages, 4 authors, 2023-07-03

Re: [PATCH v3 09/10] eventfs: moving tracing/events to eventfs

From: Ajay Kaher <hidden>
Date: 2023-06-13 07:10:48
Also in: linux-kselftest, lkml, oe-lkp

Hello,

kernel test robot noticed "WARNING:possible_circular_locking_dependency_detected" on:

commit: a3bb763435d444023d3bca5479da632c57724619 ("[PATCH v3 09/10] eventfs: moving tracing/events to eventfs")
url: https://github.com/intel-lab-lkp/linux/commits/Ajay-Kaher/tracing-Require-all-trace-events-to-have-a-TRACE_SYSTEM/20230601-230657
base: https://git.kernel.org/cgit/linux/kernel/git/shuah/linux-kselftest.git next
patch link: 1685610013-33478-10-git-send-email-akaher@vmware.com/">https://lore.kernel.org/all/1685610013-33478-10-git-send-email-akaher@vmware.com/ (local)
patch subject: [PATCH v3 09/10] eventfs: moving tracing/events to eventfs

in testcase: kernel-selftests
version: kernel-selftests-x86_64-60acb023-1_20230329
with following parameters:

group: ftrace

test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt


compiler: gcc-12
test machine: 36 threads 1 sockets Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (Cascade Lake) with 32G memory

(please refer to attached dmesg/kmsg for entire log/backtrace)



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot [off-list ref]
| Closes: 202306102230.b5aa258d-oliver.sang@intel.com">https://lore.kernel.org/oe-lkp/202306102230.b5aa258d-oliver.sang@intel.com (local)


kern  :warn  : [  173.884312] WARNING: possible circular locking dependency detected
kern  :warn  : [  173.884947] 6.4.0-rc1-00014-ga3bb763435d4 #1 Not tainted
kern  :warn  : [  173.885501] ------------------------------------------------------
kern  :warn  : [  173.886125] ftracetest/2186 is trying to acquire lock:
kern :warn : [  173.886665] ffff88810045d368 (&sb->s_type->i_mutex_key#5){++++}-{3:3}, at: dcache_dir_open_wrapper (fs/tracefs/event_inode.c:373)
kern  :warn  : [  173.887638]
but task is already holding lock:
kern :warn : [  173.888299] ffffffff84e6d640 (eventfs_rwsem/1){.+.+}-{3:3}, at: dcache_dir_open_wrapper (fs/tracefs/event_inode.c:364)
kern  :warn  : [  173.889183]
which lock already depends on the new lock.

kern  :warn  : [  173.890101]
the existing dependency chain (in reverse order) is:
kern  :warn  : [  173.890898]
-> #1 (eventfs_rwsem/1){.+.+}-{3:3}:
kern :warn : [  173.891600] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5693 kernel/locking/lockdep.c:5656)
kern :warn : [  173.892066] down_read_nested (kernel/locking/rwsem.c:1263 kernel/locking/rwsem.c:1646)
kern :warn : [  173.892553] eventfs_root_lookup (fs/tracefs/event_inode.c:283)
kern :warn : [  173.893058] __lookup_slow (include/linux/dcache.h:359 include/linux/dcache.h:364 fs/namei.c:1691)
kern :warn : [  173.893529] walk_component (include/linux/fs.h:790 fs/namei.c:1708 fs/namei.c:1998)
kern :warn : [  173.894006] path_lookupat (fs/namei.c:2455 fs/namei.c:2479)
kern :warn : [  173.894476] filename_lookup (fs/namei.c:2508)
kern :warn : [  173.894974] vfs_statx (fs/stat.c:239)
kern :warn : [  173.895410] vfs_fstatat (fs/stat.c:277)
kern :warn : [  173.895851] __do_sys_newfstatat (fs/stat.c:447)
kern :warn : [  173.896350] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
kern :warn : [  173.896815] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
kern  :warn  : [  173.897392]
-> #0 (&sb->s_type->i_mutex_key#5){++++}-{3:3}:
kern :warn : [  173.898158] check_prev_add (kernel/locking/lockdep.c:3109)
kern :warn : [  173.898643] __lock_acquire (kernel/locking/lockdep.c:3228 kernel/locking/lockdep.c:3842 kernel/locking/lockdep.c:5074)
kern :warn : [  173.899133] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5693 kernel/locking/lockdep.c:5656)
kern :warn : [  173.899610] down_write (arch/x86/include/asm/preempt.h:80 kernel/locking/rwsem.c:1304 kernel/locking/rwsem.c:1315 kernel/locking/rwsem.c:1574)
kern :warn : [  173.900054] dcache_dir_open_wrapper (fs/tracefs/event_inode.c:373)
kern :warn : [  173.900603] do_dentry_open (fs/open.c:920)
kern :warn : [  173.901081] do_open (fs/namei.c:3636)
kern :warn : [  173.901508] path_openat (fs/namei.c:3792)
kern :warn : [  173.901963] do_filp_open (fs/namei.c:3818)
kern :warn : [  173.902425] do_sys_openat2 (fs/open.c:1356)
kern :warn : [  173.902902] __x64_sys_openat (fs/open.c:1383)
kern :warn : [  173.903408] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
kern :warn : [  173.903864] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
kern  :warn  : [  173.904451]
other info that might help us debug this:

kern  :warn  : [  173.905372]  Possible unsafe locking scenario:

kern  :warn  : [  173.906049]        CPU0                    CPU1
kern  :warn  : [  173.906538]        ----                    ----
kern  :warn  : [  173.907027]   rlock(eventfs_rwsem/1);
kern  :warn  : [  173.907464]                                lock(&sb->s_type->i_mutex_key#5);
kern  :warn  : [  173.908171]                                lock(eventfs_rwsem/1);
kern  :warn  : [  173.908800]   lock(&sb->s_type->i_mutex_key#5);
kern  :warn  : [  173.909291]
*** DEADLOCK ***
Steve, this seems not to be a problem here as dcache_dir_open_wrapper()
and eventfs_root_lookup() both lock eventfs_rwsem as read lock, however
it’s known problem in Lockdep for rwlock:
https://lpc.events/event/2/contributions/74/
And available patchset on Lockdep not upstreamed:
https://lore.kernel.org/all/20190829083132.22394-1-duyuyang@gmail.com/ (local)

-Ajay
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help