Arch Linux

Lockheed

Member

Registered: 2010-03-16

Posts: 1,521

pm-hibernate stalls trice upon resume

Every stall is followed with a short beep, and lasts about 30-40 seconds during which the laptop is not doing anything. It is not reading from disk, it is no calculating anything. It is just waiting for something.

Here are the logs starting before hibernation and ending after resume:

pm-powersave.log

Running hook /usr/lib/pm-utils/power.d/hal-cd-polling false:

/usr/lib/pm-utils/power.d/hal-cd-polling false: success.
Running hook /usr/lib/pm-utils/power.d/intel-audio-powersave false:
Setting power savings for snd_hda_intel to 0...Done.

/usr/lib/pm-utils/power.d/intel-audio-powersave false: success.
Running hook /usr/lib/pm-utils/power.d/journal-commit false:
Setting journal commit time for / to 0...Done.
Setting journal commit time for /mnt/Disk_D to 0...Done.
Setting journal commit time for /mnt/arch_backup to 0...Done.

/usr/lib/pm-utils/power.d/journal-commit false: success.
Running hook /usr/lib/pm-utils/power.d/laptop-mode false:
Laptop mode disabled.

/usr/lib/pm-utils/power.d/laptop-mode false: success.
Running hook /usr/lib/pm-utils/power.d/pcie_aspm false:

/usr/lib/pm-utils/power.d/pcie_aspm false: success.
Running hook /usr/lib/pm-utils/power.d/readahead false:
Setting readahead for /dev/sdb1 to 256...Done.
Setting readahead for /dev/sdb3 to 256...Done.
Setting readahead for /dev/sda1 to 256...Done.
Setting readahead for /dev/sda2 to 256...Done.

/usr/lib/pm-utils/power.d/readahead false: success.
Running hook /usr/lib/pm-utils/power.d/sata_alpm false:
Setting SATA APLM on host2 to max_performance...Done.
Setting SATA APLM on host3 to max_performance...Done.
Setting SATA APLM on host4 to max_performance...Done.

/usr/lib/pm-utils/power.d/sata_alpm false: success.
Running hook /usr/lib/pm-utils/power.d/sched-powersave false:
**sched policy powersave OFF

/usr/lib/pm-utils/power.d/sched-powersave false: success.
Running hook /usr/lib/pm-utils/power.d/wireless false:
Turning powersave for wlan0 off...Done.

/usr/lib/pm-utils/power.d/wireless false: success.
Running hook /usr/lib/pm-utils/power.d/xfs_buffer false:

/usr/lib/pm-utils/power.d/xfs_buffer false: success.
Running hook /usr/lib/pm-utils/power.d/zztlp false:
TLP started in ac mode.

/usr/lib/pm-utils/power.d/zztlp false: success.
Running hook /usr/lib/pm-utils/power.d/hal-cd-polling false:

/usr/lib/pm-utils/power.d/hal-cd-polling false: success.
Running hook /usr/lib/pm-utils/power.d/intel-audio-powersave false:
Setting power savings for snd_hda_intel to 0...Done.

/usr/lib/pm-utils/power.d/intel-audio-powersave false: success.
Running hook /usr/lib/pm-utils/power.d/journal-commit false:
Setting journal commit time for / to 0...Done.
Setting journal commit time for /mnt/Disk_D to 0...Done.
Setting journal commit time for /mnt/arch_backup to 0...Done.

/usr/lib/pm-utils/power.d/journal-commit false: success.
Running hook /usr/lib/pm-utils/power.d/laptop-mode false:
Laptop mode disabled.

/usr/lib/pm-utils/power.d/laptop-mode false: success.
Running hook /usr/lib/pm-utils/power.d/pcie_aspm false:

/usr/lib/pm-utils/power.d/pcie_aspm false: success.
Running hook /usr/lib/pm-utils/power.d/readahead false:
Setting readahead for /dev/sdb1 to 256...Done.
Setting readahead for /dev/sdb3 to 256...Done.
Setting readahead for /dev/sda1 to 256...Done.
Setting readahead for /dev/sda2 to 256...Done.

/usr/lib/pm-utils/power.d/readahead false: success.
Running hook /usr/lib/pm-utils/power.d/sata_alpm false:
Setting SATA APLM on host2 to max_performance...Done.
Setting SATA APLM on host3 to max_performance...Done.
Setting SATA APLM on host4 to max_performance...Done.

/usr/lib/pm-utils/power.d/sata_alpm false: success.
Running hook /usr/lib/pm-utils/power.d/sched-powersave false:
**sched policy powersave OFF

/usr/lib/pm-utils/power.d/sched-powersave false: success.
Running hook /usr/lib/pm-utils/power.d/wireless false:
Turning powersave for wlan0 off...Done.

/usr/lib/pm-utils/power.d/wireless false: success.
Running hook /usr/lib/pm-utils/power.d/xfs_buffer false:

/usr/lib/pm-utils/power.d/xfs_buffer false: success.
Running hook /usr/lib/pm-utils/power.d/zztlp false:
TLP started in ac mode.

/usr/lib/pm-utils/power.d/zztlp false: success.

pm-suspend.log

Initial commandline parameters: 
Thu  4 Jul 09:41:12 CEST 2013: Running hooks for hibernate.
Running hook /etc/pm/sleep.d/00doit hibernate hibernate:

