| Message ID | 20230830125654.21257-6-zhangpeng.00@bytedance.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | Introduce __mt_dup() to improve the performance of fork() | expand |
Hello,
kernel test robot noticed "WARNING:possible_recursive_locking_detected" on:
commit: 2730245bd6b13a94a67e84c10832a9f52fad0aa5 ("[PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()")
url: https://github.com/intel-lab-lkp/linux/commits/Peng-Zhang/maple_tree-Add-two-helpers/20230830-205847
base: https://git.kernel.org/cgit/linux/kernel/git/akpm/mm.git mm-everything
patch link: https://lore.kernel.org/all/20230830125654.21257-6-zhangpeng.00@bytedance.com/
patch subject: [PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()
in testcase: boot
compiler: clang-16
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(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@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202308312115.cad34fed-oliver.sang@intel.com
[ 25.146957][ T1] WARNING: possible recursive locking detected
[ 25.147110][ T1] 6.5.0-rc4-00632-g2730245bd6b1 #1 Tainted: G TN
[ 25.147110][ T1] --------------------------------------------
[ 25.147110][ T1] swapper/1 is trying to acquire lock:
[ 25.147110][ T1] ffffffff86485058 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854)
[ 25.147110][ T1]
[ 25.147110][ T1] but task is already holding lock:
[ 25.147110][ T1] ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854)
[ 25.147110][ T1]
[ 25.147110][ T1] other info that might help us debug this:
[ 25.147110][ T1] Possible unsafe locking scenario:
[ 25.147110][ T1]
[ 25.147110][ T1] CPU0
[ 25.147110][ T1] ----
[ 25.147110][ T1] lock(&mt->ma_lock);
[ 25.147110][ T1]
[ 25.147110][ T1] *** DEADLOCK ***
[ 25.147110][ T1]
[ 25.147110][ T1] May be due to missing lock nesting notation
[ 25.147110][ T1]
[ 25.147110][ T1] 1 lock held by swapper/1:
[ 25.147110][ T1] #0: ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854)
[ 25.147110][ T1]
[ 25.147110][ T1] stack backtrace:
[ 25.147110][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1
[ 25.147110][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 25.147110][ T1] Call Trace:
[ 25.147110][ T1] <TASK>
[ 25.147110][ T1] dump_stack_lvl (lib/dump_stack.c:? lib/dump_stack.c:106)
[ 25.147110][ T1] validate_chain (kernel/locking/lockdep.c:?)
[ 25.147110][ T1] ? look_up_lock_class (kernel/locking/lockdep.c:926)
[ 25.147110][ T1] ? mark_lock (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:4655)
[ 25.147110][ T1] __lock_acquire (kernel/locking/lockdep.c:?)
[ 25.147110][ T1] lock_acquire (kernel/locking/lockdep.c:5753)
[ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854)
[ 25.147110][ T1] _raw_spin_lock (include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154)
[ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854)
[ 25.147110][ T1] check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854)
[ 25.147110][ T1] maple_tree_seed (lib/test_maple_tree.c:3583)
[ 25.147110][ T1] do_one_initcall (init/main.c:1232)
[ 25.147110][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508)
[ 25.147110][ T1] do_initcall_level (init/main.c:1293)
[ 25.147110][ T1] do_initcalls (init/main.c:1307)
[ 25.147110][ T1] kernel_init_freeable (init/main.c:1550)
[ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429)
[ 25.147110][ T1] kernel_init (init/main.c:1439)
[ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429)
[ 25.147110][ T1] ret_from_fork (arch/x86/kernel/process.c:151)
[ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429)
[ 25.147110][ T1] ret_from_fork_asm (arch/x86/entry/entry_64.S:312)
[ 25.147110][ T1] </TASK>
[ 28.697241][ T32] clocksource_wdtest: --- Verify jiffies-like uncertainty margin.
[ 28.698316][ T32] clocksource: wdtest-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6370867519511994 ns
[ 29.714980][ T32] clocksource_wdtest: --- Verify tsc-like uncertainty margin.
[ 29.716387][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[ 29.721896][ T32] clocksource_wdtest: --- tsc-like times: 1693478138832947444 - 1693478138832945950 = 1494.
[ 29.723570][ T32] clocksource_wdtest: --- Watchdog with 0x error injection, 2 retries.
[ 31.898906][ T32] clocksource_wdtest: --- Watchdog with 1x error injection, 2 retries.
[ 34.043415][ T32] clocksource_wdtest: --- Watchdog with 2x error injection, 2 retries, expect message.
[ 34.512462][ C0] clocksource: timekeeping watchdog on CPU0: kvm-clock retried 2 times before success
[ 36.169157][ T32] clocksource_wdtest: --- Watchdog with 3x error injection, 2 retries, expect clock skew.
[ 36.513464][ C0] clocksource: timekeeping watchdog on CPU0: wd-wdtest-ktime-wd excessive read-back delay of 1000880ns vs. limit of 125000ns, wd-wd read-back delay only 46ns, attempt 3, marking wdtest-ktime unstable
[ 36.516829][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog.
[ 38.412889][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[ 38.421249][ T32] clocksource_wdtest: --- Watchdog clock-value-fuzz error injection, expect clock skew and per-CPU mismatches.
[ 38.990462][ C0] clocksource: timekeeping watchdog on CPU0: Marking clocksource 'wdtest-ktime' as unstable because the skew is too large:
[ 38.992698][ C0] clocksource: 'kvm-clock' wd_nsec: 479996388 wd_now: 9454aecf2 wd_last: 928aec30e mask: ffffffffffffffff
[ 38.994924][ C0] clocksource: 'wdtest-ktime' cs_nsec: 679996638 cs_now: 17807167426ff864 cs_last: 1780716719e80b86 mask: ffffffffffffffff
[ 38.997374][ C0] clocksource: Clocksource 'wdtest-ktime' skewed 200000250 ns (200 ms) over watchdog 'kvm-clock' interval of 479996388 ns (479 ms)
[ 38.999919][ C0] clocksource: 'kvm-clock' (not 'wdtest-ktime') is current clocksource.
[ 39.001696][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog.
[ 40.441815][ T32] clocksource: Not enough CPUs to check clocksource 'wdtest-ktime'.
[ 40.443303][ T32] clocksource_wdtest: --- Done with test.
[ 293.673815][ T1] swapper invoked oom-killer: gfp_mask=0xcc0(GFP_KERNEL), order=0, oom_score_adj=0
[ 293.675628][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1
[ 293.677082][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 293.677082][ T1] Call Trace:
[ 293.677082][ T1] <TASK>
[ 293.677082][ T1] dump_stack_lvl (lib/dump_stack.c:107)
[ 293.677082][ T1] dump_header (mm/oom_kill.c:?)
[ 293.677082][ T1] out_of_memory (mm/oom_kill.c:1159)
[ 293.677082][ T1] __alloc_pages_slowpath (mm/page_alloc.c:3372 mm/page_alloc.c:4132)
[ 293.677082][ T1] __alloc_pages (mm/page_alloc.c:4469)
[ 293.677082][ T1] alloc_slab_page (mm/slub.c:1866)
[ 293.677082][ T1] new_slab (mm/slub.c:2017 mm/slub.c:2062)
[ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282)
[ 293.677082][ T1] ___slab_alloc (arch/x86/include/asm/preempt.h:80 mm/slub.c:3216)
[ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282)
[ 293.677082][ T1] kmem_cache_alloc_bulk (mm/slub.c:? mm/slub.c:4041)
[ 293.677082][ T1] mas_alloc_nodes (lib/maple_tree.c:1282)
[ 293.677082][ T1] mas_nomem (lib/maple_tree.c:?)
[ 293.677082][ T1] mtree_store_range (lib/maple_tree.c:6191)
[ 293.677082][ T1] check_dup_gaps (lib/test_maple_tree.c:2623)
[ 293.677082][ T1] check_dup (lib/test_maple_tree.c:2707)
[ 293.677082][ T1] maple_tree_seed (lib/test_maple_tree.c:3766)
[ 293.677082][ T1] do_one_initcall (init/main.c:1232)
[ 293.677082][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508)
[ 293.677082][ T1] do_initcall_level (init/main.c:1293)
[ 293.677082][ T1] do_initcalls (init/main.c:1307)
[ 293.677082][ T1] kernel_init_freeable (init/main.c:1550)
[ 293.677082][ T1] ? __cfi_kernel_init (init/main.c:1429)
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20230831/202308312115.cad34fed-oliver.sang@intel.com
在 2023/8/31 21:40, kernel test robot 写道: > > > Hello, > > kernel test robot noticed "WARNING:possible_recursive_locking_detected" on: > > commit: 2730245bd6b13a94a67e84c10832a9f52fad0aa5 ("[PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()") > url: https://github.com/intel-lab-lkp/linux/commits/Peng-Zhang/maple_tree-Add-two-helpers/20230830-205847 > base: https://git.kernel.org/cgit/linux/kernel/git/akpm/mm.git mm-everything > patch link: https://lore.kernel.org/all/20230830125654.21257-6-zhangpeng.00@bytedance.com/ > patch subject: [PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking() > > in testcase: boot > > compiler: clang-16 > test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G > > (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@intel.com> > | Closes: https://lore.kernel.org/oe-lkp/202308312115.cad34fed-oliver.sang@intel.com > > > [ 25.146957][ T1] WARNING: possible recursive locking detected > [ 25.147110][ T1] 6.5.0-rc4-00632-g2730245bd6b1 #1 Tainted: G TN > [ 25.147110][ T1] -------------------------------------------- > [ 25.147110][ T1] swapper/1 is trying to acquire lock: > [ 25.147110][ T1] ffffffff86485058 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > [ 25.147110][ T1] > [ 25.147110][ T1] but task is already holding lock: > [ 25.147110][ T1] ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) Thanks for the test. I checked that these are two different locks, why is this warning reported? Did I miss something? > [ 25.147110][ T1] > [ 25.147110][ T1] other info that might help us debug this: > [ 25.147110][ T1] Possible unsafe locking scenario: > [ 25.147110][ T1] > [ 25.147110][ T1] CPU0 > [ 25.147110][ T1] ---- > [ 25.147110][ T1] lock(&mt->ma_lock); > [ 25.147110][ T1] > [ 25.147110][ T1] *** DEADLOCK *** > [ 25.147110][ T1] > [ 25.147110][ T1] May be due to missing lock nesting notation > [ 25.147110][ T1] > [ 25.147110][ T1] 1 lock held by swapper/1: > [ 25.147110][ T1] #0: ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) > [ 25.147110][ T1] > [ 25.147110][ T1] stack backtrace: > [ 25.147110][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1 > [ 25.147110][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 > [ 25.147110][ T1] Call Trace: > [ 25.147110][ T1] <TASK> > [ 25.147110][ T1] dump_stack_lvl (lib/dump_stack.c:? lib/dump_stack.c:106) > [ 25.147110][ T1] validate_chain (kernel/locking/lockdep.c:?) > [ 25.147110][ T1] ? look_up_lock_class (kernel/locking/lockdep.c:926) > [ 25.147110][ T1] ? mark_lock (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:4655) > [ 25.147110][ T1] __lock_acquire (kernel/locking/lockdep.c:?) > [ 25.147110][ T1] lock_acquire (kernel/locking/lockdep.c:5753) > [ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > [ 25.147110][ T1] _raw_spin_lock (include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154) > [ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > [ 25.147110][ T1] check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > [ 25.147110][ T1] maple_tree_seed (lib/test_maple_tree.c:3583) > [ 25.147110][ T1] do_one_initcall (init/main.c:1232) > [ 25.147110][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508) > [ 25.147110][ T1] do_initcall_level (init/main.c:1293) > [ 25.147110][ T1] do_initcalls (init/main.c:1307) > [ 25.147110][ T1] kernel_init_freeable (init/main.c:1550) > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > [ 25.147110][ T1] kernel_init (init/main.c:1439) > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > [ 25.147110][ T1] ret_from_fork (arch/x86/kernel/process.c:151) > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > [ 25.147110][ T1] ret_from_fork_asm (arch/x86/entry/entry_64.S:312) > [ 25.147110][ T1] </TASK> > [ 28.697241][ T32] clocksource_wdtest: --- Verify jiffies-like uncertainty margin. > [ 28.698316][ T32] clocksource: wdtest-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6370867519511994 ns > [ 29.714980][ T32] clocksource_wdtest: --- Verify tsc-like uncertainty margin. > [ 29.716387][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns > [ 29.721896][ T32] clocksource_wdtest: --- tsc-like times: 1693478138832947444 - 1693478138832945950 = 1494. > [ 29.723570][ T32] clocksource_wdtest: --- Watchdog with 0x error injection, 2 retries. > [ 31.898906][ T32] clocksource_wdtest: --- Watchdog with 1x error injection, 2 retries. > [ 34.043415][ T32] clocksource_wdtest: --- Watchdog with 2x error injection, 2 retries, expect message. > [ 34.512462][ C0] clocksource: timekeeping watchdog on CPU0: kvm-clock retried 2 times before success > [ 36.169157][ T32] clocksource_wdtest: --- Watchdog with 3x error injection, 2 retries, expect clock skew. > [ 36.513464][ C0] clocksource: timekeeping watchdog on CPU0: wd-wdtest-ktime-wd excessive read-back delay of 1000880ns vs. limit of 125000ns, wd-wd read-back delay only 46ns, attempt 3, marking wdtest-ktime unstable > [ 36.516829][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog. > [ 38.412889][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns > [ 38.421249][ T32] clocksource_wdtest: --- Watchdog clock-value-fuzz error injection, expect clock skew and per-CPU mismatches. > [ 38.990462][ C0] clocksource: timekeeping watchdog on CPU0: Marking clocksource 'wdtest-ktime' as unstable because the skew is too large: > [ 38.992698][ C0] clocksource: 'kvm-clock' wd_nsec: 479996388 wd_now: 9454aecf2 wd_last: 928aec30e mask: ffffffffffffffff > [ 38.994924][ C0] clocksource: 'wdtest-ktime' cs_nsec: 679996638 cs_now: 17807167426ff864 cs_last: 1780716719e80b86 mask: ffffffffffffffff > [ 38.997374][ C0] clocksource: Clocksource 'wdtest-ktime' skewed 200000250 ns (200 ms) over watchdog 'kvm-clock' interval of 479996388 ns (479 ms) > [ 38.999919][ C0] clocksource: 'kvm-clock' (not 'wdtest-ktime') is current clocksource. > [ 39.001696][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog. > [ 40.441815][ T32] clocksource: Not enough CPUs to check clocksource 'wdtest-ktime'. > [ 40.443303][ T32] clocksource_wdtest: --- Done with test. > [ 293.673815][ T1] swapper invoked oom-killer: gfp_mask=0xcc0(GFP_KERNEL), order=0, oom_score_adj=0 > [ 293.675628][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1 > [ 293.677082][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 > [ 293.677082][ T1] Call Trace: > [ 293.677082][ T1] <TASK> > [ 293.677082][ T1] dump_stack_lvl (lib/dump_stack.c:107) > [ 293.677082][ T1] dump_header (mm/oom_kill.c:?) > [ 293.677082][ T1] out_of_memory (mm/oom_kill.c:1159) > [ 293.677082][ T1] __alloc_pages_slowpath (mm/page_alloc.c:3372 mm/page_alloc.c:4132) > [ 293.677082][ T1] __alloc_pages (mm/page_alloc.c:4469) > [ 293.677082][ T1] alloc_slab_page (mm/slub.c:1866) > [ 293.677082][ T1] new_slab (mm/slub.c:2017 mm/slub.c:2062) > [ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282) > [ 293.677082][ T1] ___slab_alloc (arch/x86/include/asm/preempt.h:80 mm/slub.c:3216) > [ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282) > [ 293.677082][ T1] kmem_cache_alloc_bulk (mm/slub.c:? mm/slub.c:4041) > [ 293.677082][ T1] mas_alloc_nodes (lib/maple_tree.c:1282) > [ 293.677082][ T1] mas_nomem (lib/maple_tree.c:?) > [ 293.677082][ T1] mtree_store_range (lib/maple_tree.c:6191) > [ 293.677082][ T1] check_dup_gaps (lib/test_maple_tree.c:2623) > [ 293.677082][ T1] check_dup (lib/test_maple_tree.c:2707) > [ 293.677082][ T1] maple_tree_seed (lib/test_maple_tree.c:3766) > [ 293.677082][ T1] do_one_initcall (init/main.c:1232) > [ 293.677082][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508) > [ 293.677082][ T1] do_initcall_level (init/main.c:1293) > [ 293.677082][ T1] do_initcalls (init/main.c:1307) > [ 293.677082][ T1] kernel_init_freeable (init/main.c:1550) > [ 293.677082][ T1] ? __cfi_kernel_init (init/main.c:1429) > > > The kernel config and materials to reproduce are available at: > https://download.01.org/0day-ci/archive/20230831/202308312115.cad34fed-oliver.sang@intel.com > > >
* Peng Zhang <zhangpeng.00@bytedance.com> [230901 06:58]: > > > 在 2023/8/31 21:40, kernel test robot 写道: > > > > > > Hello, > > > > kernel test robot noticed "WARNING:possible_recursive_locking_detected" on: > > > > commit: 2730245bd6b13a94a67e84c10832a9f52fad0aa5 ("[PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()") > > url: https://github.com/intel-lab-lkp/linux/commits/Peng-Zhang/maple_tree-Add-two-helpers/20230830-205847 > > base: https://git.kernel.org/cgit/linux/kernel/git/akpm/mm.git mm-everything > > patch link: https://lore.kernel.org/all/20230830125654.21257-6-zhangpeng.00@bytedance.com/ > > patch subject: [PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking() > > > > in testcase: boot > > > > compiler: clang-16 > > test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G > > > > (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@intel.com> > > | Closes: https://lore.kernel.org/oe-lkp/202308312115.cad34fed-oliver.sang@intel.com > > > > > > [ 25.146957][ T1] WARNING: possible recursive locking detected > > [ 25.147110][ T1] 6.5.0-rc4-00632-g2730245bd6b1 #1 Tainted: G TN > > [ 25.147110][ T1] -------------------------------------------- > > [ 25.147110][ T1] swapper/1 is trying to acquire lock: > > [ 25.147110][ T1] ffffffff86485058 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > > [ 25.147110][ T1] > > [ 25.147110][ T1] but task is already holding lock: > > [ 25.147110][ T1] ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) > Thanks for the test. I checked that these are two different locks, why > is this warning reported? Did I miss something? I don't think you can nest spinlocks like this. In my previous test I avoided nesting, but in your case we cannot avoid having both locks at the same time. You can get around this by using an rwsemaphore, set the two trees as external and use down_write_nested(&lock2, SINGLE_DEPTH_NESTING) like the real fork. Basically, switch the locking to exactly what fork does. > > [ 25.147110][ T1] > > [ 25.147110][ T1] other info that might help us debug this: > > [ 25.147110][ T1] Possible unsafe locking scenario: > > [ 25.147110][ T1] > > [ 25.147110][ T1] CPU0 > > [ 25.147110][ T1] ---- > > [ 25.147110][ T1] lock(&mt->ma_lock); > > [ 25.147110][ T1] > > [ 25.147110][ T1] *** DEADLOCK *** > > [ 25.147110][ T1] > > [ 25.147110][ T1] May be due to missing lock nesting notation > > [ 25.147110][ T1] > > [ 25.147110][ T1] 1 lock held by swapper/1: > > [ 25.147110][ T1] #0: ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) > > [ 25.147110][ T1] > > [ 25.147110][ T1] stack backtrace: > > [ 25.147110][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1 > > [ 25.147110][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 > > [ 25.147110][ T1] Call Trace: > > [ 25.147110][ T1] <TASK> > > [ 25.147110][ T1] dump_stack_lvl (lib/dump_stack.c:? lib/dump_stack.c:106) > > [ 25.147110][ T1] validate_chain (kernel/locking/lockdep.c:?) > > [ 25.147110][ T1] ? look_up_lock_class (kernel/locking/lockdep.c:926) > > [ 25.147110][ T1] ? mark_lock (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:4655) > > [ 25.147110][ T1] __lock_acquire (kernel/locking/lockdep.c:?) > > [ 25.147110][ T1] lock_acquire (kernel/locking/lockdep.c:5753) > > [ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > > [ 25.147110][ T1] _raw_spin_lock (include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154) > > [ 25.147110][ T1] ? check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > > [ 25.147110][ T1] check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > > [ 25.147110][ T1] maple_tree_seed (lib/test_maple_tree.c:3583) > > [ 25.147110][ T1] do_one_initcall (init/main.c:1232) > > [ 25.147110][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508) > > [ 25.147110][ T1] do_initcall_level (init/main.c:1293) > > [ 25.147110][ T1] do_initcalls (init/main.c:1307) > > [ 25.147110][ T1] kernel_init_freeable (init/main.c:1550) > > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > > [ 25.147110][ T1] kernel_init (init/main.c:1439) > > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > > [ 25.147110][ T1] ret_from_fork (arch/x86/kernel/process.c:151) > > [ 25.147110][ T1] ? __cfi_kernel_init (init/main.c:1429) > > [ 25.147110][ T1] ret_from_fork_asm (arch/x86/entry/entry_64.S:312) > > [ 25.147110][ T1] </TASK> > > [ 28.697241][ T32] clocksource_wdtest: --- Verify jiffies-like uncertainty margin. > > [ 28.698316][ T32] clocksource: wdtest-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6370867519511994 ns > > [ 29.714980][ T32] clocksource_wdtest: --- Verify tsc-like uncertainty margin. > > [ 29.716387][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns > > [ 29.721896][ T32] clocksource_wdtest: --- tsc-like times: 1693478138832947444 - 1693478138832945950 = 1494. > > [ 29.723570][ T32] clocksource_wdtest: --- Watchdog with 0x error injection, 2 retries. > > [ 31.898906][ T32] clocksource_wdtest: --- Watchdog with 1x error injection, 2 retries. > > [ 34.043415][ T32] clocksource_wdtest: --- Watchdog with 2x error injection, 2 retries, expect message. > > [ 34.512462][ C0] clocksource: timekeeping watchdog on CPU0: kvm-clock retried 2 times before success > > [ 36.169157][ T32] clocksource_wdtest: --- Watchdog with 3x error injection, 2 retries, expect clock skew. > > [ 36.513464][ C0] clocksource: timekeeping watchdog on CPU0: wd-wdtest-ktime-wd excessive read-back delay of 1000880ns vs. limit of 125000ns, wd-wd read-back delay only 46ns, attempt 3, marking wdtest-ktime unstable > > [ 36.516829][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog. > > [ 38.412889][ T32] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns > > [ 38.421249][ T32] clocksource_wdtest: --- Watchdog clock-value-fuzz error injection, expect clock skew and per-CPU mismatches. > > [ 38.990462][ C0] clocksource: timekeeping watchdog on CPU0: Marking clocksource 'wdtest-ktime' as unstable because the skew is too large: > > [ 38.992698][ C0] clocksource: 'kvm-clock' wd_nsec: 479996388 wd_now: 9454aecf2 wd_last: 928aec30e mask: ffffffffffffffff > > [ 38.994924][ C0] clocksource: 'wdtest-ktime' cs_nsec: 679996638 cs_now: 17807167426ff864 cs_last: 1780716719e80b86 mask: ffffffffffffffff > > [ 38.997374][ C0] clocksource: Clocksource 'wdtest-ktime' skewed 200000250 ns (200 ms) over watchdog 'kvm-clock' interval of 479996388 ns (479 ms) > > [ 38.999919][ C0] clocksource: 'kvm-clock' (not 'wdtest-ktime') is current clocksource. > > [ 39.001696][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog. > > [ 40.441815][ T32] clocksource: Not enough CPUs to check clocksource 'wdtest-ktime'. > > [ 40.443303][ T32] clocksource_wdtest: --- Done with test. > > [ 293.673815][ T1] swapper invoked oom-killer: gfp_mask=0xcc0(GFP_KERNEL), order=0, oom_score_adj=0 > > [ 293.675628][ T1] CPU: 0 PID: 1 Comm: swapper Tainted: G TN 6.5.0-rc4-00632-g2730245bd6b1 #1 > > [ 293.677082][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 > > [ 293.677082][ T1] Call Trace: > > [ 293.677082][ T1] <TASK> > > [ 293.677082][ T1] dump_stack_lvl (lib/dump_stack.c:107) > > [ 293.677082][ T1] dump_header (mm/oom_kill.c:?) > > [ 293.677082][ T1] out_of_memory (mm/oom_kill.c:1159) > > [ 293.677082][ T1] __alloc_pages_slowpath (mm/page_alloc.c:3372 mm/page_alloc.c:4132) > > [ 293.677082][ T1] __alloc_pages (mm/page_alloc.c:4469) > > [ 293.677082][ T1] alloc_slab_page (mm/slub.c:1866) > > [ 293.677082][ T1] new_slab (mm/slub.c:2017 mm/slub.c:2062) > > [ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282) > > [ 293.677082][ T1] ___slab_alloc (arch/x86/include/asm/preempt.h:80 mm/slub.c:3216) > > [ 293.677082][ T1] ? mas_alloc_nodes (lib/maple_tree.c:1282) > > [ 293.677082][ T1] kmem_cache_alloc_bulk (mm/slub.c:? mm/slub.c:4041) > > [ 293.677082][ T1] mas_alloc_nodes (lib/maple_tree.c:1282) > > [ 293.677082][ T1] mas_nomem (lib/maple_tree.c:?) > > [ 293.677082][ T1] mtree_store_range (lib/maple_tree.c:6191) > > [ 293.677082][ T1] check_dup_gaps (lib/test_maple_tree.c:2623) > > [ 293.677082][ T1] check_dup (lib/test_maple_tree.c:2707) > > [ 293.677082][ T1] maple_tree_seed (lib/test_maple_tree.c:3766) > > [ 293.677082][ T1] do_one_initcall (init/main.c:1232) > > [ 293.677082][ T1] ? __cfi_maple_tree_seed (lib/test_maple_tree.c:3508) > > [ 293.677082][ T1] do_initcall_level (init/main.c:1293) > > [ 293.677082][ T1] do_initcalls (init/main.c:1307) > > [ 293.677082][ T1] kernel_init_freeable (init/main.c:1550) > > [ 293.677082][ T1] ? __cfi_kernel_init (init/main.c:1429) > > > > > > The kernel config and materials to reproduce are available at: > > https://download.01.org/0day-ci/archive/20230831/202308312115.cad34fed-oliver.sang@intel.com > > > > > > >
On Thu, Sep 07, 2023 at 02:03:01PM -0400, Liam R. Howlett wrote: > > > WARNING: possible recursive locking detected > > > 6.5.0-rc4-00632-g2730245bd6b1 #1 Tainted: G TN > > > -------------------------------------------- > > > swapper/1 is trying to acquire lock: > > > ffffffff86485058 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) > > > > > > but task is already holding lock: > > > ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) > > Thanks for the test. I checked that these are two different locks, why > > is this warning reported? Did I miss something? > > I don't think you can nest spinlocks like this. In my previous test I > avoided nesting, but in your case we cannot avoid having both locks at > the same time. > > You can get around this by using an rwsemaphore, set the two trees as > external and use down_write_nested(&lock2, SINGLE_DEPTH_NESTING) like > the real fork. Basically, switch the locking to exactly what fork does. spin_lock_nested() exists. You should probably both read through Documentation/locking/lockdep-design.rst It's not the best user documentation in the world, but it's what we have.
* Peng Zhang <zhangpeng.00@bytedance.com> [230830 08:57]: > Updated check_forking() and bench_forking() to use __mt_dup() to > duplicate maple tree. Also increased the number of VMAs, because the > new way is faster. > > Signed-off-by: Peng Zhang <zhangpeng.00@bytedance.com> > --- > lib/test_maple_tree.c | 61 +++++++++++++++++++++---------------------- > 1 file changed, 30 insertions(+), 31 deletions(-) > > diff --git a/lib/test_maple_tree.c b/lib/test_maple_tree.c > index 0ec0c6a7c0b5..72fba7cce148 100644 > --- a/lib/test_maple_tree.c > +++ b/lib/test_maple_tree.c > @@ -1837,36 +1837,37 @@ static noinline void __init check_forking(struct maple_tree *mt) > { > > struct maple_tree newmt; > - int i, nr_entries = 134; > + int i, nr_entries = 300, ret; check_forking can probably remain at 134, I set it to to 134 as a 'reasonable' value. Unless you want 300 to test some specific case in your case? > void *val; > MA_STATE(mas, mt, 0, 0); > - MA_STATE(newmas, mt, 0, 0); > + MA_STATE(newmas, &newmt, 0, 0); > + > + mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); > > for (i = 0; i <= nr_entries; i++) > mtree_store_range(mt, i*10, i*10 + 5, > xa_mk_value(i), GFP_KERNEL); > > + > mt_set_non_kernel(99999); > - mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); > - newmas.tree = &newmt; > - mas_reset(&newmas); > - mas_reset(&mas); > mas_lock(&newmas); > - mas.index = 0; > - mas.last = 0; > - if (mas_expected_entries(&newmas, nr_entries)) { > + mas_lock(&mas); > + > + ret = __mt_dup(mt, &newmt, GFP_NOWAIT | __GFP_NOWARN); > + if (ret) { > pr_err("OOM!"); > BUG_ON(1); > } > - rcu_read_lock(); > - mas_for_each(&mas, val, ULONG_MAX) { > - newmas.index = mas.index; > - newmas.last = mas.last; > + > + mas_set(&newmas, 0); > + mas_for_each(&newmas, val, ULONG_MAX) { > mas_store(&newmas, val); > } > - rcu_read_unlock(); > - mas_destroy(&newmas); > + > + mas_unlock(&mas); > mas_unlock(&newmas); > + > + mas_destroy(&newmas); > mt_validate(&newmt); > mt_set_non_kernel(0); > mtree_destroy(&newmt); > @@ -1974,12 +1975,11 @@ static noinline void __init check_mas_store_gfp(struct maple_tree *mt) > #if defined(BENCH_FORK) > static noinline void __init bench_forking(struct maple_tree *mt) > { > - > struct maple_tree newmt; > - int i, nr_entries = 134, nr_fork = 80000; > + int i, nr_entries = 300, nr_fork = 80000, ret; > void *val; > MA_STATE(mas, mt, 0, 0); > - MA_STATE(newmas, mt, 0, 0); > + MA_STATE(newmas, &newmt, 0, 0); > > for (i = 0; i <= nr_entries; i++) > mtree_store_range(mt, i*10, i*10 + 5, > @@ -1988,25 +1988,24 @@ static noinline void __init bench_forking(struct maple_tree *mt) > for (i = 0; i < nr_fork; i++) { > mt_set_non_kernel(99999); > mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); > - newmas.tree = &newmt; > - mas_reset(&newmas); > - mas_reset(&mas); > - mas.index = 0; > - mas.last = 0; > - rcu_read_lock(); > + > mas_lock(&newmas); > - if (mas_expected_entries(&newmas, nr_entries)) { > - printk("OOM!"); > + mas_lock(&mas); Should probably switch this locking to not nest as well, since you have to make the test framework cope with it already :/ > + ret = __mt_dup(mt, &newmt, GFP_NOWAIT | __GFP_NOWARN); > + if (ret) { > + pr_err("OOM!"); > BUG_ON(1); > } > - mas_for_each(&mas, val, ULONG_MAX) { > - newmas.index = mas.index; > - newmas.last = mas.last; > + > + mas_set(&newmas, 0); > + mas_for_each(&newmas, val, ULONG_MAX) { > mas_store(&newmas, val); > } > - mas_destroy(&newmas); > + > + mas_unlock(&mas); > mas_unlock(&newmas); > - rcu_read_unlock(); > + > + mas_destroy(&newmas); > mt_validate(&newmt); > mt_set_non_kernel(0); > mtree_destroy(&newmt); > -- > 2.20.1 >
在 2023/9/8 02:16, Matthew Wilcox 写道: > On Thu, Sep 07, 2023 at 02:03:01PM -0400, Liam R. Howlett wrote: >>>> WARNING: possible recursive locking detected >>>> 6.5.0-rc4-00632-g2730245bd6b1 #1 Tainted: G TN >>>> -------------------------------------------- >>>> swapper/1 is trying to acquire lock: >>>> ffffffff86485058 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:? lib/test_maple_tree.c:1854) >>>> >>>> but task is already holding lock: >>>> ffff888110847a30 (&mt->ma_lock){+.+.}-{2:2}, at: check_forking (include/linux/spinlock.h:351 lib/test_maple_tree.c:1854) >>> Thanks for the test. I checked that these are two different locks, why >>> is this warning reported? Did I miss something? >> >> I don't think you can nest spinlocks like this. In my previous test I >> avoided nesting, but in your case we cannot avoid having both locks at >> the same time. >> >> You can get around this by using an rwsemaphore, set the two trees as >> external and use down_write_nested(&lock2, SINGLE_DEPTH_NESTING) like >> the real fork. Basically, switch the locking to exactly what fork does. Here I can use rwsemaphore to avoid the warning. But what about in mtree_dup()? mtree_dup() handles locks internally. Maybe spin_lock_nested() mentioned by Matthew can be used in mtree_dup(). > > spin_lock_nested() exists. Thanks for mentioning this, I'll have a look. > > You should probably both read through > Documentation/locking/lockdep-design.rst It's not the best user > documentation in the world, but it's what we have. >
diff --git a/lib/test_maple_tree.c b/lib/test_maple_tree.c index 0ec0c6a7c0b5..72fba7cce148 100644 --- a/lib/test_maple_tree.c +++ b/lib/test_maple_tree.c @@ -1837,36 +1837,37 @@ static noinline void __init check_forking(struct maple_tree *mt) { struct maple_tree newmt; - int i, nr_entries = 134; + int i, nr_entries = 300, ret; void *val; MA_STATE(mas, mt, 0, 0); - MA_STATE(newmas, mt, 0, 0); + MA_STATE(newmas, &newmt, 0, 0); + + mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); for (i = 0; i <= nr_entries; i++) mtree_store_range(mt, i*10, i*10 + 5, xa_mk_value(i), GFP_KERNEL); + mt_set_non_kernel(99999); - mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); - newmas.tree = &newmt; - mas_reset(&newmas); - mas_reset(&mas); mas_lock(&newmas); - mas.index = 0; - mas.last = 0; - if (mas_expected_entries(&newmas, nr_entries)) { + mas_lock(&mas); + + ret = __mt_dup(mt, &newmt, GFP_NOWAIT | __GFP_NOWARN); + if (ret) { pr_err("OOM!"); BUG_ON(1); } - rcu_read_lock(); - mas_for_each(&mas, val, ULONG_MAX) { - newmas.index = mas.index; - newmas.last = mas.last; + + mas_set(&newmas, 0); + mas_for_each(&newmas, val, ULONG_MAX) { mas_store(&newmas, val); } - rcu_read_unlock(); - mas_destroy(&newmas); + + mas_unlock(&mas); mas_unlock(&newmas); + + mas_destroy(&newmas); mt_validate(&newmt); mt_set_non_kernel(0); mtree_destroy(&newmt); @@ -1974,12 +1975,11 @@ static noinline void __init check_mas_store_gfp(struct maple_tree *mt) #if defined(BENCH_FORK) static noinline void __init bench_forking(struct maple_tree *mt) { - struct maple_tree newmt; - int i, nr_entries = 134, nr_fork = 80000; + int i, nr_entries = 300, nr_fork = 80000, ret; void *val; MA_STATE(mas, mt, 0, 0); - MA_STATE(newmas, mt, 0, 0); + MA_STATE(newmas, &newmt, 0, 0); for (i = 0; i <= nr_entries; i++) mtree_store_range(mt, i*10, i*10 + 5, @@ -1988,25 +1988,24 @@ static noinline void __init bench_forking(struct maple_tree *mt) for (i = 0; i < nr_fork; i++) { mt_set_non_kernel(99999); mt_init_flags(&newmt, MT_FLAGS_ALLOC_RANGE); - newmas.tree = &newmt; - mas_reset(&newmas); - mas_reset(&mas); - mas.index = 0; - mas.last = 0; - rcu_read_lock(); + mas_lock(&newmas); - if (mas_expected_entries(&newmas, nr_entries)) { - printk("OOM!"); + mas_lock(&mas); + ret = __mt_dup(mt, &newmt, GFP_NOWAIT | __GFP_NOWARN); + if (ret) { + pr_err("OOM!"); BUG_ON(1); } - mas_for_each(&mas, val, ULONG_MAX) { - newmas.index = mas.index; - newmas.last = mas.last; + + mas_set(&newmas, 0); + mas_for_each(&newmas, val, ULONG_MAX) { mas_store(&newmas, val); } - mas_destroy(&newmas); + + mas_unlock(&mas); mas_unlock(&newmas); - rcu_read_unlock(); + + mas_destroy(&newmas); mt_validate(&newmt); mt_set_non_kernel(0); mtree_destroy(&newmt);
Updated check_forking() and bench_forking() to use __mt_dup() to duplicate maple tree. Also increased the number of VMAs, because the new way is faster. Signed-off-by: Peng Zhang <zhangpeng.00@bytedance.com> --- lib/test_maple_tree.c | 61 +++++++++++++++++++++---------------------- 1 file changed, 30 insertions(+), 31 deletions(-)