diff mbox

2.6.30: hibernation/swsusp lockup due to acpi-cpufreq

Message ID 20090616202558.GA5423@linux-os.sc.intel.com (mailing list archive)
State RFC, archived
Headers show

Commit Message

venkip June 16, 2009, 8:25 p.m. UTC
On Tue, Jun 16, 2009 at 12:57:50PM -0700, Johannes Stezenbach wrote:
> On Tue, Jun 16, 2009 at 11:55:40AM -0700, Andrew Morton wrote:
> > On Tue, 16 Jun 2009 16:22:17 +0200
> > Johannes Stezenbach <js@sig21.net> wrote:
> > 
> > > Fix swsusp failure on !SMP
> > > 
> > > Commit 01599fca6758d2cd133e78f87426fc851c9ea725 introduced
> > > a regression which caused a backtrace on suspend and
> > > a hang on resume on a Thinkpad T42p (Pentium M CPU).
> > > 
> > > Signed-off-by: Johannes Stezenbach <js@sig21.net>
> > > 
> > > 
> > > --- linux-2.6.30/kernel/up.c.orig	2009-06-16 15:56:28.000000000 +0200
> > > +++ linux-2.6.30/kernel/up.c	2009-06-16 15:57:27.000000000 +0200
> > > @@ -10,11 +10,13 @@
> > >  int smp_call_function_single(int cpu, void (*func) (void *info), void *info,
> > >  				int wait)
> > >  {
> > > +	unsigned long flags;
> > > +
> > >  	WARN_ON(cpu != 0);
> > >  
> > > -	local_irq_disable();
> > > +	local_irq_save(flags);
> > >  	(func)(info);
> > > -	local_irq_enable();
> > > +	local_irq_restore(flags);
> > >  
> > >  	return 0;
> > >  }
> > 
> > ok, what's going on here?  The patch implies that someone (presumably
> > acpi-cpufreq) is calling smp_call_function_single() with local
> > interrupts disabled.  That's a bug on SMP kernels.  And it'll generate
> > a trace if it happens:
> > 
> > 	/* Can deadlock when called with interrupts disabled */
> > 	WARN_ON_ONCE(irqs_disabled() && !oops_in_progress);
> > 
> > but nobody has reported such a trace AFAIK?
> 
> This problem apparently only exists on !SMP kernels...
> 
> > Also, prior to 01599fca6758d2cd133e78f87426fc851c9ea725, acpi-cpufreq
> > was using work_on_cpu().  If it was calling work_on_cpu() with local
> > interrupts disabled then that would have been a bug too, which could
> > generate might_sleep() or scheduling-while-atomic warnings.
> 
> On !SMP, work_on_cpu() is just a function call:
> http://lxr.linux.no/linux+v2.6.30/include/linux/workqueue.h#L261
> 
> > Because it is a bug to call the SMP version of
> > smp_call_function_single() with local interrupts disabled, I don't
> > think we should need to apply the above patch.
> 
> and on SMP, smp_call_function_single() also uses
> local_irq_save/restore() iff  cpu == this_cpu:
> http://lxr.linux.no/linux+v2.6.30/kernel/smp.c#L272
> 
> > But I don't know what we _should_ do because I don't know what the bug
> > is.  Are you able to get us a copy of that stack trace?
> 
> Unfortunately my laptop doesn't have a serial port, and the
> stack trace is large and scrolls off the screen, I can only
> see the last part of it and I would need to find someone with
> a camera to take a picture...


Can you try the patch below (your changes + a warnon). That should give
the stack trace with successful suspend-resume.

acpi-cpufreq will not directly disable interrupt and call these routines.
So, it will be interesting to see how we are ending up in this state.

Thanks,
Venki


--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Comments

