[arch-general] pm-suspend stuck at uhci_hcd

[Manne Merak]

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"
/usr/lib/pm-utils/functions: line 89: log: command not found
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.

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