2015-12-05 21:20:12

by Jeremiah Mahler

[permalink] [raw]
Subject: [BUG, linux-next] slow resume, hard LOCKUP on cpu 1

all,

Running the latest linux-next (20151202+) on an Acer C720, it will
sporadically be very slow to resume from a suspend. Sometimes it
resumes normally, other times it can take over a minute. During the
worst cases the NMI watchdog will detect a hard lockup on cpu 1 as
shown in the log snippet below (full log is attached).

...
[ 2551.172249] ACPI: Waking up from system sleep state S3
[ 2551.244796] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
[ 2551.244890] PM: noirq resume of devices complete after 72.403 msecs
[ 2551.250938] PM: early resume of devices complete after 6.030 msecs
[ 2551.251702] ath: phy0: ASPM enabled: 0x43
[ 2551.251773] rtc_cmos 00:03: System wakeup disabled by ACPI
[ 2551.268820] sd 0:0:0:0: [sda] Starting disk
[ 2551.288749] xhci_hcd 0000:00:14.0: port 3 resume PLC timeout
[ 2581.325318] NMI watchdog: Watchdog detected hard LOCKUP on cpu 1
[ 2581.325362] Modules linked in: sha256_generic hmac drbg ctr ccm snd_hda_codec_hdmi arc4 ath9k ath9k_common i915 ath9k_hw ath mac80211 uvcvideo cfg80211 videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 isl29018(C) i2c_algo_bit drm_kms_helper videobuf2_core snd_hda_codec_realtek v4l2_common industrialio snd_hda_codec_generic cyapatp videodev regmap_i2c intel_rapl iosf_mbi syscopyarea crc_itu_t snd_hda_intel sysfillrect x86_pkg_temp_thermal sysimgblt intel_powerclamp fb_sys_fops snd_hda_codec drm coretemp media crct10dif_pclmul crc32_pclmul crc32c_intel snd_hwdep snd_hda_core rfkill chromeos_laptop evdev cryptd serio_raw snd_pcm pcspkr shpchp sg lpc_ich snd_timer i2c_i801 mfd_core i2c_designware_pci snd i2c_designware_core battery ac video soundcore i2c_core tpm_tis tpm button autofs4 ext4 crc16 mbcache
[ 2581.325371] jbd2 sd_mod sdhci_acpi sdhci ahci mmc_core libahci libata fan scsi_mod xhci_pci thermal xhci_hcd usbcore usb_common
[ 2581.325374] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G C 4.4.0-rc3-next-20151202+ #58
[ 2581.325375] Hardware name: GOOGLE Peppy/Peppy, BIOS 4.0-6588-g4acd8ea-dirty 09/04/2014
[ 2581.325377] task: ffff880100356e00 ti: ffff880100358000 task.ti: ffff880100358000
[ 2581.325384] RIP: 0010:[<ffffffff813a5217>] [<ffffffff813a5217>] cpuidle_enter_state+0x117/0x250
[ 2581.325385] RSP: 0000:ffff88010035bec8 EFLAGS: 00000246
[ 2581.325386] RAX: 0000000000000000 RBX: 000002521736c80b RCX: 0000000000000018
[ 2581.325387] RDX: 0000000000000000 RSI: 000000000bbf4cf1 RDI: 0000000000000000
[ 2581.325388] RBP: 0000000000000006 R08: 000000002332ec94 R09: ffff880100311844
[ 2581.325389] R10: 0000000000000e51 R11: 00000000ffffffff R12: ffffe8ffffd06f00
[ 2581.325390] R13: 000002521736c80b R14: ffffffff818a33f8 R15: 0000025216fa9cb3
[ 2581.325392] FS: 0000000000000000(0000) GS:ffff880100300000(0000) knlGS:0000000000000000
[ 2581.325393] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2581.325394] CR2: 0000000000000000 CR3: 000000000180a000 CR4: 00000000000406e0
[ 2581.325394] Stack:
[ 2581.325397] 0000000000000000 ffffe8ffffd06f00 ffff88010035c000 ffff880100358000
[ 2581.325399] ffff880100358000 ffff88010035c000 ffffffff818a31a0 ffffffff81093fc4
[ 2581.325401] a1b81e5358297dd8 0000000000000000 0000000000000000 0000000000000000
[ 2581.325402] Call Trace:
[ 2581.325407] [<ffffffff81093fc4>] ? cpu_startup_entry+0x234/0x2e0
[ 2581.325411] [<ffffffff81036e14>] ? start_secondary+0x144/0x170
[ 2581.325435] Code: c5 0f 1f 44 00 00 31 ff e8 57 ea ce ff 8b 44 24 04 85 c0 74 12 9c 58 f6 c4 02 0f 85 01 01 00 00 31 ff e8 0d 89 d1 ff fb 4c 89 eb <48> ba cf f7 53 e3 a5 9b c4 20 4c 29 fb 48 89 d8 48 c1 fb 3f 48
[ 2621.433815] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 2621.434605] ata1.00: configured for UDMA/100
[ 2621.490099] usb 1-3: reset high-speed USB device number 2 using xhci_hcd
[ 2621.842050] usb 1-4: reset full-speed USB device number 3 using xhci_hcd
[ 2621.971325] PM: resume of devices complete after 70727.399 msecs
[ 2621.971728] Restarting tasks ... done.
[ 2621.988444] cfg80211: World regulatory domain updated:
[ 2621.988448] cfg80211: DFS Master region: unset
...

Anyone else having this problem? Any suggestions for how to debug?

Thanks,
--
- Jeremiah Mahler


Attachments:
(No filename) (4.06 kB)
dmesg.bad (46.03 kB)
Download all attachments

2015-12-09 18:24:51

by Jeremiah Mahler

[permalink] [raw]
Subject: Re: [BUG, linux-next] slow resume, hard LOCKUP on cpu 1

On Sat, Dec 05, 2015 at 01:20:01PM -0800, Jeremiah Mahler wrote:
> all,
>
> Running the latest linux-next (20151202+) on an Acer C720, it will
> sporadically be very slow to resume from a suspend. Sometimes it
> resumes normally, other times it can take over a minute. During the
> worst cases the NMI watchdog will detect a hard lockup on cpu 1 as
> shown in the log snippet below (full log is attached).
>
...

Apparently something got fixed because it seems to be working fine with
linux-next 20151207.

--
- Jeremiah Mahler