You are not logged in.

#1 2014-08-15 14:46:48

Unknown1
Member
From: Elsweyr, Tamriel
Registered: 2013-05-09
Posts: 2

Hibernation takes forever

Hi.
All this week I thought hibernation didn't work at all, and I simply reboot when I need to. Turned out, if I wait long enough, system will eventually shut down. During the hibernation process screen goes black, when usually there is blinking underscore. After one long hibernation process all the rest attempts to hibernate goes fine, so if I need to reboot for some reason, I have to endure one painful hibernation after.
It looks like Nvidia driver involved, because everything works fine when hibernating from the terminal or with xf86-video-nouveau.

I have 6g ram / 6g swap. All software is up to date. Nvidia-dkms didn't help.

Journalctrl output:

Aug 15 17:18:41 archbox NetworkManager[278]: <info> sleep requested (sleeping: no  enabled: yes)
Aug 15 17:18:41 archbox NetworkManager[278]: <info> sleeping...
Aug 15 17:18:41 archbox NetworkManager[278]: <info> (wlan0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
Aug 15 17:18:41 archbox NetworkManager[278]: <info> (wlan0): deactivating device (reason 'sleeping') [37]
Aug 15 17:18:41 archbox dhcpcd[309]: received signal TERM from PID 278, stopping
Aug 15 17:18:41 archbox dhcpcd[309]: wlan0: removing interface
Aug 15 17:18:41 archbox NetworkManager[278]: dhcpcd[309]: received signal TERM from PID 278, stopping
Aug 15 17:18:41 archbox NetworkManager[278]: dhcpcd[309]: wlan0: removing interface
Aug 15 17:18:42 archbox NetworkManager[278]: <warn> (wlan0): DHCP client pid 309 didn't exit, will kill it.
Aug 15 17:18:42 archbox NetworkManager[278]: <info> (wlan0): canceled DHCP transaction, DHCP client pid 309
Aug 15 17:18:42 archbox kernel: wlan0: deauthenticating from 84:c9:b2:0b:08:58 by local choice (Reason: 3=DEAUTH_LEAVING)
Aug 15 17:18:42 archbox NetworkManager[278]: <info> NetworkManager state is now ASLEEP
Aug 15 17:18:42 archbox kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Aug 15 17:18:42 archbox kernel: cfg80211: Calling CRDA for country: RU
Aug 15 17:18:42 archbox kernel: IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Aug 15 17:18:42 archbox dbus[283]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Aug 15 17:18:42 archbox NetworkManager[278]: <warn> (pid 309) unhandled DHCP event for interface wlan0
Aug 15 17:18:42 archbox systemd[1]: Starting Sleep.
Aug 15 17:18:42 archbox systemd[1]: Reached target Sleep.
Aug 15 17:18:42 archbox systemd[1]: Starting Hibernate...
Aug 15 17:18:42 archbox systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 15 17:18:42 archbox dbus[283]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 15 17:18:42 archbox systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 15 17:18:42 archbox kernel: PM: Hibernation mode set to 'platform'
Aug 15 17:18:42 archbox systemd-sleep[556]: Suspending system...
Aug 15 17:18:44 archbox systemd-logind[281]: kernel does not support evdev-revocation
Aug 15 17:29:24 archbox kernel: PM: Syncing filesystems ... done.
Aug 15 17:29:24 archbox kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Aug 15 17:29:24 archbox kernel: PM: Marking nosave pages: [mem 0x0009d000-0x000fffff]
Aug 15 17:29:24 archbox kernel: PM: Marking nosave pages: [mem 0xbf681000-0xbf6befff]
Aug 15 17:29:24 archbox kernel: PM: Marking nosave pages: [mem 0xbf75d000-0xbf7befff]
Aug 15 17:29:24 archbox kernel: PM: Marking nosave pages: [mem 0xbf7e0000-0xbf7fefff]
Aug 15 17:29:24 archbox kernel: PM: Marking nosave pages: [mem 0xbf800000-0xffffffff]
Aug 15 17:29:24 archbox kernel: PM: Basic memory bitmaps created
Aug 15 17:29:24 archbox kernel: PM: Preallocating image memory... done (allocated 267178 pages)

11 Minutes.

P.S. Sorry for my awful English.

Offline

#2 2014-08-15 15:25:13

lucke
Member
From: Poland
Registered: 2004-11-30
Posts: 4,018

Re: Hibernation takes forever

See if you get more kernel output after echoing 8 to /proc/sys/kernel/printk.

Offline

#3 2014-08-15 17:34:20

Unknown1
Member
From: Elsweyr, Tamriel
Registered: 2013-05-09
Posts: 2

Re: Hibernation takes forever

Nope, same:

[  114.949946] wlan0: deauthenticating from 84:c9:b2:0b:08:58 by local choice (Reason: 3=DEAUTH_LEAVING)
[  114.956451] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  114.957238] cfg80211: Calling CRDA for country: RU
[  114.976381] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[  115.096782] PM: Hibernation mode set to 'platform'

[  117.214587] PM: Syncing filesystems ... done.
[  118.257045] Freezing user space processes ... (elapsed 0.001 seconds) done.
[  118.260172] PM: Marking nosave pages: [mem 0x0009d000-0x000fffff]
[  118.261865] PM: Marking nosave pages: [mem 0xbf681000-0xbf6befff]
[  118.263510] PM: Marking nosave pages: [mem 0xbf75d000-0xbf7befff]
[  118.265188] PM: Marking nosave pages: [mem 0xbf7e0000-0xbf7fefff]
[  118.266242] PM: Marking nosave pages: [mem 0xbf800000-0xffffffff]

But now I can see more detailed info instead of underscore when hibernation works normal. Is there a way to prevent display shutdown or at least dump this info somewhere?