/etc/pm/sleep.d/00doit hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00logging hibernate hibernate:
Linux panzor 3.9.4-pf-ARCH #1 SMP PREEMPT Fri Jun 21 18:03:32 CEST 2013 x86_64 GNU/Linux
Module                  Size  Used by
dm_mod                 72207  0 
omfs                   14088  0 
jfs                   171061  0 
xfs                   766252  0 
crc32c                  1736  1 
libcrc32c               1002  1 xfs
reiserfs              240563  0 
hfs                    45025  0 
hfsplus                90020  0 
vfat                   10119  0 
fat                    49421  1 vfat
isofs                  31965  0 
nls_utf8                1320  0 
udf                    78193  0 
usb_storage            47095  0 
pci_stub                1381  1 
vboxpci                14581  0 
vboxnetflt             16652  0 
vboxnetadp             18195  0 
vboxvideo               1933  0 
ipt_MASQUERADE          2154  2 
xt_TCPMSS               3471  2 
iptable_nat             3358  1 
nf_nat_ipv4             3568  1 iptable_nat
nf_nat                 15028  3 ipt_MASQUERADE,nf_nat_ipv4,iptable_nat
iptable_mangle          1584  0 
ipt_REJECT              2313  5 
xt_tcpudp               3143  10 
nf_conntrack_ipv4       9262  6 
nf_defrag_ipv4          1371  1 nf_conntrack_ipv4
xt_recent               8600  4 
xt_conntrack            3265  5 
nf_conntrack           69663  6 ipt_MASQUERADE,nf_nat,nf_nat_ipv4,xt_conntrack,iptable_nat,nf_conntrack_ipv4
iptable_filter          1488  1 
ip_tables              17186  3 iptable_filter,iptable_mangle,iptable_nat
x_tables               17223  9 xt_recent,ip_tables,xt_tcpudp,ipt_MASQUERADE,xt_conntrack,iptable_filter,xt_TCPMSS,ipt_REJECT,iptable_mangle
hid_logitech_dj        10471  0 
usbhid                 40956  1 hid_logitech_dj
hid                    87411  2 usbhid,hid_logitech_dj
iTCO_wdt                5407  0 
iTCO_vendor_support     1929  1 iTCO_wdt
coretemp                6102  0 
kvm_intel             125381  0 
snd_hda_codec_analog    79909  1 
kvm                   388248  1 kvm_intel
joydev                  9695  1 
fuse                   70505  5 
microcode              11764  0 
psmouse                84428  0 
serio_raw               5041  0 
evdev                   9912  20 
i2c_i801               11269  0 
nvidia               9387125  45 
lpc_ich                12849  0 
r852                   10276  0 
sm_common               9093  1 r852
nand                   52310  2 r852,sm_common
nand_ecc                3583  1 nand
nand_ids                5777  1 nand
mtd                    30895  2 nand,sm_common
r592                   11851  0 
arc4                    2000  2 
memstick                7408  1 r592
iwl4965                88040  0 
iwlegacy               48265  1 iwl4965
mac80211              485262  2 iwl4965,iwlegacy
cfg80211              451308  3 iwl4965,iwlegacy,mac80211
drm                   228742  4 nvidia,vboxvideo
snd_hda_intel          34138  4 
thermal                 8652  0 
wmi                     8347  0 
snd_hda_codec         144424  2 snd_hda_intel,snd_hda_codec_analog
battery                 6970  0 
snd_hwdep               6300  1 snd_hda_codec
snd_pcm                75452  3 snd_hda_codec,snd_hda_intel
ac                      2536  0 
e1000e                218758  0 
snd_page_alloc          7298  2 snd_pcm,snd_hda_intel
snd_timer              18527  2 snd_pcm
tpm_tis                10921  0 
tpm                    14803  1 tpm_tis
ptp                     8324  1 e1000e
intel_agp              10936  0 
pps_core                8889  1 ptp
intel_gtt              12664  1 intel_agp
tpm_bios                9841  1 tpm
video                  11138  0 
button                  4669  0 
msr                     2565  0 
hdaps                   8711  2 
thinkpad_acpi          61597  1 
nvram                   5874  1 thinkpad_acpi
snd                    58765  15 snd_hwdep,snd_timer,snd_pcm,snd_hda_codec,snd_hda_intel,thinkpad_acpi,snd_hda_codec_analog
soundcore               5418  1 snd
rfkill                 15626  4 cfg80211,thinkpad_acpi
i2c_core               22351  3 drm,i2c_i801,nvidia
tp_smapi               20604  0 
thinkpad_ec             4189  2 hdaps,tp_smapi
phc_intel              14803  -1 
mperf                   1235  1 phc_intel
processor              27555  3 phc_intel
vboxdrv              1822305  3 vboxnetadp,vboxnetflt,vboxpci
cpufreq_conservative     4161  2 
ext4                  485284  3 
crc16                   1359  1 ext4
mbcache                 5930  1 ext4
jbd2                   85048  1 ext4
sd_mod                 30762  7 
ata_generic             3370  0 
pata_acpi               3387  0 
mmc_block              24471  0 
sdhci_pci              11379  0 
sdhci                  28462  1 sdhci_pci
ahci                   22696  3 
libahci                21201  1 ahci
ata_piix               24888  3 
libata                165870  5 ahci,pata_acpi,libahci,ata_generic,ata_piix
scsi_mod              129340  3 usb_storage,libata,sd_mod
mmc_core               94486  3 mmc_block,sdhci,sdhci_pci
firewire_ohci          31653  0 
firewire_core          52083  1 firewire_ohci
crc_itu_t               1363  3 udf,omfs,firewire_core
uhci_hcd               24243  0 
ehci_pci                4120  0 
ehci_hcd               46479  1 ehci_pci
usbcore               176899  5 uhci_hcd,usb_storage,ehci_hcd,ehci_pci,usbhid
usb_common               954  1 usbcore
             total       used       free     shared    buffers     cached
Mem:       4045736    2369992    1675744          0     152716     514944
-/+ buffers/cache:    1702332    2343404
Swap:      4095996    1315988    2780008

/usr/lib/pm-utils/sleep.d/00logging hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00phc-intel hibernate hibernate:

/usr/lib/pm-utils/sleep.d/00phc-intel hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00powersave hibernate hibernate:

/usr/lib/pm-utils/sleep.d/00powersave hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/01grub hibernate hibernate:

/usr/lib/pm-utils/sleep.d/01grub hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/48tlp-rdw-lock hibernate hibernate:

/usr/lib/pm-utils/sleep.d/48tlp-rdw-lock hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49bay hibernate hibernate:

/usr/lib/pm-utils/sleep.d/49bay hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49bluetooth hibernate hibernate:

/usr/lib/pm-utils/sleep.d/49bluetooth hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49wwan hibernate hibernate:

/usr/lib/pm-utils/sleep.d/49wwan hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/55wicd hibernate hibernate:

/usr/lib/pm-utils/sleep.d/55wicd hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/75modules hibernate hibernate:

/usr/lib/pm-utils/sleep.d/75modules hibernate hibernate: success.
Running hook /etc/pm/sleep.d/90alsa hibernate hibernate:

/etc/pm/sleep.d/90alsa hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/90clock hibernate hibernate:

