Re: 6.11/regression/bisected - The commit c1385c1f0ba3 caused a new possible recursive locking detected warning at computer boot.

From: Jonathan Cameron
Date: Thu Jul 25 2024 - 13:14:11 EST

On Tue, 23 Jul 2024 18:20:06 +0100
Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx> wrote:

> On Tue, 23 Jul 2024 11:24:56 +0100
> Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx> wrote:
>
> > On Tue, 23 Jul 2024 00:36:18 +0500
> > Mikhail Gavrilov <mikhail.v.gavrilov@xxxxxxxxx> wrote:
> >
> > > Hi,
> > > The first Fedora update to the 6.11 kernel
> > > (kernel-debug-6.11.0-0.rc0.20240716gitd67978318827.2.fc41.x86_64)
> > > brings a new warning: possible recursive locking detected.
> >
> > Hi Mikhail,
> >
> > Thanks for the report.
> >
> > This is an interesting corner and perhaps reflects a flawed
> > assumption we were making that for this path anything that can happen for an
> > initially present CPU can also happen for a hotplugged one. On the hotplugged
> > path the lock was always held and hence the static_key_enable() would
> > have failed.
> >
> > I'm somewhat stumped on working out why this path couldn't happen
> > for a hotplugged CPU so why this is a new problem?
> >
> > Maybe this is just a case of no one is providing _CPC for CPUs in virtual
> > machines so the path wasn't seen? QEMU doesn't generate ACPI tables with
> > _CPC today, so maybe that's it.
> >
> > So maybe this is has revealed an existing latent bug. There have been
> > QEMU patches for _CPC in the past but never merged. I'll hack them
> > into an x86 virtual machine and see if we hit the same bug you have
> > here before and after the series.
> >
> > Either way obviously we need to fix it for the current kernel (and maybe
> > backport the fix if I can verify it's a latent bug). I'll get a test
> > setup running asap and see if I can replicate.
> >
> > +CC x86 maintainers.
>
> It will take me a little longer to emulate a suitable setup to hit the
> AMD case on (I have it run on arm64 now, but no similar issue occurs)
>
> Ultimately the problem is occurring in arch_init_invariance_cppc
> I note that the arm64 version of that topology_init_cpu_capacity_cppc
> delays some activity via a work queue specifically to avoid some
> locking issues.
>
> On AMD systems arch_init_invariance_cppc is defined
> as init_freq_invariance_cppc which calls amd_set_max_freq_ratio just
> once (there is a static bool) which in turn calls
> freq_invariance_set_perf_ratio() / freq_invariance_enable()
>
> Until I have a setup to test on I'm not going to draw firm conclusions
> but how much would it matter if we set that static key a bit late
> via a workqueue? In the meantime go with a default value similar to
> that disable_freq_invariance_work sets (which is done via a workqueue).
>
> The intel equivalent is called via an early_init() so not
> the hotplug path.
>
> Any hints on from people familiar with this code would be most
> welcome. Whilst git suggests tglx touched these paths most recently that
> was in tidying them up to split the Intel and AMD paths.
>

Hi Mikhail.

So the short story, ignoring the journey (which should only be described
with beer in hand), is that I now have an emulated test setup in QEMU
that fakes enough of the previously missing bits to bring up this path
and can trigger the splat you shared. With the below fix I can get to
something approaching a running system.

However, without more work the emulation isn't actually doing any control
of frequency etc so I have no idea if the code actually works after this
patch.

If you are in a position to test a patch, could you try the following?

One bit I need to check out tomorrow is to make sure this doesn't race with the
workfn that is used to tear down the same static key on error.

From 8f7ad4c73954aae74265a3ec50a1d56e0c56050d Mon Sep 17 00:00:00 2001
From: Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx>
Date: Thu, 25 Jul 2024 17:56:00 +0100
Subject: [RFC PATCH] x86/aperfmperf: Push static_branch_enable(&arch_scale_freq_key) onto work queue

This to avoid a deadlock reported by lockdep.

TODO: Fix up this commit message before posting to actually give
some details and tags etc.

Reported-by: Mikhail Gavrilov <mikhail.v.gavrilov@xxxxxxxxx>
Signed-off-by: Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx>
---
arch/x86/kernel/cpu/aperfmperf.c | 13 ++++++++++---
1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/arch/x86/kernel/cpu/aperfmperf.c b/arch/x86/kernel/cpu/aperfmperf.c
index b3fa61d45352..41c729d3517c 100644
--- a/arch/x86/kernel/cpu/aperfmperf.c
+++ b/arch/x86/kernel/cpu/aperfmperf.c
@@ -300,15 +300,22 @@ static void register_freq_invariance_syscore_ops(void)
static inline void register_freq_invariance_syscore_ops(void) {}
#endif

+static void enable_freq_invariance_workfn(struct work_struct *work)
+{
+ static_branch_enable(&arch_scale_freq_key);
+ register_freq_invariance_syscore_ops();
+ pr_info("Estimated ratio of average max frequency by base frequency (times 1024): %llu\n", arch_max_freq_ratio);
+}
+static DECLARE_WORK(enable_freq_invariance_work,
+ enable_freq_invariance_workfn);
+
static void freq_invariance_enable(void)
{
if (static_branch_unlikely(&arch_scale_freq_key)) {
WARN_ON_ONCE(1);
return;
}
- static_branch_enable(&arch_scale_freq_key);
- register_freq_invariance_syscore_ops();
- pr_info("Estimated ratio of average max frequency by base frequency (times 1024): %llu\n", arch_max_freq_ratio);
+ schedule_work(&enable_freq_invariance_work);
}

void freq_invariance_set_perf_ratio(u64 ratio, bool turbo_disabled)
--
2.43.0


> Jonathan
>
>
>
> >
> > Thanks,
> >
> > Jonathan
> >
> >
> >
> >
> > > The trace looks like:
> > > ACPI: button: Power Button [PWRF]
> > >
> > > ============================================
> > > WARNING: possible recursive locking detected
> > > 6.11.0-0.rc0.20240716gitd67978318827.2.fc41.x86_64+debug #1 Not tainted
> > > --------------------------------------------
> > > cpuhp/0/22 is trying to acquire lock:
> > > ffffffffb7f9cb40 (cpu_hotplug_lock){++++}-{0:0}, at: static_key_enable+0x12/0x20
> > >
> > > but task is already holding lock:
> > > ffffffffb7f9cb40 (cpu_hotplug_lock){++++}-{0:0}, at: cpuhp_thread_fun+0xcd/0x6f0
> > >
> > > other info that might help us debug this:
> > > Possible unsafe locking scenario:
> > >
> > > CPU0
> > > ----
> > > lock(cpu_hotplug_lock);
> > > lock(cpu_hotplug_lock);
> > >
> > > *** DEADLOCK ***
> > >
> > > May be due to missing lock nesting notation
> > >
> > > 3 locks held by cpuhp/0/22:
> > > #0: ffffffffb7f9cb40 (cpu_hotplug_lock){++++}-{0:0}, at:
> > > cpuhp_thread_fun+0xcd/0x6f0
> > > #1: ffffffffb7f9f2e0 (cpuhp_state-up){+.+.}-{0:0}, at:
> > > cpuhp_thread_fun+0xcd/0x6f0
> > > #2: ffffffffb7f1d650 (freq_invariance_lock){+.+.}-{3:3}, at:
> > > init_freq_invariance_cppc+0xf4/0x1e0
> > >
> > > stack backtrace:
> > > CPU: 0 PID: 22 Comm: cpuhp/0 Not tainted
> > > 6.11.0-0.rc0.20240716gitd67978318827.2.fc41.x86_64+debug #1
> > > Hardware name: ASUS System Product Name/ROG STRIX B650E-I GAMING WIFI,
> > > BIOS 2611 04/07/2024
> > > Call Trace:
> > > <TASK>
> > > dump_stack_lvl+0x84/0xd0
> > > __lock_acquire+0x27e3/0x5c70
> > > ? __pfx___lock_acquire+0x10/0x10
> > > ? cppc_get_perf_caps+0x64f/0xf60
> > > lock_acquire+0x1ae/0x540
> > > ? static_key_enable+0x12/0x20
> > > ? __pfx_lock_acquire+0x10/0x10
> > > ? __pfx___might_resched+0x10/0x10
> > > cpus_read_lock+0x40/0xe0
> > > ? static_key_enable+0x12/0x20
> > > static_key_enable+0x12/0x20
> > > freq_invariance_enable+0x13/0x40
> > > init_freq_invariance_cppc+0x17e/0x1e0
> > > ? __pfx_init_freq_invariance_cppc+0x10/0x10
> > > ? acpi_cppc_processor_probe+0x1046/0x2300
> > > acpi_cppc_processor_probe+0x11ae/0x2300
> > > ? _raw_spin_unlock_irqrestore+0x4f/0x80
> > > ? __pfx_acpi_cppc_processor_probe+0x10/0x10
> > > ? __pfx_acpi_scan_drop_device+0x10/0x10
> > > ? acpi_fetch_acpi_dev+0x79/0xe0
> > > ? __pfx_acpi_fetch_acpi_dev+0x10/0x10
> > > ? __pfx_acpi_soft_cpu_online+0x10/0x10
> > > acpi_soft_cpu_online+0x114/0x330
> > > cpuhp_invoke_callback+0x2c7/0xa40
> > > ? __pfx_lock_release+0x10/0x10
> > > ? __pfx_lock_release+0x10/0x10
> > > ? cpuhp_thread_fun+0xcd/0x6f0
> > > cpuhp_thread_fun+0x33a/0x6f0
> > > ? smpboot_thread_fn+0x56/0x930
> > > smpboot_thread_fn+0x54b/0x930
> > > ? __pfx_smpboot_thread_fn+0x10/0x10
> > > ? __pfx_smpboot_thread_fn+0x10/0x10
> > > kthread+0x2d2/0x3a0
> > > ? _raw_spin_unlock_irq+0x28/0x60
> > > ? __pfx_kthread+0x10/0x10
> > > ret_from_fork+0x31/0x70
> > > ? __pfx_kthread+0x10/0x10
> > > ret_from_fork_asm+0x1a/0x30
> > > </TASK>
> > >
> > > Bisect is pointed to commit
> > > commit c1385c1f0ba3b80bd12f26c440612175088c664c (HEAD)
> > > Author: Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx>
> > > Date: Wed May 29 14:34:28 2024 +0100
> > >
> > > ACPI: processor: Simplify initial onlining to use same path for
> > > cold and hotplug
> > >
> > > Separate code paths, combined with a flag set in acpi_processor.c to
> > > indicate a struct acpi_processor was for a hotplugged CPU ensured that
> > > per CPU data was only set up the first time that a CPU was initialized.
> > > This appears to be unnecessary as the paths can be combined by letting
> > > the online logic also handle any CPUs online at the time of driver load.
> > >
> > > Motivation for this change, beyond simplification, is that ARM64
> > > virtual CPU HP uses the same code paths for hotplug and cold path in
> > > acpi_processor.c so had no easy way to set the flag for hotplug only.
> > > Removing this necessity will enable ARM64 vCPU HP to reuse the existing
> > > code paths.
> > >
> > > Acked-by: Rafael J. Wysocki <rafael.j.wysocki@xxxxxxxxx>
> > > Reviewed-by: Hanjun Guo <guohanjun@xxxxxxxxxx>
> > > Tested-by: Miguel Luis <miguel.luis@xxxxxxxxxx>
> > > Reviewed-by: Gavin Shan <gshan@xxxxxxxxxx>
> > > Reviewed-by: Miguel Luis <miguel.luis@xxxxxxxxxx>
> > > Signed-off-by: Jonathan Cameron <Jonathan.Cameron@xxxxxxxxxx>
> > > Link: https://lore.kernel.org/r/20240529133446.28446-2-Jonathan.Cameron@xxxxxxxxxx
> > > Signed-off-by: Catalin Marinas <catalin.marinas@xxxxxxx>
> > >
> > > drivers/acpi/acpi_processor.c | 7 +++----
> > > drivers/acpi/processor_driver.c | 43
> > > ++++++++++++-------------------------------
> > > include/acpi/processor.h | 2 +-
> > > 3 files changed, 16 insertions(+), 36 deletions(-)
> > >
> > > And I can confirm that after reverting c1385c1f0ba3 the issue is gone.
> > >
> > > I also attach here a full kernel log and build config.
> > >
> > > My hardware specs: https://linux-hardware.org/?probe=c6de14f5b8
> > >
> > > Jonathan, can you look into this, please?
> > >
> >
>