Re: [PATCH v2 5/6] maple_tree: Update check_forking() and bench_forking()
From: Liam R. Howlett
Date: Thu Sep 07 2023 - 14:04:55 EST
* Peng Zhang <zhangpeng.00@xxxxxxxxxxxxx> [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@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)
> 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@xxxxxxxxx
> >
> >
> >
>