[BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Artem Savkov]

I get the following BUG on suspend using systemd-sleep(this doesn't
happen with pm-suspend). This seems to be introduced by some of the
Viresh's patches.

[   94.908046] Disabling non-boot CPUs ...
[   94.908416] BUG: sleeping function called from invalid context at kernel/workqueue.c:2811
[   94.908419] in_atomic(): 1, irqs_disabled(): 1, pid: 4038, name: systemd-sleep
[   94.908421] 7 locks held by systemd-sleep/4038:
[   94.908439]  #0:  (&buffer->mutex){......}, at: [<c11908e9>] sysfs_write_file+0x29/0x100
[   94.908448]  #1:  (s_active#179){......}, at: [<c119094d>] sysfs_write_file+0x8d/0x100
[   94.908459]  #2:  (pm_mutex){......}, at: [<c107f990>] pm_suspend+0x40/0x1e0
[   94.908469]  #3:  (cpu_add_remove_lock){......}, at: [<c103ab04>] cpu_maps_update_begin+0x14/0x20
[   94.908476]  #4:  (cpu_hotplug.lock){......}, at: [<c103a9e2>] cpu_hotplug_begin+0x22/0x50
[   94.908487]  #5:  (&per_cpu(cpu_policy_rwsem, cpu)){......}, at: [<c14bfbfd>] lock_policy_rwsem_write+0x3d/0x70
[   94.908495]  #6:  (cpufreq_driver_lock){......}, at: [<c14bfe06>] __cpufreq_remove_dev.isra.10+0x26/0x270
[   94.908500] Pid: 4038, comm: systemd-sleep Not tainted 3.8.0-rc6-next-20130205+ #200
[   94.908501] Call Trace:
[   94.908511]  [<c1067ce0>] __might_sleep+0xe0/0x100
[   94.908518]  [<c1050f3f>] flush_work+0x5f/0x230
[   94.908523]  [<c1050ee0>] ? insert_work+0x50/0x50
[   94.908528]  [<c1046277>] ? del_timer+0x47/0x70
[   94.908533]  [<c1046277>] ? del_timer+0x47/0x70
[   94.908538]  [<c1052b08>] ? try_to_grab_pending+0xa8/0x120
[   94.908543]  [<c1053b49>] __cancel_work_timer+0x59/0x80
[   94.908548]  [<c1053b82>] cancel_delayed_work_sync+0x12/0x20
[   94.908555]  [<c14c32ed>] cpufreq_governor_dbs+0x2cd/0x490
[   94.908561]  [<c14c26c6>] od_cpufreq_governor_dbs+0x16/0x20
[   94.908565]  [<c14bfd21>] __cpufreq_governor+0x41/0x100
[   94.908570]  [<c14bfe06>] ? __cpufreq_remove_dev.isra.10+0x26/0x270
[   94.908575]  [<c14bfe36>] __cpufreq_remove_dev.isra.10+0x56/0x270
[   94.908580]  [<c14bfbfd>] ? lock_policy_rwsem_write+0x3d/0x70
[   94.908589]  [<c1686c20>] cpufreq_cpu_callback+0x50/0x65
[   94.908596]  [<c16966c7>] notifier_call_chain+0x47/0x90
[   94.908606]  [<c1060fee>] __raw_notifier_call_chain+0x1e/0x30
[   94.908610]  [<c103a974>] __cpu_notify+0x24/0x50
[   94.908615]  [<c167bf7d>] _cpu_down+0x6d/0x250
[   94.908621]  [<c103ac7c>] disable_nonboot_cpus+0x6c/0xf0
[   94.908625]  [<c107f815>] suspend_devices_and_enter+0x175/0x2b0
[   94.908629]  [<c107fb27>] pm_suspend+0x1d7/0x1e0
[   94.908633]  [<c107ebed>] state_store+0x5d/0xb0
[   94.908638]  [<c107eb90>] ? pm_trace_dev_match_show+0x20/0x20
[   94.908644]  [<c12c074b>] kobj_attr_store+0x1b/0x30
[   94.908650]  [<c1190963>] sysfs_write_file+0xa3/0x100
[   94.908655]  [<c11908c0>] ? sysfs_open_file+0x1f0/0x1f0
[   94.908662]  [<c112dc28>] vfs_write+0x88/0x140
[   94.908667]  [<c11908c0>] ? sysfs_open_file+0x1f0/0x1f0
[   94.908672]  [<c112def7>] sys_write+0x47/0x90
[   94.908679]  [<c169a0fa>] sysenter_do_call+0x12/0x2d
[   94.911067] smpboot: CPU 1 is now offline
[   94.915585] smpboot: CPU 2 is now offline
[   94.917500] smpboot: CPU 3 is now offline


