Re: [PATCH v5 6/9] slub: Delay freezing of partial slabs

[Mark Brown]

On Thu, Nov 02, 2023 at 03:23:27AM +0000, chengming.zhou@xxxxxxxxx wrote:
> From: Chengming Zhou <zhouchengming@xxxxxxxxxxxxx>
> 
> Now we will freeze slabs when moving them out of node partial list to
> cpu partial list, this method needs two cmpxchg_double operations:
> 
> 1. freeze slab (acquire_slab()) under the node list_lock
> 2. get_freelist() when pick used in ___slab_alloc()

Recently -next has been failing to boot on a Raspberry Pi 3 with an arm
multi_v7_defconfig and a NFS rootfs, a bisect appears to point to this
patch (in -next as c8d312e039030edab25836a326bcaeb2a3d4db14) as having
introduced the issue.  I've included the full bisect log below.

When we see problems we see RCU stalls while logging in, for example:

debian-testing-armhf login: root (automatic login)
Linux debian-testing-armhf 6.7.0-rc1-00006-gc8d312e03903 #1 SMP @1699864348 armv7l
The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.
Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
[   46.453323] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[   46.459361] rcu: 	3-...0: (1 GPs behind) idle=def4/1/0x40000000 softirq=1304/1304 fqs=951
[   46.467669] rcu: 	(detected by 0, t=2103 jiffies, g=1161, q=499 ncpus=4)
[   46.474472] Sending NMI from CPU 0 to CPUs 3:
[   56.478894] rcu: rcu_sched kthread timer wakeup didn't happen for 1002 jiffies! g1161 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
[   56.490195] rcu: 	Possible timer handling issue on cpu=0 timer-softirq=1650
[   56.497259] rcu: rcu_sched kthread starved for 1005 jiffies! g1161 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=0
[   56.507589] rcu: 	Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[   56.516681] rcu: RCU grace-period kthread stack dump:
[   56.521803] task:rcu_sched       state:I stack:0     pid:13    tgid:13    ppid:2      flags:0x00000000
[   56.531267]  __schedule from schedule+0x20/0xe8
[   56.535883]  schedule from schedule_timeout+0xa0/0x158
[   56.541111]  schedule_timeout from rcu_gp_fqs_loop+0x104/0x594
[   56.547048]  rcu_gp_fqs_loop from rcu_gp_kthread+0x14c/0x1c0
[   56.552801]  rcu_gp_kthread from kthread+0xe0/0xfc
[   56.557674]  kthread from ret_from_fork+0x14/0x28
[   56.562457] Exception stack(0xf084dfb0 to 0xf084dff8)
[   56.567584] dfa0:                                     00000000 00000000 00000000 00000000
[   56.575886] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[   56.584191] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[   56.590907] rcu: Stack dump where RCU GP kthread last ran:
[   56.596474] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.7.0-rc1-00006-gc8d312e03903 #1
[   56.604515] Hardware name: BCM2835
[   56.607965] PC is at default_idle_call+0x1c/0xb0
[   56.612654] LR is at ct_kernel_enter.constprop.0+0x48/0x11c
[   56.618311] pc : [<c1197054>]    lr : [<c1195c98>]    psr: 60010013
[   56.624672] sp : c1b01f70  ip : c1d5af7c  fp : 00000000
[   56.629974] r10: c19cda60  r9 : 00000000  r8 : 00000000
[   56.635277] r7 : c1b04d50  r6 : c1b04d18  r5 : c1d5b684  r4 : c1b09740
[   56.641902] r3 : 00000000  r2 : 00000000  r1 : 00000001  r0 : 002a3114
[   56.648528] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none
[   56.655774] Control: 10c5383d  Table: 0237406a  DAC: 00000051
[   56.661605]  default_idle_call from do_idle+0x208/0x290
[   56.666920]  do_idle from cpu_startup_entry+0x28/0x2c
[   56.672059]  cpu_startup_entry from rest_init+0xac/0xb0
[   56.677371]  rest_init from arch_post_acpi_subsys_init+0x0/0x8
Login ti

A full log for that run can be seen at:

   https://validation.linaro.org/scheduler/job/4017095

Boots to initramfs with the same kernel image seem fine.  Other systems,
including other 32 bit arm ones, don't seem to be having similar issues
with this userspace.  I've not investigated beyond running the bisect,
the log for which is below:

git bisect start
# good: [64e6d94bfb47ed0732ad06aedf8ec6af5dd2ab84] Merge branch 'for-linux-next-fixes' of git://anongit.freedesktop.org/drm/drm-misc
git bisect good 64e6d94bfb47ed0732ad06aedf8ec6af5dd2ab84
# bad: [5a82d69d48c82e89aef44483d2a129f869f3506a] Add linux-next specific files for 20231120
git bisect bad 5a82d69d48c82e89aef44483d2a129f869f3506a
# good: [ce252a92a867da8a6622463bff637e5f7b904a46] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/wireless/wireless-next.git
git bisect good ce252a92a867da8a6622463bff637e5f7b904a46
# good: [c22e026efad504e3b056d4436920d173a09c580e] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/regulator.git
git bisect good c22e026efad504e3b056d4436920d173a09c580e
# good: [b7fc58ffb105470cb339163cc2b04e3f59387a45] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/fpga/linux-fpga.git
git bisect good b7fc58ffb105470cb339163cc2b04e3f59387a45
# good: [26f89f0614f03e4016578a992fc2e86b048a5cb4] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/linusw/linux-pinctrl.git
git bisect good 26f89f0614f03e4016578a992fc2e86b048a5cb4
# good: [602bf18307981f3bfd9ebf19921791a4256d3fd1] Merge branch 'for-6.7' into for-next
git bisect good 602bf18307981f3bfd9ebf19921791a4256d3fd1
# good: [9f16a68069822b1df6bfb8a9ef7258a1e32b25e7] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/livepatching/livepatching
git bisect good 9f16a68069822b1df6bfb8a9ef7258a1e32b25e7
# good: [3ff57db6f6569ebc2cc333437e7e949749e59424] Merge branch 'for-next' of git://git.kernel.org/pub/scm/linux/kernel/git/krisman/unicode.git
git bisect good 3ff57db6f6569ebc2cc333437e7e949749e59424
# bad: [dd374e220ba492f95344a638b1efe5b2744fdd73] slub: Update frozen slabs documentations in the source
git bisect bad dd374e220ba492f95344a638b1efe5b2744fdd73
# good: [a3058965bb35490454953aa2c87ea51004839f2f] slub: Prepare __slab_free() for unfrozen partial slab out of node partial list
git bisect good a3058965bb35490454953aa2c87ea51004839f2f
# bad: [c8d312e039030edab25836a326bcaeb2a3d4db14] slub: Delay freezing of partial slabs
git bisect bad c8d312e039030edab25836a326bcaeb2a3d4db14
# good: [00b15a19ee543f0117cb217fcbab8b7b3fd50677] slub: Introduce freeze_slab()
git bisect good 00b15a19ee543f0117cb217fcbab8b7b3fd50677
# first bad commit: [c8d312e039030edab25836a326bcaeb2a3d4db14] slub: Delay freezing of partial slabs

Attachment: signature.asc
Description: PGP signature