/usr/lib/pm-utils/sleep.d/90clock hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/94cpufreq hibernate hibernate:

/usr/lib/pm-utils/sleep.d/94cpufreq hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/95led hibernate hibernate:

/usr/lib/pm-utils/sleep.d/95led hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/98video-quirk-db-handler hibernate hibernate:
nVidia binary video drive detected, not using quirks.

/usr/lib/pm-utils/sleep.d/98video-quirk-db-handler hibernate hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/99video hibernate hibernate:

/usr/lib/pm-utils/sleep.d/99video hibernate hibernate: success.
Running hook /etc/pm/sleep.d/wicd.sh hibernate hibernate:

/etc/pm/sleep.d/wicd.sh hibernate hibernate: success.
Thu  4 Jul 09:41:19 CEST 2013: performing hibernate
/usr/sbin/hibernate: 81: /usr/sbin/hibernate: /sbin/runlevel: not found
/usr/sbin/hibernate: 81: /usr/sbin/hibernate: /sbin/runlevel: not found
Thu  4 Jul 09:43:37 CEST 2013: Awake.
Thu  4 Jul 09:43:37 CEST 2013: Running hooks for thaw
Running hook /etc/pm/sleep.d/wicd.sh thaw hibernate:
/etc/pm/sleep.d/wicd.sh: line 4: /usr/lib/wicd/autoconnect.py: No such file or directory

/etc/pm/sleep.d/wicd.sh thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/99video thaw hibernate:

/usr/lib/pm-utils/sleep.d/99video thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/98video-quirk-db-handler thaw hibernate:

/usr/lib/pm-utils/sleep.d/98video-quirk-db-handler thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/95led thaw hibernate:

/usr/lib/pm-utils/sleep.d/95led thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/94cpufreq thaw hibernate:

/usr/lib/pm-utils/sleep.d/94cpufreq thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/90clock thaw hibernate:

/usr/lib/pm-utils/sleep.d/90clock thaw hibernate: success.
Running hook /etc/pm/sleep.d/90alsa thaw hibernate:
Playing raw data '/dev/zero' : Unsigned 8 bit, Rate 8000 Hz, Mono
Suspended. Trying resume. Done.

/etc/pm/sleep.d/90alsa thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/75modules thaw hibernate:
Reloaded unloaded modules.

/usr/lib/pm-utils/sleep.d/75modules thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/55wicd thaw hibernate:

/usr/lib/pm-utils/sleep.d/55wicd thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49wwan thaw hibernate:

/usr/lib/pm-utils/sleep.d/49wwan thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49bluetooth thaw hibernate:

/usr/lib/pm-utils/sleep.d/49bluetooth thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/49bay thaw hibernate:

/usr/lib/pm-utils/sleep.d/49bay thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/48tlp-rdw-lock thaw hibernate:

/usr/lib/pm-utils/sleep.d/48tlp-rdw-lock thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/01grub thaw hibernate:

/usr/lib/pm-utils/sleep.d/01grub thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00powersave thaw hibernate:

/usr/lib/pm-utils/sleep.d/00powersave thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00phc-intel thaw hibernate:
/usr/bin/phc-intel: line 11: echo: write error: Invalid argument
/usr/bin/phc-intel: line 11: echo: write error: Invalid argument

/usr/lib/pm-utils/sleep.d/00phc-intel thaw hibernate: success.
Running hook /usr/lib/pm-utils/sleep.d/00logging thaw hibernate:

/usr/lib/pm-utils/sleep.d/00logging thaw hibernate: success.
Running hook /etc/pm/sleep.d/00doit thaw hibernate:

/etc/pm/sleep.d/00doit thaw hibernate: success.
Thu  4 Jul 09:43:42 CEST 2013: Finished.

everything.log