-- 
Kind regards,
Artem

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Rafael J. Wysocki]

On Thursday, February 07, 2013 12:25:13 AM Artem Savkov wrote:
> I get the following BUG on suspend using systemd-sleep(this doesn't
> happen with pm-suspend). This seems to be introduced by some of the
> Viresh's patches.

Which branch from which day?

Rafael


> [   94.908046] Disabling non-boot CPUs ...
> [   94.908416] BUG: sleeping function called from invalid context at kernel/workqueue.c:2811
> [   94.908419] in_atomic(): 1, irqs_disabled(): 1, pid: 4038, name: systemd-sleep
> [   94.908421] 7 locks held by systemd-sleep/4038:
> [   94.908439]  #0:  (&buffer->mutex){......}, at: [<c11908e9>] sysfs_write_file+0x29/0x100
> [   94.908448]  #1:  (s_active#179){......}, at: [<c119094d>] sysfs_write_file+0x8d/0x100
> [   94.908459]  #2:  (pm_mutex){......}, at: [<c107f990>] pm_suspend+0x40/0x1e0
> [   94.908469]  #3:  (cpu_add_remove_lock){......}, at: [<c103ab04>] cpu_maps_update_begin+0x14/0x20
> [   94.908476]  #4:  (cpu_hotplug.lock){......}, at: [<c103a9e2>] cpu_hotplug_begin+0x22/0x50
> [   94.908487]  #5:  (&per_cpu(cpu_policy_rwsem, cpu)){......}, at: [<c14bfbfd>] lock_policy_rwsem_write+0x3d/0x70
> [   94.908495]  #6:  (cpufreq_driver_lock){......}, at: [<c14bfe06>] __cpufreq_remove_dev.isra.10+0x26/0x270
> [   94.908500] Pid: 4038, comm: systemd-sleep Not tainted 3.8.0-rc6-next-20130205+ #200
> [   94.908501] Call Trace:
> [   94.908511]  [<c1067ce0>] __might_sleep+0xe0/0x100
> [   94.908518]  [<c1050f3f>] flush_work+0x5f/0x230
> [   94.908523]  [<c1050ee0>] ? insert_work+0x50/0x50
> [   94.908528]  [<c1046277>] ? del_timer+0x47/0x70
> [   94.908533]  [<c1046277>] ? del_timer+0x47/0x70
> [   94.908538]  [<c1052b08>] ? try_to_grab_pending+0xa8/0x120
> [   94.908543]  [<c1053b49>] __cancel_work_timer+0x59/0x80
> [   94.908548]  [<c1053b82>] cancel_delayed_work_sync+0x12/0x20
> [   94.908555]  [<c14c32ed>] cpufreq_governor_dbs+0x2cd/0x490
> [   94.908561]  [<c14c26c6>] od_cpufreq_governor_dbs+0x16/0x20
> [   94.908565]  [<c14bfd21>] __cpufreq_governor+0x41/0x100
> [   94.908570]  [<c14bfe06>] ? __cpufreq_remove_dev.isra.10+0x26/0x270
> [   94.908575]  [<c14bfe36>] __cpufreq_remove_dev.isra.10+0x56/0x270
> [   94.908580]  [<c14bfbfd>] ? lock_policy_rwsem_write+0x3d/0x70
> [   94.908589]  [<c1686c20>] cpufreq_cpu_callback+0x50/0x65
> [   94.908596]  [<c16966c7>] notifier_call_chain+0x47/0x90
> [   94.908606]  [<c1060fee>] __raw_notifier_call_chain+0x1e/0x30
> [   94.908610]  [<c103a974>] __cpu_notify+0x24/0x50
> [   94.908615]  [<c167bf7d>] _cpu_down+0x6d/0x250
> [   94.908621]  [<c103ac7c>] disable_nonboot_cpus+0x6c/0xf0
> [   94.908625]  [<c107f815>] suspend_devices_and_enter+0x175/0x2b0
> [   94.908629]  [<c107fb27>] pm_suspend+0x1d7/0x1e0
> [   94.908633]  [<c107ebed>] state_store+0x5d/0xb0
> [   94.908638]  [<c107eb90>] ? pm_trace_dev_match_show+0x20/0x20
> [   94.908644]  [<c12c074b>] kobj_attr_store+0x1b/0x30
> [   94.908650]  [<c1190963>] sysfs_write_file+0xa3/0x100
> [   94.908655]  [<c11908c0>] ? sysfs_open_file+0x1f0/0x1f0
> [   94.908662]  [<c112dc28>] vfs_write+0x88/0x140
> [   94.908667]  [<c11908c0>] ? sysfs_open_file+0x1f0/0x1f0
> [   94.908672]  [<c112def7>] sys_write+0x47/0x90
> [   94.908679]  [<c169a0fa>] sysenter_do_call+0x12/0x2d
> [   94.911067] smpboot: CPU 1 is now offline
> [   94.915585] smpboot: CPU 2 is now offline
> [   94.917500] smpboot: CPU 3 is now offline
> 
> 
> 
-- 
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Rafael J. Wysocki]

