You are not logged in.
Laptop freezes after resuming from suspension, after I resume from a suspension the laptop freezes for 3-10 seconds.
The only message in my journal:
Jan 24 22:06:21 trevog systemd[465]: Time has been changed
I'm not sure how I can log the issues best.
Last edited by trevog (2015-01-24 21:50:33)
Offline
I was able to log alot more using pm-utils, here is the output:
[ 7118.500716] wlp4s0: authenticate with b4:82:fe:bf:5f:6b
[ 7118.503333] wlp4s0: send auth to b4:82:fe:bf:5f:6b (try 1/3)
[ 7118.505203] wlp4s0: authenticated
[ 7118.505822] wlp4s0: associate with b4:82:fe:bf:5f:6b (try 1/3)
[ 7118.508532] wlp4s0: RX AssocResp from b4:82:fe:bf:5f:6b (capab=0x411 status=0 aid=5)
[ 7118.509962] wlp4s0: associated
[ 7119.434595] cfg80211: Calling CRDA to update world regulatory domain
[ 7119.955836] cfg80211: Calling CRDA to update world regulatory domain
[ 7120.257728] EXT4-fs (sda2): re-mounted. Opts: data=ordered,discard,commit=0
[ 7120.259430] EXT4-fs (sda1): re-mounted. Opts: data=ordered,discard,commit=0
[ 7120.296308] usb 3-11: USB disconnect, device number 31
[ 7120.385957] PM: Syncing filesystems ... done.
[ 7120.396331] PM: Preparing system for mem sleep
[ 7120.396580] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 7120.397897] Freezing remaining freezable tasks ... (elapsed 0.022 seconds) done.
[ 7120.420869] PM: Entering mem sleep
[ 7120.420886] Suspending console(s) (use no_console_suspend to debug)
[ 7120.556599] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 7120.559859] sd 0:0:0:0: [sda] Stopping disk
[ 7120.777882] e1000e: EEE TX LPI TIMER: 00000011
[ 7121.054678] PM: suspend of devices complete after 633.149 msecs
[ 7121.108030] PM: late suspend of devices complete after 53.305 msecs
[ 7121.108783] ehci-pci 0000:00:1d.0: System wakeup enabled by ACPI
[ 7121.109031] ehci-pci 0000:00:1a.0: System wakeup enabled by ACPI
[ 7121.109074] e1000e 0000:00:19.0: System wakeup enabled by ACPI
[ 7121.109084] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
[ 7121.121292] PM: noirq suspend of devices complete after 13.249 msecs
[ 7121.121509] ACPI: Preparing to enter system sleep state S3
[ 7121.274724] PM: Saving platform NVS memory
[ 7121.274729] Disabling non-boot CPUs ...
[ 7121.274768] intel_pstate CPU 1 exiting
[ 7121.275997] smpboot: CPU 1 is now offline
[ 7121.276230] intel_pstate CPU 2 exiting
[ 7121.277446] smpboot: CPU 2 is now offline
[ 7121.277697] intel_pstate CPU 3 exiting
[ 7121.278896] smpboot: CPU 3 is now offline
[ 7121.279070] intel_pstate CPU 4 exiting
[ 7121.280275] smpboot: CPU 4 is now offline
[ 7121.280525] intel_pstate CPU 5 exiting
[ 7121.281711] smpboot: CPU 5 is now offline
[ 7121.281888] intel_pstate CPU 6 exiting
[ 7121.283092] smpboot: CPU 6 is now offline
[ 7121.283326] intel_pstate CPU 7 exiting
[ 7121.284478] smpboot: CPU 7 is now offline
[ 7121.285761] ACPI: Low-level resume complete
[ 7121.285796] PM: Restoring platform NVS memory
[ 7121.286130] Enabling non-boot CPUs ...
[ 7121.286163] x86: Booting SMP configuration:
[ 7121.286163] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 7121.300519] CPU1 is up
[ 7121.300541] smpboot: Booting Node 0 Processor 2 APIC 0x2
[ 7121.314762] CPU2 is up
[ 7121.314788] smpboot: Booting Node 0 Processor 3 APIC 0x3
[ 7121.329136] CPU3 is up
[ 7121.329159] smpboot: Booting Node 0 Processor 4 APIC 0x4
[ 7121.343400] CPU4 is up
[ 7121.343423] smpboot: Booting Node 0 Processor 5 APIC 0x5
[ 7121.357789] CPU5 is up
[ 7121.357810] smpboot: Booting Node 0 Processor 6 APIC 0x6
[ 7121.372058] CPU6 is up
[ 7121.372081] smpboot: Booting Node 0 Processor 7 APIC 0x7
[ 7121.386584] CPU7 is up
[ 7121.394057] ACPI: Waking up from system sleep state S3
[ 7121.689792] acpi LNXPOWER:02: Turning OFF
[ 7121.696631] ehci-pci 0000:00:1a.0: System wakeup disabled by ACPI
[ 7121.696799] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
[ 7121.696805] ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
[ 7121.710942] PM: noirq resume of devices complete after 14.458 msecs
[ 7121.950109] PM: early resume of devices complete after 238.950 msecs
[ 7121.950165] e1000e 0000:00:19.0: System wakeup disabled by ACPI
[ 7121.950181] mei_me 0000:00:16.0: irq 26 for MSI/MSI-X
[ 7121.950200] usb usb3: root hub lost power or was reset
[ 7121.950202] usb usb4: root hub lost power or was reset
[ 7121.950214] snd_hda_intel 0000:00:03.0: irq 28 for MSI/MSI-X
[ 7121.950371] xhci_hcd 0000:00:14.0: irq 29 for MSI/MSI-X
[ 7121.950555] snd_hda_intel 0000:00:1b.0: irq 32 for MSI/MSI-X
[ 7121.950733] rtc_cmos 00:02: System wakeup disabled by ACPI
[ 7121.951373] sd 0:0:0:0: [sda] Starting disk
[ 7121.980057] tpm_tis 00:05: TPM is disabled/deactivated (0x6)
[ 7122.043981] e1000e 0000:00:19.0: irq 33 for MSI/MSI-X
[ 7122.170215] usb 1-1: reset high-speed USB device number 2 using ehci-pci
[ 7122.170225] usb 2-1: reset high-speed USB device number 2 using ehci-pci
[ 7122.270283] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 7122.270299] ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 7122.272951] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[ 7122.272952] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[ 7122.273213] ata1.00: supports DRM functions and may not be fully accessible
[ 7122.273236] ata6.00: ACPI cmd e3/00:79:00:00:00:a0 (IDLE) succeeded
[ 7122.273280] ata1.00: failed to get NCQ Send/Recv Log Emask 0x1
[ 7122.273607] ata6.00: ACPI cmd e3/00:01:00:00:00:a0 (IDLE) succeeded
[ 7122.276902] ata6.00: ACPI cmd e3/00:79:00:00:00:a0 (IDLE) succeeded
[ 7122.277138] ata6.00: ACPI cmd e3/00:01:00:00:00:a0 (IDLE) succeeded
[ 7122.278057] ata6.00: configured for UDMA/133
[ 7122.278711] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[ 7122.278713] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[ 7122.278932] ata1.00: supports DRM functions and may not be fully accessible
[ 7122.278982] ata1.00: failed to get NCQ Send/Recv Log Emask 0x1
[ 7122.279044] ata1.00: configured for UDMA/133
[ 7122.327129] usb 3-5: reset full-speed USB device number 4 using xhci_hcd
[ 7122.362148] iwlwifi 0000:04:00.0: L1 Enabled - LTR Enabled
[ 7122.368588] iwlwifi 0000:04:00.0: L1 Enabled - LTR Enabled
[ 7122.501893] usb 3-5: No LPM exit latency info found, disabling LPM.
[ 7122.507124] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231f27000
[ 7122.507126] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231f27048
[ 7122.507143] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231f27090
[ 7122.714102] usb 3-12: reset high-speed USB device number 8 using xhci_hcd
[ 7122.944909] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88022df431e0
[ 7123.047714] usb 3-7: reset full-speed USB device number 5 using xhci_hcd
[ 7123.221973] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88023217cc00
[ 7123.221975] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88023217cc48
[ 7123.221976] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88023217cc90
[ 7123.221976] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88023217ccd8
[ 7123.381292] usb 3-10: reset high-speed USB device number 32 using xhci_hcd
[ 7128.972537] usb 3-1: reset full-speed USB device number 2 using xhci_hcd
[ 7129.147672] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880232f47360
[ 7129.147674] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880232f473c0
[ 7129.151274] PM: resume of devices complete after 7195.352 msecs
[ 7129.151541] PM: Finishing wakeup.
[ 7129.151542] Restarting tasks ...
[ 7129.151600] usb 3-3: USB disconnect, device number 26
[ 7129.152784] wlp4s0: authenticate with b4:82:fe:bf:5f:6b
[ 7129.153180] done.
[ 7129.154597] wlp4s0: send auth to b4:82:fe:bf:5f:6b (try 1/3)
[ 7129.156438] wlp4s0: authenticated
[ 7129.159141] wlp4s0: associate with b4:82:fe:bf:5f:6b (try 1/3)
[ 7129.161802] wlp4s0: RX AssocResp from b4:82:fe:bf:5f:6b (capab=0x411 status=0 aid=5)
[ 7129.165902] wlp4s0: associated
[ 7129.240282] EXT4-fs (sda2): re-mounted. Opts: data=ordered,discard,commit=0
[ 7129.241964] EXT4-fs (sda1): re-mounted. Opts: data=ordered,discard,commit=0
[ 7129.269262] usb 3-10: USB disconnect, device number 32
[ 7129.269298] cdc_mbim 3-10:1.0 wwp0s20u10: unregister 'cdc_mbim' usb-0000:00:14.0-10, CDC MBIM
[ 7129.299779] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800a7e118a0
[ 7129.299783] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88022fbeadc8
[ 7129.299785] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88022fbead80
[ 7129.299787] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8800a7e11c60
[ 7129.299788] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88022fbea1c8
[ 7129.299790] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88022fbea180
[ 7129.579556] usb 3-10: new high-speed USB device number 33 using xhci_hcd
[ 7129.782140] cdc_mbim 3-10:1.0: cdc-wdm1: USB WDM device
[ 7129.782291] cdc_mbim 3-10:1.0 wwan0: register 'cdc_mbim' at usb-0000:00:14.0-10, CDC MBIM, 1a:9a:ff:37:e7:ef
[ 7129.783256] cdc_acm 3-10:1.2: This device cannot do calls on its own. It is not a modem.
[ 7129.783282] cdc_acm 3-10:1.2: ttyACM0: USB ACM device
[ 7129.785626] cdc_mbim 3-10:1.0 wwp0s20u10: renamed from wwan0
[ 7130.063277] usb 3-11: new full-speed USB device number 34 using xhci_hcd
[ 7130.252315] Bluetooth: hci0: read Intel version: 370710018002030d00
[ 7130.252394] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq
[ 7130.456460] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated[ 7129.151274] PM: resume of devices complete after 7195.352 msecs
As you can see this is a pretty long time, but I can't see why.
Last edited by trevog (2015-01-25 21:15:28)
Offline
Bump, I've still got this problem these are the lines i can see with "dmesg" that take a long time.
[30539.821495] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231b99c00
[30539.821497] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231b99c48
[30539.821498] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880231b99c90
[30539.975076] usb 3-10: reset high-speed USB device number 29 using xhci_hcd
[30551.914962] PM: resume of devices complete after 13306.958 msecs
[30551.915188] PM: Finishing wakeup.Offline