Jul  4 09:41:12 panzor kernel: [107428.617590] EXT4-fs (sdb1): re-mounted. Opts: discard,commit=60,commit=0
Jul  4 09:41:12 panzor kernel: [107428.632471] EXT4-fs (sda1): re-mounted. Opts: commit=60,commit=0
Jul  4 09:41:12 panzor kernel: [107428.636738] EXT4-fs (sda2): re-mounted. Opts: commit=60,commit=0
Jul  4 09:41:13 panzor wicd[407]: dhcpcd[32707]: sending signal 1 to pid 26575
Jul  4 09:41:13 panzor dhcpcd[32707]: sending signal 1 to pid 26575
Jul  4 09:41:13 panzor dhcpcd[26575]: received SIGHUP, releasing
Jul  4 09:41:13 panzor dhcpcd[26575]: wlan0: releasing lease of 192.168.1.7
Jul  4 09:41:13 panzor dhcpcd[32707]: waiting for pid 26575 to exit
Jul  4 09:41:13 panzor wicd[407]: dhcpcd[32707]: waiting for pid 26575 to exit
Jul  4 09:41:13 panzor dhcpcd[26575]: wlan0: removing interface
Jul  4 09:41:13 panzor kernel: [107429.443568] wlan0: deauthenticating from d0:ae:ec:1a:0d:1c by local choice (reason=3)
Jul  4 09:41:13 panzor kernel: [107429.481131] cfg80211: Calling CRDA to update world regulatory domain
Jul  4 09:41:13 panzor kernel: [107429.732820] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  4 09:41:13 panzor wicd[407]: dhcpcd[32729]: dhcpcd not running
Jul  4 09:41:13 panzor dhcpcd[32729]: dhcpcd not running
Jul  4 09:41:14 panzor kernel: [107430.391538] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:41:14 panzor kernel: [107430.492739] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:41:14 panzor kernel: [107430.492893] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  4 09:41:14 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: eth0  error: No such file or directory
Jul  4 09:41:14 panzor wicd[407]: dhcpcd[32740]: dhcpcd not running
Jul  4 09:41:14 panzor dhcpcd[32740]: dhcpcd not running
Jul  4 09:41:14 panzor kernel: [107430.765923] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  4 09:41:15 panzor kernel: [107431.032495] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  4 09:41:15 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: wlan0  error: No such file or directory
Jul  4 09:41:15 panzor wicd[407]: dhcpcd[32746]: dhcpcd not running
Jul  4 09:41:15 panzor dhcpcd[32746]: dhcpcd not running
Jul  4 09:41:15 panzor kernel: [107431.711691] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:41:15 panzor kernel: [107431.812795] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:41:15 panzor kernel: [107431.812986] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  4 09:41:15 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: eth0  error: No such file or directory
Jul  4 09:41:20 panzor kernel: [107436.111021] TuxOnIce: No image found.
Jul  4 09:41:20 panzor kernel: [107436.157111] TuxOnIce 3.3, with support for usm, compression, block i/o, swap storage, file storage, userui.
Jul  4 09:41:20 panzor kernel: [107436.157245] Initiating a hibernation cycle.
Jul  4 09:41:20 panzor kernel: [107436.158679] Failed to launch userspace program '/usr/local/sbin/tuxoniceui_text': Error -2
Jul  4 09:41:20 panzor kernel: [107436.158681] Launch userspace program failed.
Jul  4 09:41:20 panzor kernel: [107436.177374] mmc0: card d555 removed
Jul  4 09:41:20 panzor kernel: [107436.179126] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
Jul  4 09:41:20 panzor kernel: [107436.180147] Starting other threads.
Jul  4 09:41:20 panzor kernel: [107436.180154] Freezing processes & syncing filesystems.
Jul  4 09:43:34 panzor kernel: [107436.199861] Freezing user space processes ... (elapsed 0.01 seconds) done.
Jul  4 09:43:34 panzor kernel: [107436.212685] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Jul  4 09:43:34 panzor kernel: [107436.360179] Preparing Image. Try 1.
Jul  4 09:43:34 panzor kernel: [107436.820915] Restarting kernel threads ... done.
Jul  4 09:43:34 panzor kernel: [107436.879612] Freezing remaining freezable tasks ... (elapsed 0.09 seconds) done.
Jul  4 09:43:34 panzor kernel: [107437.108371] Starting to save the image..
Jul  4 09:43:34 panzor kernel: [107437.127202] Writing caches...
Jul  4 09:43:34 panzor kernel: [107437.144607] Waited for i/o due to synchronous I/O 3 times.
Jul  4 09:43:34 panzor kernel: [107437.144610] Doing atomic copy/restore.
Jul  4 09:43:34 panzor kernel: [107437.162645] Suspending console(s) (use no_console_suspend to debug)
Jul  4 09:43:35 panzor kernel: [107437.184891] hdaps: setting ec_rate=0, filter_order=1
Jul  4 09:43:35 panzor kernel: [107437.436196] ------------[ cut here ]------------
Jul  4 09:43:35 panzor kernel: [107437.436204] WARNING: at kernel/irq/manage.c:1249 __free_irq+0xa3/0x1e0()
Jul  4 09:43:35 panzor kernel: [107437.436205] Hardware name: 8918DEG
Jul  4 09:43:35 panzor kernel: [107437.436206] Trying to free already-free IRQ 17
Jul  4 09:43:35 panzor kernel: [107437.436258] Modules linked in: dm_mod omfs jfs xfs crc32c libcrc32c reiserfs hfs hfsplus vfat fat isofs nls_utf8 udf usb_storage pci_stub vboxpci(O) vboxnetflt(O) vboxnetadp(O) vboxvideo(O) ipt_MASQUERADE xt_TCPMSS iptable_nat nf_nat_ipv4 nf_nat iptable_mangle ipt_REJECT xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_recent xt_conntrack nf_conntrack iptable_filter ip_tables x_tables hid_logitech_dj usbhid hid iTCO_wdt iTCO_vendor_support coretemp kvm_intel snd_hda_codec_analog kvm joydev fuse microcode psmouse serio_raw evdev i2c_i801 nvidia(PO) lpc_ich r852 sm_common nand nand_ecc nand_ids mtd r592 arc4 memstick iwl4965 iwlegacy mac80211 cfg80211 drm snd_hda_intel thermal wmi snd_hda_codec battery snd_hwdep snd_pcm ac e1000e snd_page_alloc snd_timer tpm_tis tpm ptp intel_agp pps_core intel_gtt tpm_bios video button msr hdaps(O) thinkpad_acpi nvram snd soundcore rfkill i2c_core tp_smapi(O) thinkpad_ec(O) phc_intel(O) mperf processor vboxdrv(O) cpufreq_conservative ext4 crc16 mbcache jbd2 sd_mod ata_generic pata_acpi mmc_block sdhci_pci sdhci ahci libahci ata_piix libata scsi_mod mmc_core firewire_ohci firewire_core crc_itu_t uhci_hcd ehci_pci ehci_hcd usbcore usb_common
Jul  4 09:43:35 panzor kernel: [107437.436284] Pid: 27443, comm: kworker/u:0 Tainted: P        W  O 3.9.4-pf-ARCH #1
Jul  4 09:43:35 panzor kernel: [107437.436285] Call Trace:
Jul  4 09:43:35 panzor kernel: [107437.436291]  [<ffffffff81056ac0>] warn_slowpath_common+0x70/0xa0
Jul  4 09:43:35 panzor kernel: [107437.436293]  [<ffffffff81056b3c>] warn_slowpath_fmt+0x4c/0x50
Jul  4 09:43:35 panzor kernel: [107437.436297]  [<ffffffff81087d74>] ? try_to_wake_up+0x1e4/0x1f0
Jul  4 09:43:35 panzor kernel: [107437.436299]  [<ffffffff810dda13>] __free_irq+0xa3/0x1e0
Jul  4 09:43:35 panzor kernel: [107437.436301]  [<ffffffff810ddbe9>] free_irq+0x49/0xb0
Jul  4 09:43:35 panzor kernel: [107437.436310]  [<ffffffffa0152c8e>] pci_suspend+0x3e/0xc0 [firewire_ohci]
Jul  4 09:43:35 panzor kernel: [107437.436316]  [<ffffffff812a0608>] pci_legacy_suspend+0x38/0xc0
Jul  4 09:43:35 panzor kernel: [107437.436318]  [<ffffffff812a18b0>] ? pci_pm_poweroff+0xd0/0xd0
Jul  4 09:43:35 panzor kernel: [107437.436320]  [<ffffffff812a195d>] pci_pm_freeze+0xad/0xc0
Jul  4 09:43:35 panzor kernel: [107437.436324]  [<ffffffff81360db4>] dpm_run_callback+0x44/0x90
Jul  4 09:43:35 panzor kernel: [107437.436326]  [<ffffffff8136222b>] __device_suspend+0xdb/0x270
Jul  4 09:43:35 panzor kernel: [107437.436328]  [<ffffffff8136260f>] async_suspend+0x1f/0xa0
Jul  4 09:43:36 panzor kernel: [107437.436331]  [<ffffffff81080a27>] async_run_entry_fn+0x37/0x130
Jul  4 09:43:36 panzor kernel: [107437.436334]  [<ffffffff81074730>] process_one_work+0x170/0x440
Jul  4 09:43:36 panzor kernel: [107437.436336]  [<ffffffff81075205>] worker_thread+0x115/0x3d0
Jul  4 09:43:36 panzor kernel: [107437.436338]  [<ffffffff810750f0>] ? manage_workers+0x340/0x340
Jul  4 09:43:36 panzor kernel: [107437.436340]  [<ffffffff81079d90>] kthread+0xc0/0xd0
Jul  4 09:43:36 panzor kernel: [107437.436342]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jul  4 09:43:36 panzor kernel: [107437.436346]  [<ffffffff814ca9ec>] ret_from_fork+0x7c/0xb0
Jul  4 09:43:36 panzor kernel: [107437.436348]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jul  4 09:43:36 panzor kernel: [107437.436349] ---[ end trace 06dce76c865570d4 ]---
Jul  4 09:43:36 panzor kernel: [107437.673704] PM: freeze of devices complete after 511.051 msecs
Jul  4 09:43:36 panzor kernel: [107437.674091] PM: late freeze of devices complete after 0.384 msecs
Jul  4 09:43:36 panzor kernel: [107437.675046] PM: noirq freeze of devices complete after 0.952 msecs
Jul  4 09:43:36 panzor kernel: [107437.675436] ACPI: Preparing to enter system sleep state S4
Jul  4 09:43:36 panzor kernel: [107437.679187] PM: Saving platform NVS memory
Jul  4 09:43:36 panzor kernel: [107437.679490] Disabling non-boot CPUs ...
Jul  4 09:43:36 panzor kernel: [107437.782608] smpboot: CPU 1 is now offline
Jul  4 09:43:36 panzor kernel: [107437.782897] PM: Restoring platform NVS memory
Jul  4 09:43:36 panzor kernel: [107437.782897] Enabling non-boot CPUs ...
Jul  4 09:43:36 panzor kernel: [107437.782897] smpboot: Booting Node 0 Processor 1 APIC 0x1
Jul  4 09:43:36 panzor kernel: [107437.819361] CPU1 is up
Jul  4 09:43:36 panzor kernel: [107437.821349] ACPI: Waking up from system sleep state S4
Jul  4 09:43:36 panzor kernel: [107437.849972] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.850031] ehci-pci 0000:00:1a.7: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.863085] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.863194] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.863252] ehci-pci 0000:00:1d.7: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.863572] nvidia 0000:01:00.0: power state changed by ACPI to D0
Jul  4 09:43:36 panzor kernel: [107437.876414] PM: noirq restore of devices complete after 26.673 msecs
Jul  4 09:43:36 panzor kernel: [107437.876604] PM: early restore of devices complete after 0.148 msecs
Jul  4 09:43:36 panzor kernel: [107437.876653] e1000e 0000:00:19.0: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.876655] uhci_hcd 0000:00:1a.0: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.876686] usb usb2: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.876702] uhci_hcd 0000:00:1a.1: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.876729] usb usb4: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.876733] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:43:36 panzor kernel: [107437.876743] ehci-pci 0000:00:1a.7: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.876758] usb usb1: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.879293] uhci_hcd 0000:00:1d.0: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879298] uhci_hcd 0000:00:1d.1: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879321] usb usb5: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.879325] usb usb6: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.879335] uhci_hcd 0000:00:1d.2: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879344] ehci-pci 0000:00:1d.7: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879360] usb usb7: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.879374] pci 0000:00:1e.0: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879376] usb usb3: root hub lost power or was reset
Jul  4 09:43:36 panzor kernel: [107437.879407] ahci 0000:00:1f.2: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.879796] iwl4965 0000:03:00.0: RF_KILL bit toggled to enable radio.
Jul  4 09:43:36 panzor kernel: [107437.879799] firewire_ohci 0000:15:00.1: failed to reset ohci card
Jul  4 09:43:36 panzor kernel: [107437.879806] dpm_run_callback(): pci_pm_restore+0x0/0xb0 returns -16
Jul  4 09:43:36 panzor kernel: [107437.879807] PM: Device 0000:15:00.1 failed to restore async: error -16
Jul  4 09:43:36 panzor kernel: [107437.882646] ata_piix 0000:00:1f.1: setting latency timer to 64
Jul  4 09:43:36 panzor kernel: [107437.882713] snd_hda_intel 0000:00:1b.0: irq 48 for MSI/MSI-X
Jul  4 09:43:36 panzor kernel: [107437.886255] ehci-pci 0000:00:1a.7: cache line size of 64 is not supported
Jul  4 09:43:36 panzor kernel: [107437.886761] ehci-pci 0000:00:1d.7: cache line size of 64 is not supported
Jul  4 09:43:36 panzor kernel: [107437.891491] ata2: port disabled--ignoring
Jul  4 09:43:36 panzor kernel: [107438.773231] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jul  4 09:43:36 panzor kernel: [107438.773234] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jul  4 09:43:36 panzor kernel: [107438.773236] ata1.00: ACPI cmd ef/03:45:00:00:00:a0 (SET FEATURES) filtered out
Jul  4 09:43:36 panzor kernel: [107438.773237] ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
Jul  4 09:43:36 panzor kernel: [107438.793235] ata1.00: configured for UDMA/100
Jul  4 09:43:36 panzor kernel: [107438.796123] tpm_tis 00:09: TPM is disabled/deactivated (0x6)
Jul  4 09:43:36 panzor kernel: [107438.805981] sd 0:0:0:0: [sda] Starting disk
Jul  4 09:43:36 panzor kernel: [107438.875999] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Jul  4 09:43:36 panzor kernel: [107438.876615] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jul  4 09:43:36 panzor kernel: [107438.876617] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jul  4 09:43:36 panzor kernel: [107438.876619] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
Jul  4 09:43:36 panzor kernel: [107438.877132] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jul  4 09:43:36 panzor kernel: [107438.877134] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jul  4 09:43:36 panzor kernel: [107438.877136] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
Jul  4 09:43:36 panzor kernel: [107438.877356] ata3.00: configured for UDMA/133
Jul  4 09:43:36 panzor kernel: [107438.889311] sd 2:0:0:0: [sdb] Starting disk
Jul  4 09:43:36 panzor kernel: [107438.995972] smapi smapi: set_real_thresh: set stop to 0 for bat=0
Jul  4 09:43:36 panzor kernel: [107439.079321] usb 2-2: reset full-speed USB device number 3 using uhci_hcd
Jul  4 09:43:36 panzor kernel: [107439.102638] smapi smapi: set_real_thresh: set start to 74 for bat=0
Jul  4 09:43:36 panzor kernel: [107439.209274] smapi smapi: set_real_thresh: set stop to 0 for bat=1
Jul  4 09:43:36 panzor kernel: [107439.312651] usb 5-1: reset full-speed USB device number 2 using uhci_hcd
Jul  4 09:43:36 panzor kernel: [107439.315933] smapi smapi: set_real_thresh: set start to 0 for bat=1
Jul  4 09:43:36 panzor kernel: [107439.316415] thinkpad_acpi: ACPI backlight control delay disabled
Jul  4 09:43:36 panzor kernel: [107439.317543] hdaps: initial mode latch is 0x05
Jul  4 09:43:36 panzor kernel: [107439.317714] hdaps: setting ec_rate=250, filter_order=2
Jul  4 09:43:36 panzor kernel: [107528.538017] PM: restore of devices complete after 90661.408 msecs
Jul  4 09:43:36 panzor kernel: [107528.549705] Post atomic.
Jul  4 09:43:36 panzor kernel: [107528.567054] Cleaning up...
Jul  4 09:43:36 panzor kernel: [107528.697441] Restarting tasks ... done.
Jul  4 09:43:36 panzor kernel: [107528.963867] video LNXVIDEO:01: Restoring backlight state
Jul  4 09:43:36 panzor kernel: [107528.967031] TuxOnIce debugging info:
Jul  4 09:43:36 panzor kernel: [107528.967031] - TuxOnIce core  : 3.3
Jul  4 09:43:36 panzor kernel: [107528.967031] - Kernel Version : 3.9.4-pf-ARCH
Jul  4 09:43:36 panzor kernel: [107528.967031] - Compiler vers. : 4.8
Jul  4 09:43:36 panzor kernel: [107528.967031] - Attempt number : 10
Jul  4 09:43:36 panzor kernel: [107528.967031] - Parameters     : 0 700424 0 1 -2 5
Jul  4 09:43:36 panzor kernel: [107528.967031] - Overall expected compression percentage: 0.
Jul  4 09:43:36 panzor kernel: [107528.967031] - Compressor is 'lzo'.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Compressed 2066800640 bytes into 755753507 (63 percent compression).
Jul  4 09:43:36 panzor kernel: [107528.967031] - Block I/O active.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Used 186542 pages from swap on /dev/sdb2.
Jul  4 09:43:36 panzor kernel: [107528.967031] - Max outstanding reads 1. Max writes 0.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Memory_needed: 1024 x (4096 + 368 + 120) = 4694016 bytes.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Free mem throttle point reached 0.
Jul  4 09:43:36 panzor kernel: [107528.967031] - Swap Allocator enabled.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Swap available for image: 678783 pages.
Jul  4 09:43:36 panzor kernel: [107528.967031] - File Allocator active.
Jul  4 09:43:36 panzor kernel: [107528.967031]   Storage available for image: 0 pages.
Jul  4 09:43:36 panzor kernel: [107528.967058] Pid: 938, comm: dash Tainted: P        W  O 3.9.4-pf-ARCH #1
Jul  4 09:43:36 panzor kernel: [107528.967060] Call Trace:
Jul  4 09:43:36 panzor kernel: [107528.967072]  [<ffffffff8108d660>] free_update_stats+0x80/0x90
Jul  4 09:43:36 panzor kernel: [107528.967075]  [<ffffffff8108d71a>] toi_free_page+0x4a/0x60
Jul  4 09:43:36 panzor kernel: [107528.967080]  [<ffffffff8109c6a5>] forget_signature_page+0x45/0xe0
Jul  4 09:43:36 panzor kernel: [107528.967083]  [<ffffffff81099c03>] toi_bio_cleanup+0x33/0x70
Jul  4 09:43:36 panzor kernel: [107528.967086]  [<ffffffff8108d039>] toi_cleanup_modules+0x49/0x70
Jul  4 09:43:36 panzor kernel: [107528.967089]  [<ffffffff8108f2c1>] toi_finish_anything+0x11/0x90
Jul  4 09:43:36 panzor kernel: [107528.967092]  [<ffffffff8108db8e>] toi_attr_store+0x11e/0x2f0
Jul  4 09:43:36 panzor kernel: [107528.967098]  [<ffffffff811f9fc6>] sysfs_write_file+0xc6/0x140
Jul  4 09:43:36 panzor kernel: [107528.967102]  [<ffffffff811893cb>] vfs_write+0x9b/0x170
Jul  4 09:43:36 panzor kernel: [107528.967105]  [<ffffffff811896c9>] sys_write+0x49/0xa0
Jul  4 09:43:36 panzor kernel: [107528.967110]  [<ffffffff814caa9d>] system_call_fastpath+0x1a/0x1f
Jul  4 09:43:36 panzor kernel: [107528.967114] Idx  Allocs   Frees   Tests   Fails     Max Description
Jul  4 09:43:36 panzor kernel: [107528.967116]  38       0       1       0       0       0 setting swap signature
Jul  4 09:43:36 panzor kernel: [107529.039696] mmc0: new high speed SDHC card at address d555
Jul  4 09:43:36 panzor kernel: [107529.039868] mmcblk0: mmc0:d555 SD04G 3.79 GiB 
Jul  4 09:43:36 panzor kernel: [107529.041058]  mmcblk0: p1
Jul  4 09:43:34 panzor acpid: client 1243[0:100] has disconnected
Jul  4 09:43:35 panzor dnsmasq[24648]: reading /etc/resolv.conf
Jul  4 09:43:36 panzor dnsmasq[24648]: using nameserver 208.67.222.222#53
Jul  4 09:43:36 panzor dnsmasq[24648]: using nameserver 8.8.8.8#53
Jul  4 09:43:36 panzor dnsmasq[24648]: ignoring nameserver 127.0.0.1 - local interface
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:00
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:01
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: thermal_zone / LNXTHERM:00
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:00
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:01
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:00
Jul  4 09:43:36 panzor logger: ACPI group/action undefined: processor / LNXCPU:01
Jul  4 09:43:34 panzor systemd[1]: Time has been changed
Jul  4 09:43:37 panzor systemd[1]: Time has been changed
Jul  4 09:43:39 panzor acpid: client connected from 1243[0:100]
Jul  4 09:43:39 panzor acpid: 1 client rule loaded
Jul  4 09:43:40 panzor kernel: [107534.363070] EXT4-fs (sdb1): re-mounted. Opts: discard,commit=60,commit=0
Jul  4 09:43:40 panzor kernel: [107534.375026] EXT4-fs (sda1): re-mounted. Opts: commit=60,commit=0
Jul  4 09:43:40 panzor kernel: [107534.378198] EXT4-fs (sda2): re-mounted. Opts: commit=60,commit=0
Jul  4 09:43:42 panzor kernel: [107535.565588] skipping vid at 0, 75 is greater than default 39
Jul  4 09:43:42 panzor kernel: [107535.565594] failed to parse vid value at 1 (:23 74:0 8:0 6:0 136:0
Jul  4 09:43:42 panzor kernel: [107535.565594] )
Jul  4 09:43:42 panzor kernel: [107535.565860] skipping vid at 0, 75 is greater than default 39
Jul  4 09:43:42 panzor kernel: [107535.565863] failed to parse vid value at 1 (:23 74:0 8:0 6:0 136:0
Jul  4 09:43:42 panzor kernel: [107535.565863] )
Jul  4 09:43:43 panzor wicd[407]: dhcpcd[1465]: dhcpcd not running
Jul  4 09:43:43 panzor dhcpcd[1465]: dhcpcd not running
Jul  4 09:43:43 panzor kernel: [107536.834625] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  4 09:43:43 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: wlan0  error: No such file or directory
Jul  4 09:43:43 panzor wicd[407]: dhcpcd[1471]: dhcpcd not running
Jul  4 09:43:43 panzor dhcpcd[1471]: dhcpcd not running
Jul  4 09:43:43 panzor kernel: [107537.475811] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:43:44 panzor kernel: [107537.576068] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jul  4 09:43:44 panzor kernel: [107537.576217] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  4 09:43:44 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: eth0  error: No such file or directory
Jul  4 09:43:44 panzor wicd[407]: dhcpcd[1483]: dhcpcd not running
Jul  4 09:43:44 panzor dhcpcd[1483]: dhcpcd not running
Jul  4 09:43:44 panzor kernel: [107537.872817] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  4 09:43:44 panzor wicd[407]: Failed to connect to non-global ctrl_ifname: wlan0  error: No such file or directory
Jul  4 09:43:46 panzor kernel: [107540.055454] wlan0: authenticate with d0:ae:ec:1a:0d:1c
Jul  4 09:43:46 panzor kernel: [107540.055509] wlan0: send auth to d0:ae:ec:1a:0d:1c (try 1/3)
Jul  4 09:43:46 panzor kernel: [107540.057998] wlan0: authenticated
Jul  4 09:43:46 panzor kernel: [107540.059562] wlan0: associate with d0:ae:ec:1a:0d:1c (try 1/3)
Jul  4 09:43:46 panzor kernel: [107540.062915] wlan0: RX AssocResp from d0:ae:ec:1a:0d:1c (capab=0x431 status=0 aid=2)
Jul  4 09:43:46 panzor kernel: [107540.098202] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Jul  4 09:43:46 panzor kernel: [107540.098393] wlan0: associated
Jul  4 09:43:48 panzor dhcpcd[1512]: version 5.6.8 starting
Jul  4 09:43:48 panzor dhcpcd[1512]: wlan0: sending IPv6 Router Solicitation
Jul  4 09:43:48 panzor dhcpcd[1512]: wlan0: broadcasting for a lease
Jul  4 09:43:48 panzor dhcpcd[1512]: wlan0: offered 192.168.1.7 from 192.168.1.1
Jul  4 09:43:49 panzor dhcpcd[1512]: wlan0: acknowledged 192.168.1.7 from 192.168.1.1
Jul  4 09:43:50 panzor dhcpcd[1512]: wlan0: checking for 192.168.1.7
Jul  4 09:43:52 panzor dhcpcd[1512]: wlan0: sending IPv6 Router Solicitation
Jul  4 09:43:54 panzor dhcpcd[1512]: wlan0: leased 192.168.1.7 for 86400 seconds
Jul  4 09:43:54 panzor dhcpcd[1512]: forked to background, child pid 1563
Jul  4 09:43:56 panzor dhcpcd[1563]: wlan0: sending IPv6 Router Solicitation
Jul  4 09:43:57 panzor dnsmasq[24648]: reading /etc/resolv.conf
Jul  4 09:43:57 panzor dnsmasq[24648]: using nameserver 192.168.1.1#53
Jul  4 09:43:57 panzor dnsmasq[24648]: using nameserver 208.67.222.222#53
Jul  4 09:43:57 panzor dnsmasq[24648]: using nameserver 8.8.8.8#53
Jul  4 09:43:57 panzor dnsmasq[24648]: ignoring nameserver 127.0.0.1 - local interface