Johannes Stezenbach June 16, 2009, 8:40 p.m. UTC | #1
On Tue, Jun 16, 2009 at 01:25:58PM -0700, Pallipadi, Venkatesh wrote:
> 
> Can you try the patch below (your changes + a warnon). That should give
> the stack trace with successful suspend-resume.
> 
> acpi-cpufreq will not directly disable interrupt and call these routines.
> So, it will be interesting to see how we are ending up in this state.

Yes, I actually had the same idea and just did it ;-)
I also found this:
http://lkml.org/lkml/2007/7/17/674

------------[ cut here ]------------                                                                            
WARNING: at kernel/up.c:18 smp_call_function_single+0x45/0x60()                                                 
Hardware name: 2373Y4M                                                                                          
Modules linked in: ath5k mac80211 cfg80211 uhci_hcd ehci_hcd                                                    
Pid: 4139, comm: bash Not tainted 2.6.30 #8                                                                     
Call Trace:                                                                                                     
 [<c011ea0d>] warn_slowpath_common+0x60/0x90                                                                    
 [<c010d86c>] ? do_drv_read+0x0/0x31                                                                            
 [<c011ea4a>] warn_slowpath_null+0xd/0x10                                                                       
 [<c013acc1>] smp_call_function_single+0x45/0x60                                                                
 [<c010d4e5>] get_cur_val+0x62/0x6c                                                                             
 [<c010d72f>] get_cur_freq_on_cpu+0x35/0x58                                                                     
 [<c03786e9>] cpufreq_suspend+0x76/0xd9                                                                         
 [<c0136c3b>] ? clockevents_notify+0x1e/0x68                                                                    
 [<c02ff570>] sysdev_suspend+0x4e/0x182                                                                         
 [<c013fd28>] hibernation_snapshot+0x89/0x16b                                                                   
 [<c013fe99>] hibernate+0x8f/0x147                                                                              
 [<c013ec82>] ? state_store+0x0/0xa2                                                                            
 [<c013ecd7>] state_store+0x55/0xa2                                                                             
 [<c013ec82>] ? state_store+0x0/0xa2                                                                            
 [<c024dff5>] kobj_attr_store+0x1a/0x22                                                                         
 [<c01a7164>] sysfs_write_file+0xb4/0xdf                                                                        
 [<c01a70b0>] ? sysfs_write_file+0x0/0xdf                                                                       
 [<c0170cf2>] vfs_write+0x8a/0x12c                                                                              
 [<c0170e2d>] sys_write+0x3b/0x60                                                                               
 [<c01028f4>] sysenter_do_call+0x12/0x26                                                                        
---[ end trace 1c2172bce3982a59 ]---                                                                            


Johannes
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Johannes Stezenbach June 16, 2009, 8:44 p.m. UTC | #2
On Tue, Jun 16, 2009 at 01:25:58PM -0700, Pallipadi, Venkatesh wrote:
> 
> diff --git a/kernel/up.c b/kernel/up.c
> index 1ff27a2..a4318ff 100644
> --- a/kernel/up.c
> +++ b/kernel/up.c
> @@ -10,11 +10,15 @@
>  int smp_call_function_single(int cpu, void (*func) (void *info), void *info,
>  				int wait)
>  {
> +	unsigned long flags;
> +
>  	WARN_ON(cpu != 0);
>  
> -	local_irq_disable();
> +	WARN_ON(irqs_disabled());
> +
> +	local_irq_save(flags);
>  	(func)(info);
> -	local_irq_enable();
> +	local_irq_restore(flags);
>  
>  	return 0;
>  }
> 

PS: It seems like a good idea to apply this patch with
the warning even if the root cause of the hibernate problem
is elsewhere, for better debuggability of such issues?


Johannes
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Andrew Morton June 16, 2009, 9:09 p.m. UTC | #3
On Tue, 16 Jun 2009 22:40:39 +0200
Johannes Stezenbach <js@sig21.net> wrote:

