Re: BUG: sleeping function called from invalid context when hibernating

[Andrew Morton <akpm@linux-foundation.org>]

On Thu, 15 May 2008 00:27:52 +0200
"Rafael J. Wysocki" <rjw@sisk.pl> wrote:

> On Thursday, 15 of May 2008, Sitsofe Wheeler wrote:
> > When using the linux-next kernel from 13 May 2008 I see the following in 
> > the logs when resuming from hibernate (system is Ubuntu 7.10):
> 
> Something in the PCI department attempted to take a lock with interrupts
> disabled, but that lock had previously been held with interrupts enabled, or so
> it seems.  That something was called from pci_device_resume_early and it was
> a VIA quirk, AFAICS.
> 
> I always need some help from people who actually understand these messages,
> though.  Oh, well.
> 
> > [ 3283.928033] BUG: sleeping function called from invalid context at kernel/rwsem.c:21
> > [ 3283.928033] in_atomic():0, irqs_disabled():1
> > [ 3283.928033] 3 locks held by hibernate.sh/5892:
> > [ 3283.928033]  #0:  (&buffer->mutex){--..}, at: [<c01958e3>] sysfs_write_file+0x25/0xdf
> > [ 3283.928033]  #1:  (pm_mutex){--..}, at: [<c013d6c1>] hibernate+0x10/0x177
> > [ 3283.928033]  #2:  (pm_sleep_rwsem){--..}, at: [<c021c32f>] device_suspend+0x2a/0x1c7
> > [ 3283.928033] irq event stamp: 461790
> > [ 3283.928033] hardirqs last  enabled at (461789): [<c0298283>] __mutex_unlock_slowpath+0xd6/0xde
> > [ 3283.928033] hardirqs last disabled at (461790): [<c013d5fa>] hibernation_snapshot+0xab/0x162
> > [ 3283.928033] softirqs last  enabled at (461166): [<c011e1de>] __do_softirq+0x8f/0x94
> > [ 3283.928033] softirqs last disabled at (461161): [<c011e20d>] do_softirq+0x2a/0x42
> > [ 3283.928033] Pid: 5892, comm: hibernate.sh Not tainted 2.6.25skw #25
> > [ 3283.928033]  [<c0114aad>] __might_sleep+0xb8/0xbf
> > [ 3283.928033]  [<c0298835>] down_read+0x19/0x68
> > [ 3283.928033]  [<c01c5152>] pci_get_subsys+0x48/0xc5
> > [ 3283.928033]  [<c01c51dd>] pci_get_device+0xe/0x10
> > [ 3283.928033]  [<c01c41eb>] quirk_vialatency+0x1b/0xac
> > [ 3283.928033]  [<c01c3fe0>] pci_fixup_device+0x70/0x7c
> > [ 3283.928033]  [<c01c4ae5>] pci_device_resume_early+0x17/0x2e
> > [ 3283.928033]  [<c021c154>] dpm_power_up+0x66/0x94
> > [ 3283.928033]  [<c021c4d9>] device_power_up+0xd/0xf
> > [ 3283.928033]  [<c013d66f>] hibernation_snapshot+0x120/0x162
> > [ 3283.928033]  [<c013d771>] hibernate+0xc0/0x177
> > [ 3283.928033]  [<c013c5ce>] ? state_store+0x0/0xaa
> > [ 3283.928033]  [<c013c613>] state_store+0x45/0xaa
> > [ 3283.928033]  [<c013c5ce>] ? state_store+0x0/0xaa
> > [ 3283.928033]  [<c01b0c3d>] kobj_attr_store+0x1a/0x22
> > [ 3283.928033]  [<c019596b>] sysfs_write_file+0xad/0xdf
> > [ 3283.928033]  [<c01958be>] ? sysfs_write_file+0x0/0xdf
> > [ 3283.928033]  [<c0164afd>] vfs_write+0x88/0xf8
> > [ 3283.928033]  [<c0164f76>] sys_write+0x3b/0x60
> > [ 3283.928033]  [<c01047a2>] sysenter_past_esp+0x5f/0xa5
> > [ 3283.928033]  =======================
> > [ 3283.928033] pci 0000:00:07.0: Disabling VIA external APIC routing
> > 

That's the device_power_up() "Must be called with interrupts disabled"
thing.

We break it again and again.