lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <202306102230.b5aa258d-oliver.sang@intel.com>
Date:   Sat, 10 Jun 2023 23:25:27 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Ajay Kaher <akaher@...are.com>
CC:     <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
        Steven Rostedt <rostedt@...dmis.org>,
        Ching-lin Yu <chinglinyu@...gle.com>,
        <linux-kernel@...r.kernel.org>,
        <linux-trace-kernel@...r.kernel.org>, <mhiramat@...nel.org>,
        <shuah@...nel.org>, <linux-kselftest@...r.kernel.org>,
        <namit@...are.com>, <srivatsa@...il.mit.edu>,
        <amakhalov@...are.com>, <vsirnapalli@...are.com>,
        <tkundu@...are.com>, <er.ajay.kaher@...il.com>,
        Ajay Kaher <akaher@...are.com>, <oliver.sang@...el.com>
Subject: Re: [PATCH v3 09/10] eventfs: moving tracing/events to eventfs



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: https://lore.kernel.org/all/1685610013-33478-10-git-send-email-akaher@vmware.com/
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 <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202306102230.b5aa258d-oliver.sang@intel.com


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 ***

kern  :warn  : [  173.910026] 1 lock held by ftracetest/2186:
kern :warn : [  173.910488] #0: ffffffff84e6d640 (eventfs_rwsem/1){.+.+}-{3:3}, at: dcache_dir_open_wrapper (fs/tracefs/event_inode.c:364) 
kern  :warn  : [  173.911413]
stack backtrace:
kern  :warn  : [  173.911955] CPU: 13 PID: 2186 Comm: ftracetest Not tainted 6.4.0-rc1-00014-ga3bb763435d4 #1
kern  :warn  : [  173.912777] Hardware name: Gigabyte Technology Co., Ltd. X299 UD4 Pro/X299 UD4 Pro-CF, BIOS F8a 04/27/2021
kern  :warn  : [  173.913694] Call Trace:
kern  :warn  : [  173.914014]  <TASK>
kern :warn : [  173.914305] dump_stack_lvl (lib/dump_stack.c:108) 
kern :warn : [  173.914727] check_noncircular (kernel/locking/lockdep.c:2191) 
kern :warn : [  173.915199] ? print_circular_bug (kernel/locking/lockdep.c:2167) 
kern :warn : [  173.915676] ? mark_usage (kernel/locking/lockdep.c:4930) 
kern :warn : [  173.916100] check_prev_add (kernel/locking/lockdep.c:3109) 
kern :warn : [  173.916553] __lock_acquire (kernel/locking/lockdep.c:3228 kernel/locking/lockdep.c:3842 kernel/locking/lockdep.c:5074) 
kern :warn : [  173.917003] ? mark_usage (kernel/locking/lockdep.c:4930) 
kern :warn : [  173.917425] ? __lock_acquire (arch/x86/include/asm/bitops.h:228 arch/x86/include/asm/bitops.h:240 include/asm-generic/bitops/instrumented-non-atomic.h:142 kernel/locking/lockdep.c:228 kernel/locking/lockdep.c:3754 kernel/locking/lockdep.c:3810 kernel/locking/lockdep.c:5074) 
kern :warn : [  173.917889] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5693 kernel/locking/lockdep.c:5656) 
kern :warn : [  173.918309] ? dcache_dir_open_wrapper (fs/tracefs/event_inode.c:373) 
kern :warn : [  173.918822] ? lock_sync (kernel/locking/lockdep.c:5659) 
kern :warn : [  173.919253] ? preempt_notifier_dec (kernel/sched/core.c:10108) 
kern :warn : [  173.919729] ? lock_sync (kernel/locking/lockdep.c:5659) 
kern :warn : [  173.920144] 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.920552] ? dcache_dir_open_wrapper (fs/tracefs/event_inode.c:373) 
kern :warn : [  173.921064] ? down_write_killable_nested (kernel/locking/rwsem.c:1571) 
kern :warn : [  173.921599] ? __lock_release+0x111/0x440 
kern :warn : [  173.922097] ? do_dentry_open (fs/open.c:872) 
kern :warn : [  173.922540] dcache_dir_open_wrapper (fs/tracefs/event_inode.c:373) 
kern :warn : [  173.923039] ? fsnotify_perm+0x13b/0x4a0 
kern :warn : [  173.923548] do_dentry_open (fs/open.c:920) 
kern :warn : [  173.923982] ? eventfs_create_dir (fs/tracefs/event_inode.c:349) 
kern :warn : [  173.924470] ? may_open (fs/namei.c:3265) 
kern :warn : [  173.924869] do_open (fs/namei.c:3636) 
kern :warn : [  173.925255] path_openat (fs/namei.c:3792) 
kern :warn : [  173.926598] ? path_lookupat (fs/namei.c:3773) 
kern :warn : [  173.927039] ? .slowpath (kernel/locking/qspinlock.c:317) 
kern :warn : [  173.927454] ? lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5693 kernel/locking/lockdep.c:5656) 
kern :warn : [  173.927889] ? __create_object (mm/kmemleak.c:678) 
kern :warn : [  173.928347] do_filp_open (fs/namei.c:3818) 
kern :warn : [  173.928768] ? may_open_dev (fs/namei.c:3812) 
kern :warn : [  173.929202] ? _raw_spin_unlock (arch/x86/include/asm/preempt.h:95 include/linux/spinlock_api_smp.h:143 kernel/locking/spinlock.c:186) 
kern :warn : [  173.929651] ? alloc_fd (fs/file.c:555 (discriminator 10)) 
kern :warn : [  173.930060] ? getname_flags (fs/namei.c:206) 
kern :warn : [  173.930544] do_sys_openat2 (fs/open.c:1356) 
kern :warn : [  173.930979] ? build_open_flags (fs/open.c:1342) 
kern :warn : [  173.931460] __x64_sys_openat (fs/open.c:1383) 
kern :warn : [  173.931909] ? __ia32_compat_sys_open (fs/open.c:1383) 
kern :warn : [  173.932416] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4539) 
kern :warn : [  173.933016] ? syscall_enter_from_user_mode (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 kernel/entry/common.c:111) 
kern :warn : [  173.933552] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
kern :warn : [  173.933966] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120) 
kern  :warn  : [  173.934500] RIP: 0033:0x7fc11f551e41
kern :warn : [ 173.934913] 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
All code
========
   0:	44 24 18             	rex.R and $0x18,%al
   3:	31 c0                	xor    %eax,%eax
   5:	41 83 e2 40          	and    $0x40,%r10d
   9:	75 3e                	jne    0x49
   b:	89 f0                	mov    %esi,%eax
   d:	25 00 00 41 00       	and    $0x410000,%eax
  12:	3d 00 00 41 00       	cmp    $0x410000,%eax
  17:	74 30                	je     0x49
  19:	89 f2                	mov    %esi,%edx
  1b:	b8 01 01 00 00       	mov    $0x101,%eax
  20:	48 89 fe             	mov    %rdi,%rsi
  23:	bf 9c ff ff ff       	mov    $0xffffff9c,%edi
  28:	0f 05                	syscall 
  2a:*	48 3d 00 f0 ff ff    	cmp    $0xfffffffffffff000,%rax		<-- trapping instruction
  30:	77 3f                	ja     0x71
  32:	48 8b 54 24 18       	mov    0x18(%rsp),%rdx
  37:	64 48 2b 14 25 28 00 	sub    %fs:0x28,%rdx
  3e:	00 00 

Code starting with the faulting instruction
===========================================
   0:	48 3d 00 f0 ff ff    	cmp    $0xfffffffffffff000,%rax
   6:	77 3f                	ja     0x47
   8:	48 8b 54 24 18       	mov    0x18(%rsp),%rdx
   d:	64 48 2b 14 25 28 00 	sub    %fs:0x28,%rdx
  14:	00 00 


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        sudo bin/lkp install job.yaml           # job file is attached in this email
        bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
        sudo bin/lkp run generated-yaml-file

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki



View attachment "config-6.4.0-rc1-00014-ga3bb763435d4" of type "text/plain" (162889 bytes)

View attachment "job-script" of type "text/plain" (6374 bytes)

Download attachment "kmsg.xz" of type "application/x-xz" (51468 bytes)

View attachment "kernel-selftests" of type "text/plain" (4118 bytes)

View attachment "job.yaml" of type "text/plain" (5067 bytes)

View attachment "reproduce" of type "text/plain" (247 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