This entire process makes the resume from hibernation take about 2 minutes, while it should be no longer than ~10 seconds.
Can you see anything in those logs that could be causing it?

Desclaimer:
Resume from hibernation with TuxOnIce does take ~10 seconds, but I cannot use it because with it my screen remains off even though system is well resumed.
So please do not recommend me alternative hibernation methods, because they all have one of those two results, and those that stall at least render the laptop usable after resume.

cfr

Member

From: Cymru

Registered: 2011-11-27

Posts: 7,137

Re: pm-hibernate stalls trice upon resume

/etc/pm/sleep.d/90alsa seems to be playing something. Could that be it?

EDIT: Also note the errors from /usr/lib/pm-utils/sleep.d/00phc-intel and /etc/pm/sleep.d/wicd.sh. They don't seem to be playing anything, mind.

Last edited by cfr (2013-07-07 02:33:01)

---

CLI Paste | How To Ask Questions

Arch Linux | x86_64 | GPT | EFI boot | refind | stub loader | systemd | LVM2 on LUKS
Lenovo x270 | Intel(R) Core(TM) i5-7200U CPU @ 2.50GHz | Intel Wireless 8265/8275 | US keyboard w/ Euro | 512G NVMe INTEL SSDPEKKF512G7L

Lockheed

Member

