lkml.org 
[lkml]   [2014]   [Oct]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Date
From
SubjectRe: lockdep splat in CPU hotplug
On Tue, 21 Oct 2014, Jiri Kosina wrote:

> Hi,
>
> I am seeing the lockdep report below when resuming from suspend-to-disk
> with current Linus' tree (c2661b80609).
>
> The reason for CCing Ingo and Peter is that I can't make any sense of one
> of the stacktraces lockdep is providing.
>
> Please have a look at the very first stacktrace in the dump, where lockdep
> is trying to explain where cpu_hotplug.lock#2 has been acquired. It seems
> to imply that cpuidle_pause() is taking cpu_hotplug.lock, but that's not
> the case at all.
>
> What am I missing?

Okay, reverting 442bf3aaf55a ("sched: Let the scheduler see CPU idle
states") and followup 83a0a96a5f26 ("sched/fair: Leverage the idle state
info when choosing the "idlest" cpu") which depends on it makes the splat
go away.

Just for the sake of testing the hypothesis, I did just the minimal change
below on top of current Linus' tree, and it also makes the splat go away
(of course it's totally incorrect thing to do by itself alone):

diff --git a/drivers/cpuidle/cpuidle.c b/drivers/cpuidle/cpuidle.c
index 125150d..d31e04c 100644
--- a/drivers/cpuidle/cpuidle.c
+++ b/drivers/cpuidle/cpuidle.c
@@ -225,12 +225,6 @@ void cpuidle_uninstall_idle_handler(void)
initialized = 0;
wake_up_all_idle_cpus();
}
-
- /*
- * Make sure external observers (such as the scheduler)
- * are done looking at pointed idle states.
- */
- synchronize_rcu();
}