On Wednesday, February 06, 2013 10:11:25 PM Rafael J. Wysocki wrote:
> On Thursday, February 07, 2013 12:25:13 AM Artem Savkov wrote:
> > I get the following BUG on suspend using systemd-sleep(this doesn't
> > happen with pm-suspend). This seems to be introduced by some of the
> > Viresh's patches.
> 
> Which branch from which day?

OK, I've reproduced it and the appended patch fixes it for me.  Can you please
try it and report back?

Rafael


---
From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Subject: cpufreq: Move sysfs_remove_link() from under a spinlock

Commit 73bf0fc "cpufreq: Don't remove sysfs link for policy->cpu"
attempted to fix a bug in __cpufreq_remove_dev() by avoiding to
remove the link to the "cpufreq" directory for policy->cpu, but it
rearranged the code in such a way that sysfs_remove_link() ended up
under a spinlock, which caused complaints about sleeping in atomic
context to be emitted into the kernel log during system suspend.

To fix this, revert commit 73bf0fc partially and move the
sysfs_remove_link() in question to a separate block executed for
cpus > 1 outside of the spinlock.

Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
---
 drivers/cpufreq/cpufreq.c |   18 +++++++++---------
 1 file changed, 9 insertions(+), 9 deletions(-)

Index: test/drivers/cpufreq/cpufreq.c
===================================================================
--- test.orig/drivers/cpufreq/cpufreq.c
+++ test/drivers/cpufreq/cpufreq.c
@@ -1058,9 +1058,7 @@ static int __cpufreq_remove_dev(struct d
 	cpus = cpumask_weight(data->cpus);
 	cpumask_clear_cpu(cpu, data->cpus);
 
-	if (cpu != data->cpu) {
-		sysfs_remove_link(&dev->kobj, "cpufreq");
-	} else if (cpus > 1) {
+	if (unlikely(cpu == data->cpu && cpus > 1)) {
 		/* first sibling now owns the new sysfs dir */
 		cpu_dev = get_cpu_device(cpumask_first(data->cpus));
 		sysfs_remove_link(&cpu_dev->kobj, "cpufreq");
@@ -1085,9 +1083,14 @@ static int __cpufreq_remove_dev(struct d
 	pr_debug("%s: removing link, cpu: %d\n", __func__, cpu);
 	cpufreq_cpu_put(data);
 	unlock_policy_rwsem_write(cpu);
-
-	/* If cpu is last user of policy, free policy */
-	if (cpus == 1) {
+	if (cpus > 1) {
+		sysfs_remove_link(&dev->kobj, "cpufreq");
+		if (cpufreq_driver->target) {
+			__cpufreq_governor(data, CPUFREQ_GOV_START);
+			__cpufreq_governor(data, CPUFREQ_GOV_LIMITS);
+		}
+	} else {
+		/* If cpu is the last user of policy, free policy */
 		lock_policy_rwsem_write(cpu);
 		kobj = &data->kobj;
 		cmp = &data->kobj_unregister;
@@ -1110,9 +1113,6 @@ static int __cpufreq_remove_dev(struct d
 		free_cpumask_var(data->related_cpus);
 		free_cpumask_var(data->cpus);
 		kfree(data);
-	} else if (cpufreq_driver->target) {
-		__cpufreq_governor(data, CPUFREQ_GOV_START);
-		__cpufreq_governor(data, CPUFREQ_GOV_LIMITS);
 	}
 
 	return 0;


-- 
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Artem Savkov]

On Thu, Feb 07, 2013 at 01:41:57AM +0100, Rafael J. Wysocki wrote:
> On Wednesday, February 06, 2013 10:11:25 PM Rafael J. Wysocki wrote:
> > On Thursday, February 07, 2013 12:25:13 AM Artem Savkov wrote:
> > > I get the following BUG on suspend using systemd-sleep(this doesn't
> > > happen with pm-suspend). This seems to be introduced by some of the
> > > Viresh's patches.
> > 
> > Which branch from which day?

The log is from linux-next-20130205, still reproducible on -20130206

> OK, I've reproduced it and the appended patch fixes it for me.  Can you please
> try it and report back?

I've tried the patch and the bug is still reproducible. I might be wrong
but it seems that the bug happens on first __cpufreq_remove_dev
call(CPU1) on __cpufreq_governor(data, CPUFREQ_GOV_STOP) call (line
~1050) but changes in your patch are all below that call.

-- 
Kind regards,
Artem

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Viresh Kumar]

On Thu, Feb 7, 2013 at 1:55 AM, Artem Savkov <artem.savkov@gmail.com> wrote:
> I get the following BUG on suspend using systemd-sleep(this doesn't
> happen with pm-suspend). This seems to be introduced by some of the
> Viresh's patches.

Hi Artem,

I have sent another patchset (and you are in --to), please test your platform
with these and tell us the results.

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Viresh Kumar]

On 7 February 2013 06:11, Rafael J. Wysocki <rjw@sisk.pl> wrote:
> From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> Subject: cpufreq: Move sysfs_remove_link() from under a spinlock
>
> Commit 73bf0fc "cpufreq: Don't remove sysfs link for policy->cpu"
> attempted to fix a bug in __cpufreq_remove_dev() by avoiding to
> remove the link to the "cpufreq" directory for policy->cpu, but it
> rearranged the code in such a way that sysfs_remove_link() ended up
> under a spinlock, which caused complaints about sleeping in atomic
> context to be emitted into the kernel log during system suspend.
>
> To fix this, revert commit 73bf0fc partially and move the
> sysfs_remove_link() in question to a separate block executed for
> cpus > 1 outside of the spinlock.
>
> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

BTW, i have dropped this patch completely as i got another lock fixing
patch :)

Re: [BUG] cpufreq: sleeping function called from invalid context at kernel/workqueue.c:2811

[Rafael J. Wysocki]

On Friday, February 08, 2013 11:24:39 AM Viresh Kumar wrote:
> On 7 February 2013 06:11, Rafael J. Wysocki <rjw@sisk.pl> wrote:
> > From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> > Subject: cpufreq: Move sysfs_remove_link() from under a spinlock
> >
> > Commit 73bf0fc "cpufreq: Don't remove sysfs link for policy->cpu"
> > attempted to fix a bug in __cpufreq_remove_dev() by avoiding to
> > remove the link to the "cpufreq" directory for policy->cpu, but it
> > rearranged the code in such a way that sysfs_remove_link() ended up
> > under a spinlock, which caused complaints about sleeping in atomic
> > context to be emitted into the kernel log during system suspend.
> >
> > To fix this, revert commit 73bf0fc partially and move the
> > sysfs_remove_link() in question to a separate block executed for
> > cpus > 1 outside of the spinlock.
> >
> > Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
> 
> BTW, i have dropped this patch completely as i got another lock fixing
> patch :)

Sure, I suppose you can get a better fix. :-)

Thanks,
Rafael


-- 
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.