Registered: 2010-03-16

Posts: 1,521

Re: pm-hibernate stalls trice upon resume

Thank you for the suggestions.

I got rid of all those scripts you mentioned, but it changed nothing.

cfr

Member

From: Cymru

Registered: 2011-11-27

Posts: 7,137

Re: pm-hibernate stalls trice upon resume

Are you using systemctl to hibernate? If not, does doing it that way make any difference?

---

CLI Paste | How To Ask Questions

Arch Linux | x86_64 | GPT | EFI boot | refind | stub loader | systemd | LVM2 on LUKS
Lenovo x270 | Intel(R) Core(TM) i5-7200U CPU @ 2.50GHz | Intel Wireless 8265/8275 | US keyboard w/ Euro | 512G NVMe INTEL SSDPEKKF512G7L

Lockheed

Member

Registered: 2010-03-16

Posts: 1,521

Re: pm-hibernate stalls trice upon resume

No and no.
I mean I could use it as TuxOnIce, and then this problem disappears, but instead I am losing the screen.

Last edited by Lockheed (2013-07-07 14:32:30)

WonderWoofy

Member

From: Los Gatos, CA

Registered: 2012-05-19

Posts: 8,414

Re: pm-hibernate stalls trice upon resume

In my experience, hibernation either works fine on your particular hardware and it is easy to set up, or it is just a total shit hole of buggy-ness.  It is very hardware dependent, and there is really no telling what you are going to get.  So just because hibernation works on one machine, does not meant that when you set up Linux on another machine you will be able to figure it out.