> On Tue, Jun 16, 2009 at 01:25:58PM -0700, Pallipadi, Venkatesh wrote:
> >
> > Can you try the patch below (your changes + a warnon). That should give
> > the stack trace with successful suspend-resume.
> >
> > acpi-cpufreq will not directly disable interrupt and call these routines.
> > So, it will be interesting to see how we are ending up in this state.
>
> Yes, I actually had the same idea and just did it ;-)
> I also found this:
> http://lkml.org/lkml/2007/7/17/674
>
> ------------[ cut here ]------------
> WARNING: at kernel/up.c:18 smp_call_function_single+0x45/0x60()
> Hardware name: 2373Y4M
> Modules linked in: ath5k mac80211 cfg80211 uhci_hcd ehci_hcd
> Pid: 4139, comm: bash Not tainted 2.6.30 #8
> Call Trace:
>  [<c011ea0d>] warn_slowpath_common+0x60/0x90
>  [<c010d86c>] ? do_drv_read+0x0/0x31
>  [<c011ea4a>] warn_slowpath_null+0xd/0x10
>  [<c013acc1>] smp_call_function_single+0x45/0x60
>  [<c010d4e5>] get_cur_val+0x62/0x6c
>  [<c010d72f>] get_cur_freq_on_cpu+0x35/0x58
>  [<c03786e9>] cpufreq_suspend+0x76/0xd9
>  [<c0136c3b>] ? clockevents_notify+0x1e/0x68
>  [<c02ff570>] sysdev_suspend+0x4e/0x182
>  [<c013fd28>] hibernation_snapshot+0x89/0x16b
>  [<c013fe99>] hibernate+0x8f/0x147
>  [<c013ec82>] ? state_store+0x0/0xa2
>  [<c013ecd7>] state_store+0x55/0xa2
>  [<c013ec82>] ? state_store+0x0/0xa2
>  [<c024dff5>] kobj_attr_store+0x1a/0x22
>  [<c01a7164>] sysfs_write_file+0xb4/0xdf
>  [<c01a70b0>] ? sysfs_write_file+0x0/0xdf
>  [<c0170cf2>] vfs_write+0x8a/0x12c
>  [<c0170e2d>] sys_write+0x3b/0x60
>  [<c01028f4>] sysenter_do_call+0x12/0x26
> ---[ end trace 1c2172bce3982a59 ]---

Right, so it's the suspend-must-disable-local-interrupts thing.  Again.
 create_image()'s local_irq_disable().

It was wrong to call work_on_cpu() with lcoal interrupts disabled, and
it's now wrong to call smp_call_function_single() with local interrupts
disabled.  It's just that smp_call_function_single() warns while
work_on_cpu() didn't.

That all explains the warning But afaik we still don't know why your
machine actually failed.  Perhaps it is a side-efect of emitting the
warning when the console is in a weird state?

So..  what to do?  Possibly we could hack cpufreq to not use
smp_call_function_single() if the call is to be done on the local CPU. 
But SMP might still be broken - if it really does want to do a cross-cpu
call.

