[arch-general] pm-suspend stuck at uhci_hcd

Sun May 20 14:13:53 EDT 2012

On Sun, 20 May 2012 12:36:16 +0200
Manne Merak <mannemerak at gmail.com> wrote:

> On 05/17/2012 01:11 AM, Leonid Isaev wrote:
> > On Wed, 16 May 2012 23:50:06 +0200
> > Manne Merak<mannemerak at gmail.com>  wrote:
> >
> >> Hi,
> >> Couple of updates ago suspend to RAM stopped working.
> >> Looking at the pm-suspend.log (below) file shows that it gets stuck at
> >> unloading uhci_hcd?
> >> I can unload and load the module by hand just fine.
> >> Anyone else have this?
> > Hmm, 75modules should print something like "done" or "fail". What do you
> > mean by stopped working? What configuration do you have
> > in /etc/pm/config.d/*?
> >
> 
> Ok, some more debugging.
> The first suspend-RAM works file.  Checked the pm-suspend.log and all 
> gets unloaded just fine.
> On second suspend, I get the mentioned stuck at unloading uhci_hcd 
> (leaving it a while gives):
> 
> -------
> Running hook /usr/lib/pm-utils/sleep.d/75modules suspend suspend:
> Unloading kernel module uhci_hcd.../usr/lib/pm-utils/functions: line 84: 
> 26341 Killed                  modprobe -r "$1"

I am puzzled by this... really. Do you get anything at all in syslog after
this? Or syslog is already stopped at this point?

> /usr/lib/pm-utils/functions: line 89: log: command not found

WTF??? This is a 2 year old bug in pm-utils. OpenSUSE 11.3 fixed that in
1.3.0. Please see if this fix gets rid of the "log" error:
<http://lists.freedesktop.org/archives/pm-utils/2010-September/002219.html>.

> Failed.
> Unloading kernel module ehci_hcd...
> ----
> 
> Now stuck at unloading ehci_hcd.
> 
> I get the same behaviour trying to unload uhci_hcd or ehci_hcd after the 
> first successfull suspend and restore.

You mean "unload manually", right?

> 
> There's more; a "oops" in the system log:
> 
> [209624.386398] BUG: unable to handle kernel paging request at 6d0d0000
> [209624.386404] IP: [<c04ad62a>] _raw_spin_lock_irqsave+0x2a/0x50
> [209624.386412] *pde = 00000000
> [209624.386414] Oops: 0002 [#1] PREEMPT SMP
> [209624.386418] Modules linked in: uhci_hcd(-) ehci_hcd usb_storage uas 
> rfcomm btusb hidp bnep bluetooth fuse vboxnetadp(O) vboxnetflt(O) usbhid 
> uvcvideo hid videobuf2_vmalloc videobuf2_memops videobuf2_core videodev 
> media nvidia(PO) snd_hda_codec_idt snd_hda_intel firewire_ohci joydev 
> b44 snd_hda_codec r852 sm_common nand snd_pcm nand_ecc nand_ids arc4 
> iwl3945 iwlegacy ssb snd_page_alloc r592 mtd iTCO_wdt firewire_core 
> crc_itu_t pcmcia mii pcmcia_core mac80211 sdhci_pci intel_agp sdhci 
> intel_gtt mmc_core cfg80211 agpgart i2c_i801 i2c_core snd_hwdep 
> snd_timer snd memstick iTCO_vendor_support serio_raw dell_wmi psmouse 
> sparse_keymap soundcore wmi dell_laptop usbcore usb_common rfkill evdev 
> thermal dcdbas button battery ac video vboxdrv(O) cpufreq_powersave 
> acpi_cpufreq mperf processor ext4 crc16 jbd2 mbcache sr_mod sd_mod cdrom 
> pata_acpi ata_generic ata_piix ahci libahci libata scsi_mod [last 
> unloaded: ehci_hcd]
> [209624.386476]
> [209624.386479] Pid: 26341, comm: modprobe Tainted: P           O 
> 3.3.6-1-ARCH #1 Dell Inc. Vostro 1700                     /0HX767
> [209624.386483] EIP: 0060:[<c04ad62a>] EFLAGS: 00010002 CPU: 0
> [209624.386486] EIP is at _raw_spin_lock_irqsave+0x2a/0x50
> [209624.386488] EAX: 00000100 EBX: 6d0d0000 ECX: 6d0d0000 EDX: e002dd10
> [209624.386490] ESI: 00000206 EDI: f24ca4b4 EBP: e002dcf0 ESP: e002dce8
> [209624.386492]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [209624.386494] Process modprobe (pid: 26341, ti=e002c000 task=c5aeca80 
> task.ti=e002c000)
> [209624.386496] Stack:
> [209624.386497]  6d0d0000 6d0d0000 e002dd08 c0142d39 e002dd10 f24ca4a8 
> 00000000 ffffffff
> [209624.386503]  e002dd20 c0142eca f8af756a f24ca400 00000000 ecdfbc94 
> e002dd38 f8af7461
> [209624.386508]  ecdfbc94 f24ca400 ecdfbcd8 ecdfbc94 e002dd58 f8af7694 
> ecdfb808 ecdfb808
> [209624.386513] Call Trace:
> [209624.386519]  [<c0142d39>] lock_timer_base.isra.33+0x29/0x50
> [209624.386522]  [<c0142eca>] del_timer+0x2a/0xe0
> [209624.386529]  [<f8af756a>] ? hci_conn_del+0x12a/0x1f0 [bluetooth]
> [209624.386534]  [<f8af7461>] hci_conn_del+0x21/0x1f0 [bluetooth]
> [209624.386538]  [<f8af7694>] hci_conn_hash_flush+0x64/0xb0 [bluetooth]
> [209624.386543]  [<f8af3746>] hci_dev_do_close+0x96/0x290 [bluetooth]
> [209624.386548]  [<f8af5958>] hci_unregister_dev+0x48/0x140 [bluetooth]
> [209624.386551]  [<f8a9ab4f>] btusb_disconnect+0x4f/0xb0 [btusb]
> [209624.386559]  [<f8ec0a5c>] usb_unbind_interface+0x3c/0x140 [usbcore]
> [209624.386564]  [<c038801d>] __device_release_driver+0x5d/0xb0
> [209624.386566]  [<c0388094>] device_release_driver+0x24/0x40
> [209624.386569]  [<c0387bf5>] bus_remove_device+0xa5/0xd0
> [209624.386572]  [<c0385d55>] device_del+0xe5/0x150
> [209624.386578]  [<f8ebeb19>] usb_disable_device+0x89/0x1a0 [usbcore]
> [209624.386584]  [<f8eb8030>] usb_disconnect+0x70/0xe0 [usbcore]
> [209624.386590]  [<f8eb801f>] usb_disconnect+0x5f/0xe0 [usbcore]
> [209624.386595]  [<f8eb801f>] usb_disconnect+0x5f/0xe0 [usbcore]
> [209624.386602]  [<f8eba94c>] usb_remove_hcd+0x9c/0x120 [usbcore]
> [209624.386608]  [<f8ec8d78>] usb_hcd_pci_remove+0x48/0xb0 [usbcore]
> [209624.386611]  [<c02fdbff>] pci_device_remove+0x2f/0xe0
> [209624.386614]  [<c038801d>] __device_release_driver+0x5d/0xb0
> [209624.386616]  [<c038864f>] driver_detach+0x8f/0xa0
> [209624.386619]  [<c0387ef2>] bus_remove_driver+0x62/0xa0
> [209624.386621]  [<c0388b49>] driver_unregister+0x49/0x80
> [209624.386624]  [<c02febd2>] pci_unregister_driver+0x32/0x80
> [209624.386627]  [<f8070ce0>] uhci_hcd_cleanup+0xd/0x35 [uhci_hcd]
> [209624.386632]  [<c018e5af>] sys_delete_module+0x11f/0x280
> [209624.386635]  [<c022b920>] ? fput+0x130/0x1d0
> [209624.386639]  [<c0227984>] ? filp_close+0x54/0x80
> [209624.386642]  [<c0227a22>] ? sys_close+0x72/0xc0
> [209624.386645]  [<c04ae69f>] sysenter_do_call+0x12/0x28
> [209624.386647] Code: 00 55 89 e5 56 53 3e 8d 74 26 00 89 c1 9c 58 8d 74 
> 26 00 89 c6 fa 90 8d 74 26 00 89 e0 25 00 e0 ff ff 83 40 14 01 b8 00 01 
> 00 00 <f0> 66 0f c1 01 0f b6 dc 38 c3 74 0b 66 90 f3 90 0f b6 11 38 da
> [209624.386677] EIP: [<c04ad62a>] _raw_spin_lock_irqsave+0x2a/0x50 
> SS:ESP 0068:e002dce8
> [209624.386680] CR2: 000000006d0d0000
> [209624.386683] ---[ end trace 2d604d3b1307f2ba ]---
> [209624.386686] note: modprobe[26341] exited with preempt_count 1
> 

Seems like some kind of IRQ problem. Perhaps someone more knowledgeable can
tell whether this is kernel's or kmod's fault...

Finally, have you actually tried to remove *_hcd from MODULE_SUSPEND and see
if it works?

-- 
Leonid Isaev
GnuPG key: 0x164B5A6D
Fingerprint: C0DF 20D0 C075 C3F1 E1BE  775A A7AE F6CB 164B 5A6D
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 490 bytes
Desc: not available
URL: <http://mailman.archlinux.org/pipermail/arch-general/attachments/20120520/cdb90556/attachment.asc>