Recently, a friend told me that while trying to fix his btrfs filesystem, a btrfs dev told him to stop using hibernation because on Linux it is pretty much "pre-alpha" quality that is only included because it does happen to work on some machines.  This to me seems like a pretty good assessment. 

So Lockheed, I think you are trying to fight a battle this is a) to me, not worth fighting, but more importantly, b) a battle that might not be solvable without actually hacking on (and vastly improving) the underlying code that implements it.

cfr

Member

From: Cymru

Registered: 2011-11-27

Posts: 7,137

Re: pm-hibernate stalls trice upon resume

Why does everything.log include debugging info for TuxOnIce if you are not using it? Is that normal?

I don't really use hibernation, I have to say. I set it up and it worked but it didn't seem any quicker than just booting so I basically just use sleep which works fine and resumes within moments. The older laptop I have Linux on, on the other hand, just does not resume from hibernation correctly. It resumes but the backlight doesn't come back and there is no way to adjust it except by rebooting. (Then again, that machine can't sleep with Linux either.)

Is just sleeping an option rather than hibernating?

---

CLI Paste | How To Ask Questions

Arch Linux | x86_64 | GPT | EFI boot | refind | stub loader | systemd | LVM2 on LUKS
Lenovo x270 | Intel(R) Core(TM) i5-7200U CPU @ 2.50GHz | Intel Wireless 8265/8275 | US keyboard w/ Euro | 512G NVMe INTEL SSDPEKKF512G7L