Why does cpufreq need to do a cross-CPU get_cur_freq_on_cpu() call at
suspend time _anyway_?  Surely cpufreq knows the target CPU's frequency
from its internal in-main-memory state?
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
venkip June 16, 2009, 9:18 p.m. UTC | #4
On Tue, 2009-06-16 at 14:09 -0700, Andrew Morton wrote:
> On Tue, 16 Jun 2009 22:40:39 +0200
> Johannes Stezenbach <js@sig21.net> wrote:
> 
> > On Tue, Jun 16, 2009 at 01:25:58PM -0700, Pallipadi, Venkatesh wrote:
> > >
> > > Can you try the patch below (your changes + a warnon). That should give
> > > the stack trace with successful suspend-resume.
> > >
> > > acpi-cpufreq will not directly disable interrupt and call these routines.
> > > So, it will be interesting to see how we are ending up in this state.
> >
> > Yes, I actually had the same idea and just did it ;-)
> > I also found this:
> > http://lkml.org/lkml/2007/7/17/674
> >
> > ------------[ cut here ]------------
> > WARNING: at kernel/up.c:18 smp_call_function_single+0x45/0x60()
> > Hardware name: 2373Y4M
> > Modules linked in: ath5k mac80211 cfg80211 uhci_hcd ehci_hcd
> > Pid: 4139, comm: bash Not tainted 2.6.30 #8
> > Call Trace:
> >  [<c011ea0d>] warn_slowpath_common+0x60/0x90
> >  [<c010d86c>] ? do_drv_read+0x0/0x31
> >  [<c011ea4a>] warn_slowpath_null+0xd/0x10
> >  [<c013acc1>] smp_call_function_single+0x45/0x60
> >  [<c010d4e5>] get_cur_val+0x62/0x6c
> >  [<c010d72f>] get_cur_freq_on_cpu+0x35/0x58
> >  [<c03786e9>] cpufreq_suspend+0x76/0xd9
> >  [<c0136c3b>] ? clockevents_notify+0x1e/0x68
> >  [<c02ff570>] sysdev_suspend+0x4e/0x182
> >  [<c013fd28>] hibernation_snapshot+0x89/0x16b
> >  [<c013fe99>] hibernate+0x8f/0x147
> >  [<c013ec82>] ? state_store+0x0/0xa2
> >  [<c013ecd7>] state_store+0x55/0xa2
> >  [<c013ec82>] ? state_store+0x0/0xa2
> >  [<c024dff5>] kobj_attr_store+0x1a/0x22
> >  [<c01a7164>] sysfs_write_file+0xb4/0xdf
> >  [<c01a70b0>] ? sysfs_write_file+0x0/0xdf
> >  [<c0170cf2>] vfs_write+0x8a/0x12c
> >  [<c0170e2d>] sys_write+0x3b/0x60
> >  [<c01028f4>] sysenter_do_call+0x12/0x26
> > ---[ end trace 1c2172bce3982a59 ]---
> 
> Right, so it's the suspend-must-disable-local-interrupts thing.  Again.
>  create_image()'s local_irq_disable().
> 
> It was wrong to call work_on_cpu() with lcoal interrupts disabled, and
> it's now wrong to call smp_call_function_single() with local interrupts
> disabled.  It's just that smp_call_function_single() warns while
> work_on_cpu() didn't.
> 
> That all explains the warning But afaik we still don't know why your
> machine actually failed.  Perhaps it is a side-efect of emitting the
> warning when the console is in a weird state?
> 
> So..  what to do?  Possibly we could hack cpufreq to not use
> smp_call_function_single() if the call is to be done on the local CPU. 
> But SMP might still be broken - if it really does want to do a cross-cpu
> call.

We surely do not need cross CPU cal at this point as all secondary cpus
will be offline at this point.

> Why does cpufreq need to do a cross-CPU get_cur_freq_on_cpu() call at
> suspend time _anyway_?  Surely cpufreq knows the target CPU's frequency
> from its internal in-main-memory state?

That was what I was wondering as well. Looks like this part of
cpufreq_suspend came from

commit 42d4dc3f4e1ec1396371aac89d0dccfdd977191b
Author: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Date:   Fri Apr 29 07:40:12 2005 -0700

    [PATCH] Add suspend method to cpufreq core
    
    In order to properly fix some issues with cpufreq vs. sleep on
    PowerBooks, I had to add a suspend callback to the pmac_cpufreq
driver.
    I must force a switch to full speed before sleep and I switch back
to
    previous speed on resume.
    
    I also added a driver flag to disable the warnings in suspend/resume
    since it is expected in this case to have different speed (and I
want it
    to fixup the jiffies properly).
    
    Signed-off-by: Benjamin Herrenschmidt <benh@kernel.crashing.org>
    Signed-off-by: Andrew Morton <akpm@osdl.org>
    Signed-off-by: Linus Torvalds <torvalds@osdl.org>



