Re: [PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()

From: kernel test robot
Date: Thu Aug 31 2023 - 10:02:17 EST




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@xxxxxxxxxxxxx/
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@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202308312115.cad34fed-oliver.sang@xxxxxxxxx


[ 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@xxxxxxxxx



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