Lockheed

Member

Registered: 2010-03-16

Posts: 1,521

Re: pm-hibernate stalls trice upon resume

Yeah, I was afraid it was unsolvable. But I still don't quite understand how is it that on the same hardware windows hibernation works so well, but linux doesn't.

@cfr, yes, I usually use suspend, but it still drains some battery and is not an option to use for emergency suspend when your battery reaches 3%.
Also, suspend is much easier to wake by accident. Happened several times when my ThinkPad was in a backpack. Nearly fried it.

Powering off works fast, because I have a fast SSD. But that's not the problem. The problem is I have to save all my work before shutting down, and then manually restore it next time I boot.

Last edited by Lockheed (2013-07-07 16:56:39)

WonderWoofy

Member

From: Los Gatos, CA

Registered: 2012-05-19

Posts: 8,414

Re: pm-hibernate stalls trice upon resume

Yeah, I was afraid it was unsolvable. But I still don't quite understand how is it that on the same hardware windows hibernation works so well, but linux doesn't.

Really?  Do you really think that windows' ability to handle hibernate has anything whatsoever to do with Linux's ability to hibernate? That is a horrible bit or reasoning...

@cfr, yes, I usually use suspend, but it still drains some battery and is not an option to use for emergency suspend when your battery reaches 3%.
Also, suspend is much easier to wake by accident. Happened several times when my ThinkPad was in a backpack. Nearly fried it.

So I fail to understand why you don't just set the "emergency suspend" to something higher than 3%?  Wouldn't that be a whole hell of a lot easier than trying to make old unnecessary and unmaintained software work (which is really just a collection of hacks/workarounds).

I highly doubt that you "nearly fried" your computer.  Computers have temperature sensors, and trip points at which they will shut off.  There is one in the kernel itself that will start a normal shutdown procedure and there is one in the firmware that will just hard shutdown the system at a slightly higher level.  Both of these temperatures are levels that are set by the manufacturer of the hardware which is designed to avoid damage.  I am a bit confused as to how you managed to have your laptop wake in your backpack anyway.  If the lid is closed, the keys shouldn't be pressed, and if the keys are being pressed, you are putting unsafe amounts of strain on a screen.  So if that is the case you should probably find a different method of carrying your laptop.  But besides all that, you can also just fine tune what methods the computer will accept to wake the machine.

Powering off works fast, because I have a fast SSD. But that's not the problem. The problem is I have to save all my work before shutting down, and then manually restore it next time I boot.

I think there are software solutions for this as well.  In fact some of the big DEs already do this.  But there is also one small project with the goal of being a stand alone implementation of this. But really, I think if you just did the reasonable thing of setting your "emergency suspend" to something more sane, you wouldn't really have this problem.