benh: Do you think we still need this cpufreq_driver->get() and return
error on (!cur_freq || !cpu_policy->cur) stuff?
May be we should all the checks only if CPUFREQ_PM_NO_WARN is set?

Thanks,
Venki

--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Rafael Wysocki June 16, 2009, 9:39 p.m. UTC | #5
On Tuesday 16 June 2009, Pallipadi, Venkatesh wrote:
> On Tue, 2009-06-16 at 14:09 -0700, Andrew Morton wrote:
> > On Tue, 16 Jun 2009 22:40:39 +0200
> >
> > Johannes Stezenbach <js@sig21.net> wrote:
> > > On Tue, Jun 16, 2009 at 01:25:58PM -0700, Pallipadi, Venkatesh wrote:
> > > > Can you try the patch below (your changes + a warnon). That should
> > > > give the stack trace with successful suspend-resume.
> > > >
> > > > acpi-cpufreq will not directly disable interrupt and call these
> > > > routines. So, it will be interesting to see how we are ending up in
> > > > this state.
> > >
> > > Yes, I actually had the same idea and just did it ;-)
> > > I also found this:
> > > http://lkml.org/lkml/2007/7/17/674
> > >
> > > ------------[ cut here ]------------
> > > WARNING: at kernel/up.c:18 smp_call_function_single+0x45/0x60()
> > > Hardware name: 2373Y4M
> > > Modules linked in: ath5k mac80211 cfg80211 uhci_hcd ehci_hcd
> > > Pid: 4139, comm: bash Not tainted 2.6.30 #8
> > > Call Trace:
> > >  [<c011ea0d>] warn_slowpath_common+0x60/0x90
> > >  [<c010d86c>] ? do_drv_read+0x0/0x31
> > >  [<c011ea4a>] warn_slowpath_null+0xd/0x10
> > >  [<c013acc1>] smp_call_function_single+0x45/0x60
> > >  [<c010d4e5>] get_cur_val+0x62/0x6c
> > >  [<c010d72f>] get_cur_freq_on_cpu+0x35/0x58
> > >  [<c03786e9>] cpufreq_suspend+0x76/0xd9
> > >  [<c0136c3b>] ? clockevents_notify+0x1e/0x68
> > >  [<c02ff570>] sysdev_suspend+0x4e/0x182
> > >  [<c013fd28>] hibernation_snapshot+0x89/0x16b
> > >  [<c013fe99>] hibernate+0x8f/0x147
> > >  [<c013ec82>] ? state_store+0x0/0xa2
> > >  [<c013ecd7>] state_store+0x55/0xa2
> > >  [<c013ec82>] ? state_store+0x0/0xa2
> > >  [<c024dff5>] kobj_attr_store+0x1a/0x22
> > >  [<c01a7164>] sysfs_write_file+0xb4/0xdf
> > >  [<c01a70b0>] ? sysfs_write_file+0x0/0xdf
> > >  [<c0170cf2>] vfs_write+0x8a/0x12c
> > >  [<c0170e2d>] sys_write+0x3b/0x60
> > >  [<c01028f4>] sysenter_do_call+0x12/0x26
> > > ---[ end trace 1c2172bce3982a59 ]---
> >
> > Right, so it's the suspend-must-disable-local-interrupts thing.  Again.
> >  create_image()'s local_irq_disable().
> >
> > It was wrong to call work_on_cpu() with lcoal interrupts disabled, and
> > it's now wrong to call smp_call_function_single() with local interrupts
> > disabled.  It's just that smp_call_function_single() warns while
> > work_on_cpu() didn't.
> >
> > That all explains the warning But afaik we still don't know why your
> > machine actually failed.  Perhaps it is a side-efect of emitting the
> > warning when the console is in a weird state?
> >
> > So..  what to do?  Possibly we could hack cpufreq to not use
> > smp_call_function_single() if the call is to be done on the local CPU.
> > But SMP might still be broken - if it really does want to do a cross-cpu
> > call.
>
> We surely do not need cross CPU cal at this point as all secondary cpus
> will be offline at this point.
>
> > Why does cpufreq need to do a cross-CPU get_cur_freq_on_cpu() call at
> > suspend time _anyway_?  Surely cpufreq knows the target CPU's frequency
> > from its internal in-main-memory state?
>
> That was what I was wondering as well. Looks like this part of
> cpufreq_suspend came from
>
> commit 42d4dc3f4e1ec1396371aac89d0dccfdd977191b
> Author: Benjamin Herrenschmidt <benh@kernel.crashing.org>
> Date:   Fri Apr 29 07:40:12 2005 -0700
>
>     [PATCH] Add suspend method to cpufreq core
>
>     In order to properly fix some issues with cpufreq vs. sleep on
>     PowerBooks, I had to add a suspend callback to the pmac_cpufreq
> driver.
>     I must force a switch to full speed before sleep and I switch back
> to
>     previous speed on resume.
>
>     I also added a driver flag to disable the warnings in suspend/resume
>     since it is expected in this case to have different speed (and I
> want it
>     to fixup the jiffies properly).
>
>     Signed-off-by: Benjamin Herrenschmidt <benh@kernel.crashing.org>
>     Signed-off-by: Andrew Morton <akpm@osdl.org>
>     Signed-off-by: Linus Torvalds <torvalds@osdl.org>
>
>
>
> benh: Do you think we still need this cpufreq_driver->get() and return
> error on (!cur_freq || !cpu_policy->cur) stuff?
> May be we should all the checks only if CPUFREQ_PM_NO_WARN is set?