/**
So indeed 442bf3aaf55a is guilty.

Paul was stating yesterday that it can't be the try_get_online_cpus() in
synchronize_sched_expedited(), as it's doing only trylock. There are
however more places where synchronize_sched_expedited() is acquiring
cpu_hotplug.lock unconditionally by calling put_online_cpus(), so the race
seems real.

Adding people involved in 442bf3aaf55a to CC.

Still, the lockdep stacktrace is bogus and didn't really help
understanding this. Any idea why it's wrong?

> ======================================================
> [ INFO: possible circular locking dependency detected ]
> 3.18.0-rc1-00069-gc2661b8 #1 Not tainted
> -------------------------------------------------------
> do_s2disk/2367 is trying to acquire lock:
> (cpuidle_lock){+.+.+.}, at: [<ffffffff814916c2>] cpuidle_pause_and_lock+0x12/0x20
>
> but task is already holding lock:
> (cpu_hotplug.lock#2){+.+.+.}, at: [<ffffffff810522ea>] cpu_hotplug_begin+0x4a/0x80
>
> which lock already depends on the new lock.
>
> the existing dependency chain (in reverse order) is:
>
> -> #1 (cpu_hotplug.lock#2){+.+.+.}:
> [<ffffffff81099fac>] lock_acquire+0xac/0x130
> [<ffffffff815b9f2c>] mutex_lock_nested+0x5c/0x3b0
> [<ffffffff81491892>] cpuidle_pause+0x12/0x30
> [<ffffffff81402314>] dpm_suspend_noirq+0x44/0x340
> [<ffffffff81402958>] dpm_suspend_end+0x38/0x80
> [<ffffffff810a07bd>] hibernation_snapshot+0xcd/0x370
> [<ffffffff810a1248>] hibernate+0x168/0x210
> [<ffffffff8109e9b4>] state_store+0xe4/0xf0
> [<ffffffff813003ef>] kobj_attr_store+0xf/0x20
> [<ffffffff8121e9a3>] sysfs_kf_write+0x43/0x60
> [<ffffffff8121e287>] kernfs_fop_write+0xe7/0x170
> [<ffffffff811a7342>] vfs_write+0xb2/0x1f0
> [<ffffffff811a7da4>] SyS_write+0x44/0xb0
> [<ffffffff815be856>] system_call_fastpath+0x16/0x1b
>
> -> #0 (cpuidle_lock){+.+.+.}:
> [<ffffffff81099433>] __lock_acquire+0x1a03/0x1e30
> [<ffffffff81099fac>] lock_acquire+0xac/0x130
> [<ffffffff815b9f2c>] mutex_lock_nested+0x5c/0x3b0
> [<ffffffff814916c2>] cpuidle_pause_and_lock+0x12/0x20
> [<ffffffffc02e184c>] acpi_processor_hotplug+0x45/0x8a [processor]
> [<ffffffffc02df25a>] acpi_cpu_soft_notify+0xad/0xe3 [processor]
> [<ffffffff81071393>] notifier_call_chain+0x53/0xa0
> [<ffffffff810713e9>] __raw_notifier_call_chain+0x9/0x10
> [<ffffffff810521ce>] cpu_notify+0x1e/0x40
> [<ffffffff810524a8>] _cpu_up+0x148/0x160
> [<ffffffff815a7b99>] enable_nonboot_cpus+0xc9/0x1d0
> [<ffffffff810a0955>] hibernation_snapshot+0x265/0x370
> [<ffffffff810a1248>] hibernate+0x168/0x210
> [<ffffffff8109e9b4>] state_store+0xe4/0xf0
> [<ffffffff813003ef>] kobj_attr_store+0xf/0x20
> [<ffffffff8121e9a3>] sysfs_kf_write+0x43/0x60
> [<ffffffff8121e287>] kernfs_fop_write+0xe7/0x170
> [<ffffffff811a7342>] vfs_write+0xb2/0x1f0
> [<ffffffff811a7da4>] SyS_write+0x44/0xb0
> [<ffffffff815be856>] system_call_fastpath+0x16/0x1b
>
> other info that might help us debug this:
>
> Possible unsafe locking scenario:
>
> CPU0 CPU1
> ---- ----
> lock(cpu_hotplug.lock#2);
> lock(cpuidle_lock);
> lock(cpu_hotplug.lock#2);
> lock(cpuidle_lock);
>
> *** DEADLOCK ***
>
> 8 locks held by do_s2disk/2367:
> #0: (sb_writers#6){.+.+.+}, at: [<ffffffff811a7443>] vfs_write+0x1b3/0x1f0
> #1: (&of->mutex){+.+.+.}, at: [<ffffffff8121e25b>] kernfs_fop_write+0xbb/0x170
> #2: (s_active#188){.+.+.+}, at: [<ffffffff8121e263>] kernfs_fop_write+0xc3/0x170
> #3: (pm_mutex){+.+.+.}, at: [<ffffffff810a112e>] hibernate+0x4e/0x210
> #4: (device_hotplug_lock){+.+.+.}, at: [<ffffffff813f1b52>] lock_device_hotplug+0x12/0x20
> #5: (cpu_add_remove_lock){+.+.+.}, at: [<ffffffff815a7aef>] enable_nonboot_cpus+0x1f/0x1d0
> #6: (cpu_hotplug.lock){++++++}, at: [<ffffffff810522a0>] cpu_hotplug_begin+0x0/0x80
> #7: (cpu_hotplug.lock#2){+.+.+.}, at: [<ffffffff810522ea>] cpu_hotplug_begin+0x4a/0x80
>
> stack backtrace:
> CPU: 1 PID: 2367 Comm: do_s2disk Not tainted 3.18.0-rc1-00069-g4da0564 #1
> Hardware name: LENOVO 7470BN2/7470BN2, BIOS 6DET38WW (2.02 ) 12/19/2008
> ffffffff823e4330 ffff8800789e7a48 ffffffff815b6754 0000000000001a69
> ffffffff823e4330 ffff8800789e7a98 ffffffff815b078b ffff8800741a5510
> ffff8800789e7af8 ffff8800741a5ea8 5a024e919538010b ffff8800741a5ea8
> Call Trace:
> [<ffffffff815b6754>] dump_stack+0x4e/0x68
> [<ffffffff815b078b>] print_circular_bug+0x203/0x214
> [<ffffffff81099433>] __lock_acquire+0x1a03/0x1e30
> [<ffffffff8109766d>] ? trace_hardirqs_on_caller+0xfd/0x1c0
> [<ffffffff81099fac>] lock_acquire+0xac/0x130
> [<ffffffff814916c2>] ? cpuidle_pause_and_lock+0x12/0x20
> [<ffffffff815b9f2c>] mutex_lock_nested+0x5c/0x3b0
> [<ffffffff814916c2>] ? cpuidle_pause_and_lock+0x12/0x20
> [<ffffffff814916c2>] cpuidle_pause_and_lock+0x12/0x20
> [<ffffffffc02e184c>] acpi_processor_hotplug+0x45/0x8a [processor]
> [<ffffffffc02df25a>] acpi_cpu_soft_notify+0xad/0xe3 [processor]
> [<ffffffff81071393>] notifier_call_chain+0x53/0xa0
> [<ffffffff810713e9>] __raw_notifier_call_chain+0x9/0x10
> [<ffffffff810521ce>] cpu_notify+0x1e/0x40
> [<ffffffff810524a8>] _cpu_up+0x148/0x160
> [<ffffffff815a7b99>] enable_nonboot_cpus+0xc9/0x1d0
> [<ffffffff810a0955>] hibernation_snapshot+0x265/0x370
> [<ffffffff810a1248>] hibernate+0x168/0x210
> [<ffffffff8109e9b4>] state_store+0xe4/0xf0
> [<ffffffff813003ef>] kobj_attr_store+0xf/0x20
> [<ffffffff8121e9a3>] sysfs_kf_write+0x43/0x60
> [<ffffffff8121e287>] kernfs_fop_write+0xe7/0x170
> [<ffffffff811a7342>] vfs_write+0xb2/0x1f0
> [<ffffffff815be87b>] ? sysret_check+0x1b/0x56
> [<ffffffff811a7da4>] SyS_write+0x44/0xb0
> [<ffffffff815be856>] system_call_fastpath+0x16/0x1b

--
Jiri Kosina
SUSE Labs


\
 
 \ /
  Last update: 2014-10-22 12:21    [W:0.117 / U:0.136 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site