Offline

#4 2015-01-08 10:32:50

anorax
Member
Registered: 2014-06-16
Posts: 14

Re: Hibernation takes forever

Same problem here. Although sometimes hibernation is carried out just fine in a few seconds and other times it takes ~ 5 mins.

ThinkPad T410, NVidia Graphics.

Here is a journalctl output excerpt (in reverse order) from last hibernation which was initialized automatically after idle timeout:

Jan 08 11:02:51 frank-arch kernel: ACPI: Waking up from system sleep state S4
Jan 08 11:02:51 frank-arch kernel: CPU3 is up
Jan 08 11:02:51 frank-arch kernel: Released forced binding to cpu0 for 155 processes
Jan 08 11:02:51 frank-arch kernel: Added affinity for 155 processes to cpu 3
Jan 08 11:02:51 frank-arch kernel: kvm: enabling virtualization on CPU3
Jan 08 11:02:51 frank-arch kernel: smpboot: Booting Node 0 Processor 3 APIC 0x5
Jan 08 11:02:51 frank-arch kernel: CPU2 is up
Jan 08 11:02:51 frank-arch kernel: Added affinity for 155 processes to cpu 2
Jan 08 11:02:51 frank-arch kernel: kvm: enabling virtualization on CPU2
Jan 08 11:02:51 frank-arch kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Jan 08 11:02:51 frank-arch kernel: CPU1 is up
Jan 08 11:02:51 frank-arch kernel: Added affinity for 155 processes to cpu 1
Jan 08 11:02:51 frank-arch kernel: kvm: enabling virtualization on CPU1
Jan 08 11:02:51 frank-arch kernel: smpboot: Booting Node 0 Processor 1 APIC 0x1
Jan 08 11:02:51 frank-arch kernel: x86: Booting SMP configuration:
Jan 08 11:02:51 frank-arch kernel: Enabling non-boot CPUs ...
Jan 08 11:02:51 frank-arch kernel: PM: Restoring platform NVS memory
Jan 08 11:02:51 frank-arch kernel: PM: Normal pages needed: 327405 + 1024, available pages: 685151
Jan 08 11:02:51 frank-arch kernel: PM: Need to copy 327405 pages
Jan 08 11:02:51 frank-arch kernel: PM: Creating hibernation image:
Jan 08 11:02:51 frank-arch kernel: smpboot: CPU 3 is now offline
Jan 08 11:02:51 frank-arch kernel: kvm: disabling virtualization on CPU3
Jan 08 11:02:51 frank-arch kernel: Removed affinity for 234 processes to cpu 3
Jan 08 11:02:51 frank-arch kernel: smpboot: CPU 2 is now offline
Jan 08 11:02:51 frank-arch kernel: kvm: disabling virtualization on CPU2
Jan 08 11:02:51 frank-arch kernel: Removed affinity for 235 processes to cpu 2
Jan 08 11:02:51 frank-arch kernel: smpboot: CPU 1 is now offline
Jan 08 11:02:51 frank-arch kernel: kvm: disabling virtualization on CPU1
Jan 08 11:02:51 frank-arch kernel: Removed affinity for 234 processes to cpu 1
Jan 08 11:02:51 frank-arch kernel: Disabling non-boot CPUs ...
Jan 08 11:02:51 frank-arch kernel: PM: Saving platform NVS memory
Jan 08 11:02:51 frank-arch kernel: ACPI: Preparing to enter system sleep state S4
Jan 08 11:02:51 frank-arch kernel: PM: noirq freeze of devices complete after 3.072 msecs
Jan 08 11:02:51 frank-arch kernel: PM: late freeze of devices complete after 0.430 msecs
Jan 08 11:02:51 frank-arch kernel: PM: freeze of devices complete after 500.523 msecs
Jan 08 11:02:51 frank-arch kernel: sdhci-pci 0000:0d:00.0: Will use DMA mode even though HW doesn't fully claim to support it.
Jan 08 11:02:51 frank-arch kernel: Suspending console(s) (use no_console_suspend to debug)
Jan 08 11:02:51 frank-arch kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Jan 08 11:02:51 frank-arch kernel: PM: Allocated 1311076 kbytes in 0.11 seconds (11918.87 MB/s)
Jan 08 11:02:51 frank-arch kernel: PM: Preallocating image memory... done (allocated 327769 pages)
Jan 08 11:02:51 frank-arch kernel: PM: Basic memory bitmaps created
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf800000-0xffffffff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf76b000-0xbf7fefff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf717000-0xbf71efff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf46f000-0xbf70efff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf35f000-0xbf40efff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0xbf27c000-0xbf281fff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0x0009e000-0x000fffff]
Jan 08 11:02:51 frank-arch kernel: PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
Jan 08 11:02:51 frank-arch kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Jan 08 11:02:51 frank-arch kernel: PM: Syncing filesystems ... done.
Jan 08 10:48:05 frank-arch systemd-sleep[1211]: Suspending system...
Jan 08 10:48:05 frank-arch kernel: PM: Hibernation mode set to 'platform'

When ThinkPads (at least mine) change power state they output a beep. When it takes a long time to hibernate it beeps once and then again a few seconds later as if it's changing back from hibernation. Then after approx. 5 minutes there is a lower beep which I've never heard in any other scenario and then after another 3 to 4 minutes it finally switches off (power button goes dark). When I switch it on now it resumes completely normal in a few seconds just like after a normal hibernation process. If I forcibly shut it down anytime before it does automatically, it cannot resume and boots as if it had been completely shut down.

Maybe someone else with a ThinkPad has also encountered this and knows why it's doing that and what the meaning behind all the the beeping might be.

Last edited by anorax (2015-01-08 12:57:08)

Offline

Board footer

Powered by FluxBB