In fact, we need to do this entire thing differently.

The basic problem is that cpufreq_suspend() is a sysdev thing, so it will 
always be called with iterrupts off and *only* for CPU0.  So, it looks like
the majority of things we do there is just unnecessary (at least).

Best,
Rafael

--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Johannes Stezenbach June 16, 2009, 10:44 p.m. UTC | #6
On Tue, Jun 16, 2009 at 02:09:23PM -0700, Andrew Morton wrote:
> 
> Right, so it's the suspend-must-disable-local-interrupts thing.  Again.
>  create_image()'s local_irq_disable().
> 
> It was wrong to call work_on_cpu() with lcoal interrupts disabled, and
> it's now wrong to call smp_call_function_single() with local interrupts
> disabled.  It's just that smp_call_function_single() warns while
> work_on_cpu() didn't.
> 
> That all explains the warning But afaik we still don't know why your
> machine actually failed.  Perhaps it is a side-efect of emitting the
> warning when the console is in a weird state?

smp_call_function_single() enables irqs and hibernate doesn't like that?

BTW, I have no other UP machine to test with, but I reported
in another thread that a !SMP kernel (or a SMP kernel
with maxcpus=0 parameter) does not boot at all on
my destop machine, see
http://lkml.org/lkml/2009/6/12/468

No idea if I should be worried about this since the
SMP kernel now works fine, another hibernate problem
was solved in
http://lkml.org/lkml/2009/6/14/156


Johannes
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/kernel/up.c b/kernel/up.c
index 1ff27a2..a4318ff 100644
--- a/kernel/up.c
+++ b/kernel/up.c
@@ -10,11 +10,15 @@ 
 int smp_call_function_single(int cpu, void (*func) (void *info), void *info,
 				int wait)
 {
+	unsigned long flags;
+
 	WARN_ON(cpu != 0);
 
-	local_irq_disable();
+	WARN_ON(irqs_disabled());
+
+	local_irq_save(flags);
 	(func)(info);
-	local_irq_enable();
+	local_irq_restore(flags);
 
 	return 0;
 }