Screen remains OFF after resume from hibernation

Lockheed · 2013-02-13 10:17:43

$ systemctl hibernate

Upon resume from hibernation, everything works fine except the screen.

It starts either black, or with a scrambled colourful 2mm wide line running across it's blackness, or scrambled completely (filled with such lines).

I try to switch to another console with ctrl+f2, which results with entirely black screen. Then I try to go back, but blackness never subsides.

I am running:
- Nvidia proprietary drivers (nouveau not an option due to poor power management) and TuxOnIce.
- openbox
- systemctl suspend resumes perfectly fine

Does someone know how to fix that?

Update:
That's everything.log from the moment of hibernation, until the moment of hard-shutdown induced by holding the power key after resume to black screen:

Jun 23 13:30:13 panzor wicd[467]: Failed to connect to non-global ctrl_ifname: eth0  error: No such file or directory
Jun 23 13:30:13 panzor systemd[1]: Started Wicd sleep hook.
Jun 23 13:30:13 panzor systemd[1]: Starting Sleep.
Jun 23 13:30:13 panzor systemd[1]: Reached target Sleep.
Jun 23 13:30:13 panzor systemd[1]: Starting Hibernate...
Jun 23 13:30:13 panzor kernel: [54391.410811] PM: Hibernation mode set to 'platform'
Jun 23 13:30:13 panzor systemd-sleep[11837]: Going to hibernate...
Jun 23 13:30:13 panzor systemd-sleep[11837]: Suspending system...
Jun 23 13:30:13 panzor kernel: [54391.444759] Initiating a hibernation cycle.
Jun 23 13:30:13 panzor kernel: [54391.448037] Failed to launch userspace program '/usr/local/sbin/tuxoniceui_text': Error -2
Jun 23 13:30:13 panzor kernel: [54391.448044] Launch userspace program failed.
Jun 23 13:30:13 panzor kernel: [54391.448782] mmc0: card d555 removed
Jun 23 13:30:13 panzor kernel: [54391.453512] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
Jun 23 13:30:13 panzor kernel: [54391.454544] Starting other threads.
Jun 23 13:30:13 panzor kernel: [54391.454635] Freezing processes & syncing filesystems.
Jun 23 13:30:56 panzor kernel: [54391.454641] Freezing user space processes ... (elapsed 0.01 seconds) done.
Jun 23 13:30:56 panzor kernel: [54391.468045] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Jun 23 13:30:56 panzor kernel: [54391.836805] Preparing Image. Try 1.
Jun 23 13:30:56 panzor kernel: [54393.084855] Restarting kernel threads ... done.
Jun 23 13:30:56 panzor kernel: [54393.128415] kworker/u:1: page allocation failure: order:1, mode:0x40d0
Jun 23 13:30:56 panzor kernel: [54393.128428] Pid: 8108, comm: kworker/u:1 Tainted: P           O 3.9.4-pf-ARCH #1
Jun 23 13:30:56 panzor kernel: [54393.128432] Call Trace:
Jun 23 13:30:56 panzor kernel: [54393.128450]  [<ffffffff81125c51>] warn_alloc_failed+0xe1/0x130
Jun 23 13:30:56 panzor kernel: [54393.128460]  [<ffffffff811297a1>] __alloc_pages_nodemask+0x7d1/0x9f0
Jun 23 13:30:56 panzor kernel: [54393.128490]  [<ffffffffa072ee9b>] il4965_rx_allocate+0x12b/0x2d0 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.128504]  [<ffffffffa07325db>] il4965_rx_replenish+0x1b/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.128517]  [<ffffffffa073264e>] il4965_bg_rx_replenish+0x3e/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.128527]  [<ffffffff81074730>] process_one_work+0x170/0x440
Jun 23 13:30:56 panzor kernel: [54393.128535]  [<ffffffff81075205>] worker_thread+0x115/0x3d0
Jun 23 13:30:56 panzor kernel: [54393.128543]  [<ffffffff810750f0>] ? manage_workers+0x340/0x340
Jun 23 13:30:56 panzor kernel: [54393.128551]  [<ffffffff81079d90>] kthread+0xc0/0xd0
Jun 23 13:30:56 panzor kernel: [54393.128558]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.128568]  [<ffffffff814ca9ec>] ret_from_fork+0x7c/0xb0
Jun 23 13:30:56 panzor kernel: [54393.128576]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.128580] Mem-Info:
Jun 23 13:30:56 panzor kernel: [54393.128585] DMA per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.128591] CPU    0: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.128596] CPU    1: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.128600] DMA32 per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.128605] CPU    0: hi:  186, btch:  31 usd: 177
Jun 23 13:30:56 panzor kernel: [54393.128610] CPU    1: hi:  186, btch:  31 usd: 172
Jun 23 13:30:56 panzor kernel: [54393.128614] Normal per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.128618] CPU    0: hi:  186, btch:  31 usd: 181
Jun 23 13:30:56 panzor kernel: [54393.128623] CPU    1: hi:  186, btch:  31 usd: 156
Jun 23 13:30:56 panzor kernel: [54393.128635] active_anon:140127 inactive_anon:221775 isolated_anon:0
Jun 23 13:30:56 panzor kernel: [54393.128635]  active_file:16953 inactive_file:8420 isolated_file:32
Jun 23 13:30:56 panzor kernel: [54393.128635]  unevictable:0 dirty:81 writeback:0 unstable:0
Jun 23 13:30:56 panzor kernel: [54393.128635]  free:6220 slab_reclaimable:38788 slab_unreclaimable:20911
Jun 23 13:30:56 panzor kernel: [54393.128635]  mapped:30620 shmem:106569 pagetables:7596 bounce:0
Jun 23 13:30:56 panzor kernel: [54393.128635]  free_cma:0
Jun 23 13:30:56 panzor kernel: [54393.128657] DMA free:28kB min:264kB low:328kB high:396kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun 23 13:30:56 panzor kernel: [54393.128662] lowmem_reserve[]: 0 2967 3920 3920
Jun 23 13:30:56 panzor kernel: [54393.128684] DMA32 free:24844kB min:50948kB low:63684kB high:76420kB active_anon:420312kB inactive_anon:557136kB active_file:30108kB inactive_file:23668kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:3128000kB managed:3038408kB mlocked:0kB dirty:204kB writeback:0kB mapped:72728kB shmem:206304kB slab_reclaimable:124972kB slab_unreclaimable:36492kB kernel_stack:936kB pagetables:20540kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.128689] lowmem_reserve[]: 0 0 953 953
Jun 23 13:30:56 panzor kernel: [54393.128709] Normal free:108kB min:16364kB low:20452kB high:24544kB active_anon:140196kB inactive_anon:329964kB active_file:37576kB inactive_file:10012kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1048576kB managed:975928kB mlocked:0kB dirty:120kB writeback:0kB mapped:49752kB shmem:219972kB slab_reclaimable:30180kB slab_unreclaimable:47152kB kernel_stack:1352kB pagetables:9844kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.128714] lowmem_reserve[]: 0 0 0 0
Jun 23 13:30:56 panzor kernel: [54393.128723] DMA: 1*4kB (U) 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4kB
Jun 23 13:30:56 panzor kernel: [54393.128747] DMA32: 5175*4kB (UEM) 507*8kB (UEM) 13*16kB (UE) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 24964kB
Jun 23 13:30:56 panzor kernel: [54393.128774] Normal: 31*4kB (UEM) 5*8kB (U) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 164kB
Jun 23 13:30:56 panzor kernel: [54393.128799] 142600 total pagecache pages
Jun 23 13:30:56 panzor kernel: [54393.128804] 10735 pages in swap cache
Jun 23 13:30:56 panzor kernel: [54393.128810] Swap cache stats: add 43083, delete 32348, find 1318922/1319418
Jun 23 13:30:56 panzor kernel: [54393.128814] Free swap  = 1853560kB
Jun 23 13:30:56 panzor kernel: [54393.128818] Total swap = 4095996kB
Jun 23 13:30:56 panzor kernel: [54393.168573] 1048575 pages RAM
Jun 23 13:30:56 panzor kernel: [54393.168580] 39962 pages reserved
Jun 23 13:30:56 panzor kernel: [54393.168583] 617439 pages shared
Jun 23 13:30:56 panzor kernel: [54393.168587] 618288 pages non-shared
Jun 23 13:30:56 panzor kernel: [54393.168602] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 1 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54393.168618] kworker/u:1: page allocation failure: order:1, mode:0x40d0
Jun 23 13:30:56 panzor kernel: [54393.168625] Pid: 8108, comm: kworker/u:1 Tainted: P           O 3.9.4-pf-ARCH #1
Jun 23 13:30:56 panzor kernel: [54393.168630] Call Trace:
Jun 23 13:30:56 panzor kernel: [54393.156392] Freezing remaining freezable tasks ... 
Jun 23 13:30:56 panzor kernel: [54393.168636]  [<ffffffff81125c51>] warn_alloc_failed+0xe1/0x130
Jun 23 13:30:56 panzor kernel: [54393.168656]  [<ffffffff811297a1>] __alloc_pages_nodemask+0x7d1/0x9f0
Jun 23 13:30:56 panzor kernel: [54393.168685]  [<ffffffffa072ee9b>] il4965_rx_allocate+0x12b/0x2d0 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.168699]  [<ffffffffa07325db>] il4965_rx_replenish+0x1b/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.168712]  [<ffffffffa073264e>] il4965_bg_rx_replenish+0x3e/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.168722]  [<ffffffff81074730>] process_one_work+0x170/0x440
Jun 23 13:30:56 panzor kernel: [54393.168730]  [<ffffffff81075205>] worker_thread+0x115/0x3d0
Jun 23 13:30:56 panzor kernel: [54393.168738]  [<ffffffff810750f0>] ? manage_workers+0x340/0x340
Jun 23 13:30:56 panzor kernel: [54393.168745]  [<ffffffff81079d90>] kthread+0xc0/0xd0
Jun 23 13:30:56 panzor kernel: [54393.168753]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.168763]  [<ffffffff814ca9ec>] ret_from_fork+0x7c/0xb0
Jun 23 13:30:56 panzor kernel: [54393.168770]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.168774] Mem-Info:
Jun 23 13:30:56 panzor kernel: [54393.168778] DMA per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.168784] CPU    0: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.168789] CPU    1: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.168793] DMA32 per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.168798] CPU    0: hi:  186, btch:  31 usd: 177
Jun 23 13:30:56 panzor kernel: [54393.168803] CPU    1: hi:  186, btch:  31 usd: 172
Jun 23 13:30:56 panzor kernel: [54393.168807] Normal per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.168812] CPU    0: hi:  186, btch:  31 usd: 182
Jun 23 13:30:56 panzor kernel: [54393.168817] CPU    1: hi:  186, btch:  31 usd: 156
Jun 23 13:30:56 panzor kernel: [54393.168828] active_anon:140127 inactive_anon:221775 isolated_anon:0
Jun 23 13:30:56 panzor kernel: [54393.168828]  active_file:14158 inactive_file:7254 isolated_file:32
Jun 23 13:30:56 panzor kernel: [54393.168828]  unevictable:0 dirty:81 writeback:0 unstable:0
Jun 23 13:30:56 panzor kernel: [54393.168828]  free:10213 slab_reclaimable:38788 slab_unreclaimable:20911
Jun 23 13:30:56 panzor kernel: [54393.168828]  mapped:26698 shmem:106569 pagetables:7596 bounce:0
Jun 23 13:30:56 panzor kernel: [54393.168828]  free_cma:0
Jun 23 13:30:56 panzor kernel: [54393.168850] DMA free:28kB min:264kB low:328kB high:396kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun 23 13:30:56 panzor kernel: [54393.168854] lowmem_reserve[]: 0 2967 3920 3920
Jun 23 13:30:56 panzor kernel: [54393.168876] DMA32 free:40644kB min:50948kB low:63684kB high:76420kB active_anon:420312kB inactive_anon:557136kB active_file:19056kB inactive_file:19004kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:3128000kB managed:3038408kB mlocked:0kB dirty:204kB writeback:0kB mapped:57040kB shmem:206304kB slab_reclaimable:124972kB slab_unreclaimable:36492kB kernel_stack:936kB pagetables:20540kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.168881] lowmem_reserve[]: 0 0 953 953
Jun 23 13:30:56 panzor kernel: [54393.168901] Normal free:180kB min:16364kB low:20452kB high:24544kB active_anon:140196kB inactive_anon:329964kB active_file:37576kB inactive_file:10012kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1048576kB managed:975928kB mlocked:0kB dirty:120kB writeback:0kB mapped:49752kB shmem:219972kB slab_reclaimable:30180kB slab_unreclaimable:47152kB kernel_stack:1352kB pagetables:9844kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.168906] lowmem_reserve[]: 0 0 0 0
Jun 23 13:30:56 panzor kernel: [54393.168914] DMA: 1*4kB (U) 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4kB
Jun 23 13:30:56 panzor kernel: [54393.168938] DMA32: 7236*4kB (UEM) 1285*8kB (UEM) 87*16kB (UEM) 1*32kB (U) 1*64kB (U) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 40712kB
Jun 23 13:30:56 panzor kernel: [54393.168968] Normal: 31*4kB (UEM) 12*8kB (U) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 220kB
Jun 23 13:30:56 panzor kernel: [54393.168994] 138678 total pagecache pages
Jun 23 13:30:56 panzor kernel: [54393.168999] 10735 pages in swap cache
Jun 23 13:30:56 panzor kernel: [54393.169004] Swap cache stats: add 43083, delete 32348, find 1318922/1319418
Jun 23 13:30:56 panzor kernel: [54393.169008] Free swap  = 1853560kB
Jun 23 13:30:56 panzor kernel: [54393.169012] Total swap = 4095996kB
Jun 23 13:30:56 panzor kernel: [54393.208259] 1048575 pages RAM
Jun 23 13:30:56 panzor kernel: [54393.208266] 39962 pages reserved
Jun 23 13:30:56 panzor kernel: [54393.208270] 604425 pages shared
Jun 23 13:30:56 panzor kernel: [54393.208273] 618276 pages non-shared
Jun 23 13:30:56 panzor kernel: [54393.208287] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 0 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54393.208304] kworker/u:1: page allocation failure: order:1, mode:0x40d0
Jun 23 13:30:56 panzor kernel: [54393.208310] Pid: 8108, comm: kworker/u:1 Tainted: P           O 3.9.4-pf-ARCH #1
Jun 23 13:30:56 panzor kernel: [54393.208315] Call Trace:
Jun 23 13:30:56 panzor kernel: [54393.208329]  [<ffffffff81125c51>] warn_alloc_failed+0xe1/0x130
Jun 23 13:30:56 panzor kernel: [54393.208338]  [<ffffffff811297a1>] __alloc_pages_nodemask+0x7d1/0x9f0
Jun 23 13:30:56 panzor kernel: [54393.208364]  [<ffffffffa072ee9b>] il4965_rx_allocate+0x12b/0x2d0 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.208378]  [<ffffffffa07325db>] il4965_rx_replenish+0x1b/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.208391]  [<ffffffffa073264e>] il4965_bg_rx_replenish+0x3e/0x50 [iwl4965]
Jun 23 13:30:56 panzor kernel: [54393.208400]  [<ffffffff81074730>] process_one_work+0x170/0x440
Jun 23 13:30:56 panzor kernel: [54393.208408]  [<ffffffff81075205>] worker_thread+0x115/0x3d0
Jun 23 13:30:56 panzor kernel: [54393.208416]  [<ffffffff810750f0>] ? manage_workers+0x340/0x340
Jun 23 13:30:56 panzor kernel: [54393.208423]  [<ffffffff81079d90>] kthread+0xc0/0xd0
Jun 23 13:30:56 panzor kernel: [54393.208431]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.208441]  [<ffffffff814ca9ec>] ret_from_fork+0x7c/0xb0
Jun 23 13:30:56 panzor kernel: [54393.208448]  [<ffffffff81079cd0>] ? kthread_create_on_node+0x120/0x120
Jun 23 13:30:56 panzor kernel: [54393.208452] Mem-Info:
Jun 23 13:30:56 panzor kernel: [54393.208457] DMA per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.208462] CPU    0: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.208467] CPU    1: hi:    0, btch:   1 usd:   0
Jun 23 13:30:56 panzor kernel: [54393.208471] DMA32 per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.208476] CPU    0: hi:  186, btch:  31 usd: 155
Jun 23 13:30:56 panzor kernel: [54393.208482] CPU    1: hi:  186, btch:  31 usd: 172
Jun 23 13:30:56 panzor kernel: [54393.208485] Normal per-cpu:
Jun 23 13:30:56 panzor kernel: [54393.208490] CPU    0: hi:  186, btch:  31 usd: 182
Jun 23 13:30:56 panzor kernel: [54393.208495] CPU    1: hi:  186, btch:  31 usd: 156
Jun 23 13:30:56 panzor kernel: [54393.208507] active_anon:140127 inactive_anon:221775 isolated_anon:0
Jun 23 13:30:56 panzor kernel: [54393.208507]  active_file:11696 inactive_file:4764 isolated_file:32
Jun 23 13:30:56 panzor kernel: [54393.208507]  unevictable:0 dirty:81 writeback:0 unstable:0
Jun 23 13:30:56 panzor kernel: [54393.208507]  free:15188 slab_reclaimable:38763 slab_unreclaimable:20911
Jun 23 13:30:56 panzor kernel: [54393.208507]  mapped:21703 shmem:106569 pagetables:7596 bounce:0
Jun 23 13:30:56 panzor kernel: [54393.208507]  free_cma:0
Jun 23 13:30:56 panzor kernel: [54393.208528] DMA free:28kB min:264kB low:328kB high:396kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun 23 13:30:56 panzor kernel: [54393.208533] lowmem_reserve[]: 0 2967 3920 3920
Jun 23 13:30:56 panzor kernel: [54393.208555] DMA32 free:60544kB min:50948kB low:63684kB high:76420kB active_anon:420312kB inactive_anon:557136kB active_file:9208kB inactive_file:9044kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:3128000kB managed:3038408kB mlocked:0kB dirty:204kB writeback:0kB mapped:37060kB shmem:206304kB slab_reclaimable:124872kB slab_unreclaimable:36492kB kernel_stack:936kB pagetables:20540kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:50 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.208561] lowmem_reserve[]: 0 0 953 953
Jun 23 13:30:56 panzor kernel: [54393.208581] Normal free:180kB min:16364kB low:20452kB high:24544kB active_anon:140196kB inactive_anon:329964kB active_file:37576kB inactive_file:10012kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1048576kB managed:975928kB mlocked:0kB dirty:120kB writeback:0kB mapped:49752kB shmem:219972kB slab_reclaimable:30180kB slab_unreclaimable:47152kB kernel_stack:1352kB pagetables:9844kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 23 13:30:56 panzor kernel: [54393.208585] lowmem_reserve[]: 0 0 0 0
Jun 23 13:30:56 panzor kernel: [54393.208594] DMA: 1*4kB (U) 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4kB
Jun 23 13:30:56 panzor kernel: [54393.208618] DMA32: 10795*4kB (UEM) 1951*8kB (UEM) 108*16kB (UEM) 3*32kB (U) 1*64kB (U) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 60676kB
Jun 23 13:30:56 panzor kernel: [54393.208648] Normal: 31*4kB (UEM) 15*8kB (U) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 244kB
Jun 23 13:30:56 panzor kernel: [54393.208673] 133720 total pagecache pages
Jun 23 13:30:56 panzor kernel: [54393.208678] 10735 pages in swap cache
Jun 23 13:30:56 panzor kernel: [54393.208683] Swap cache stats: add 43083, delete 32348, find 1318922/1319418
Jun 23 13:30:56 panzor kernel: [54393.208688] Free swap  = 1853560kB
Jun 23 13:30:56 panzor kernel: [54393.208691] Total swap = 4095996kB
Jun 23 13:30:56 panzor kernel: [54393.248411] 1048575 pages RAM
Jun 23 13:30:56 panzor kernel: [54393.248417] 39962 pages reserved
Jun 23 13:30:56 panzor kernel: [54393.248420] 595771 pages shared
Jun 23 13:30:56 panzor kernel: [54393.248424] 618247 pages non-shared
Jun 23 13:30:56 panzor kernel: [54393.248438] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 0 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54393.288104] (elapsed 0.13 seconds) done.
Jun 23 13:30:56 panzor kernel: [54393.640043] Starting to save the image..
Jun 23 13:30:56 panzor kernel: [54393.640055] Writing caches...
Jun 23 13:30:56 panzor kernel: [54393.640130] Waited for i/o due to synchronous I/O 6 times.
Jun 23 13:30:56 panzor kernel: [54393.640137] Doing atomic copy/restore.
Jun 23 13:30:56 panzor kernel: [54393.641095] Suspending console(s) (use no_console_suspend to debug)
Jun 23 13:30:56 panzor kernel: [54393.650532] hdaps: setting ec_rate=0, filter_order=1
Jun 23 13:30:56 panzor kernel: [54395.282862] PM: freeze of devices complete after 1641.758 msecs
Jun 23 13:30:56 panzor kernel: [54395.283246] PM: late freeze of devices complete after 0.381 msecs
Jun 23 13:30:56 panzor kernel: [54395.284199] PM: noirq freeze of devices complete after 0.950 msecs
Jun 23 13:30:56 panzor kernel: [54395.284624] ACPI: Preparing to enter system sleep state S4
Jun 23 13:30:56 panzor kernel: [54395.288365] PM: Saving platform NVS memory
Jun 23 13:30:56 panzor kernel: [54395.288664] Disabling non-boot CPUs ...
Jun 23 13:30:56 panzor kernel: [54395.391275] smpboot: CPU 1 is now offline
Jun 23 13:30:56 panzor kernel: [54395.391543] PM: Restoring platform NVS memory
Jun 23 13:30:56 panzor kernel: [54395.391543] Enabling non-boot CPUs ...
Jun 23 13:30:56 panzor kernel: [54395.391543] smpboot: Booting Node 0 Processor 1 APIC 0x1
Jun 23 13:30:56 panzor kernel: [54395.428119] CPU1 is up
Jun 23 13:30:56 panzor kernel: [54395.433075] ACPI: Waking up from system sleep state S4
Jun 23 13:30:56 panzor kernel: [54395.468714] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.468802] ehci-pci 0000:00:1a.7: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.482291] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.482460] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.482546] ehci-pci 0000:00:1d.7: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.483224] nvidia 0000:01:00.0: power state changed by ACPI to D0
Jun 23 13:30:56 panzor kernel: [54395.495339] PM: noirq restore of devices complete after 27.065 msecs
Jun 23 13:30:56 panzor kernel: [54395.495803] PM: early restore of devices complete after 0.396 msecs
Jun 23 13:30:56 panzor kernel: [54395.495877] e1000e 0000:00:19.0: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.495893] uhci_hcd 0000:00:1a.0: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.495938] usb usb2: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.495961] uhci_hcd 0000:00:1a.1: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.495996] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jun 23 13:30:56 panzor kernel: [54395.495999] usb usb3: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.496020] ehci-pci 0000:00:1a.7: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.496052] usb usb1: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.497980] uhci_hcd 0000:00:1d.0: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.497987] uhci_hcd 0000:00:1d.1: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.498020] usb usb4: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.498025] usb usb5: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.498042] uhci_hcd 0000:00:1d.2: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.498052] ehci-pci 0000:00:1d.7: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.498077] usb usb6: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.498088] pci 0000:00:1e.0: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.498109] usb usb7: root hub lost power or was reset
Jun 23 13:30:56 panzor kernel: [54395.498694] ata_piix 0000:00:1f.1: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.498719] ahci 0000:00:1f.2: setting latency timer to 64
Jun 23 13:30:56 panzor kernel: [54395.501299] iwl4965 0000:03:00.0: RF_KILL bit toggled to enable radio.
Jun 23 13:30:56 panzor kernel: [54395.501576] snd_hda_intel 0000:00:1b.0: irq 48 for MSI/MSI-X
Jun 23 13:30:56 panzor kernel: [54395.502221] ehci-pci 0000:00:1a.7: cache line size of 64 is not supported
Jun 23 13:30:56 panzor kernel: [54395.508491] ehci-pci 0000:00:1d.7: cache line size of 64 is not supported
Jun 23 13:30:56 panzor kernel: [54395.522685] ata2: port disabled--ignoring
Jun 23 13:30:56 panzor kernel: [54395.557902] Uhhuh. NMI received for unknown reason 21 on CPU 0.
Jun 23 13:30:56 panzor kernel: [54395.557902] Do you have a strange power saving mode enabled?
Jun 23 13:30:56 panzor kernel: [54395.557902] Dazed and confused, but trying to continue
Jun 23 13:30:56 panzor kernel: [54396.398753] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jun 23 13:30:56 panzor kernel: [54396.398759] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jun 23 13:30:56 panzor kernel: [54396.398764] ata1.00: ACPI cmd ef/03:45:00:00:00:a0 (SET FEATURES) filtered out
Jun 23 13:30:56 panzor kernel: [54396.398769] ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
Jun 23 13:30:56 panzor kernel: [54396.418693] ata1.00: configured for UDMA/100
Jun 23 13:30:56 panzor kernel: [54396.418758] sd 0:0:0:0: [sda] Starting disk
Jun 23 13:30:56 panzor kernel: [54396.421423] tpm_tis 00:09: TPM is disabled/deactivated (0x6)
Jun 23 13:30:56 panzor kernel: [54396.501264] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Jun 23 13:30:56 panzor kernel: [54396.501837] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jun 23 13:30:56 panzor kernel: [54396.501840] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jun 23 13:30:56 panzor kernel: [54396.501844] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
Jun 23 13:30:56 panzor kernel: [54396.502684] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Jun 23 13:30:56 panzor kernel: [54396.502688] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Jun 23 13:30:56 panzor kernel: [54396.502691] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
Jun 23 13:30:56 panzor kernel: [54396.502913] ata3.00: configured for UDMA/133
Jun 23 13:30:56 panzor kernel: [54396.514622] sd 2:0:0:0: [sdb] Starting disk
Jun 23 13:30:56 panzor kernel: [54396.621250] smapi smapi: set_real_thresh: set stop to 0 for bat=0
Jun 23 13:30:56 panzor kernel: [54396.704619] usb 2-2: reset full-speed USB device number 2 using uhci_hcd
Jun 23 13:30:56 panzor kernel: [54396.727909] smapi smapi: set_real_thresh: set start to 74 for bat=0
Jun 23 13:30:56 panzor kernel: [54396.834575] smapi smapi: set_real_thresh: set stop to 0 for bat=1
Jun 23 13:30:56 panzor kernel: [54396.891275] firewire_core 0000:15:00.1: rediscovered device fw0
Jun 23 13:30:56 panzor kernel: [54396.941262] usb 4-1: reset full-speed USB device number 2 using uhci_hcd
Jun 23 13:30:56 panzor kernel: [54396.941273] smapi smapi: set_real_thresh: set start to 0 for bat=1
Jun 23 13:30:56 panzor kernel: [54396.941894] thinkpad_acpi: ACPI backlight control delay disabled
Jun 23 13:30:56 panzor kernel: [54396.948189] hdaps: initial mode latch is 0x05
Jun 23 13:30:56 panzor kernel: [54396.948344] hdaps: setting ec_rate=250, filter_order=2
Jun 23 13:30:56 panzor kernel: [54400.864853] PM: restore of devices complete after 5369.039 msecs
Jun 23 13:30:56 panzor kernel: [54400.878774] Post atomic.
Jun 23 13:30:56 panzor kernel: [54400.878789] Cleaning up...
Jun 23 13:30:56 panzor kernel: [54401.098010] Restarting tasks ... done.
Jun 23 13:30:56 panzor kernel: [54401.551151] NVRM: GPU at 0000:01:00: GPU-77275150-d92f-b71d-320f-e618dbfadc80
Jun 23 13:30:56 panzor kernel: [54401.551167] NVRM: Xid (0000:01:00): 13, 0001 00000000 00005097 0000194c 00000000 00000080
Jun 23 13:30:56 panzor kernel: [54401.715339] video LNXVIDEO:01: Restoring backlight state
Jun 23 13:30:56 panzor kernel: [54401.716780] TuxOnIce debugging info:
Jun 23 13:30:56 panzor kernel: [54401.716780] - TuxOnIce core  : 3.3
Jun 23 13:30:56 panzor kernel: [54401.716780] - Kernel Version : 3.9.4-pf-ARCH
Jun 23 13:30:56 panzor kernel: [54401.716780] - Compiler vers. : 4.8
Jun 23 13:30:56 panzor kernel: [54401.716780] - Attempt number : 2
Jun 23 13:30:56 panzor kernel: [54401.716780] - Parameters     : 0 667648 0 0 -2 0
Jun 23 13:30:56 panzor kernel: [54401.716780] - Overall expected compression percentage: 0.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Compressor is 'lzo'.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Compressed 2073235456 bytes into 853404129 (58 percent compression).
Jun 23 13:30:56 panzor kernel: [54401.716780] - Block I/O active.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Used 210370 pages from swap on /dev/sdb2.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Max outstanding reads 1. Max writes 0.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Memory_needed: 1024 x (4096 + 368 + 120) = 4694016 bytes.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Free mem throttle point reached 0.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Swap Allocator enabled.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Swap available for image: 987373 pages.
Jun 23 13:30:56 panzor kernel: [54401.716780] - File Allocator active.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Storage available for image: 0 pages.
Jun 23 13:30:56 panzor kernel: [54401.716780] - I/O speed: Write 443 MB/s, Read 532 MB/s.
Jun 23 13:30:56 panzor kernel: [54401.791664] mmc0: new high speed SDHC card at address d555
Jun 23 13:30:56 panzor kernel: [54401.792258] mmcblk0: mmc0:d555 SD04G 3.79 GiB 
Jun 23 13:30:56 panzor kernel: [54401.796685]  mmcblk0: p1
Jun 23 13:30:56 panzor kernel: [54401.856821] skipping vid at 0, 75 is greater than default 39
Jun 23 13:30:56 panzor kernel: [54401.856831] failed to parse vid value at 1 (:23 74:0 8:0 6:0 136:0
Jun 23 13:30:56 panzor kernel: [54401.856831] )
Jun 23 13:30:56 panzor kernel: [54401.857554] skipping vid at 0, 75 is greater than default 39
Jun 23 13:30:56 panzor kernel: [54401.857561] failed to parse vid value at 1 (:23 74:0 8:0 6:0 136:0
Jun 23 13:30:56 panzor kernel: [54401.857561] )
Jun 23 13:30:55 panzor systemd[1]: Time has been changed
Jun 23 13:30:56 panzor systemd-sleep[11837]: System resumed.
Jun 23 13:30:56 panzor systemd-sleep[11837]: /usr/lib/systemd/system-sleep/phc-intel exited with exit status 1.
Jun 23 13:30:57 panzor systemd-sleep[11837]: /usr/lib/systemd/system-sleep/example.sh exited with exit status 1.
Jun 23 13:30:57 panzor systemd[1]: Started Hibernate.
Jun 23 13:30:57 panzor systemd[1]: Service sleep.target is not needed anymore. Stopping.
Jun 23 13:30:57 panzor systemd[1]: Stopping Sleep.
Jun 23 13:30:57 panzor systemd[1]: Stopped target Sleep.
Jun 23 13:30:57 panzor systemd[1]: Service wicd-sleep.service is not needed anymore. Stopping.
Jun 23 13:30:57 panzor systemd[1]: Stopping Wicd sleep hook...
Jun 23 13:30:57 panzor systemd[1]: Starting Hibernate.
Jun 23 13:30:57 panzor systemd[1]: Reached target Hibernate.
Jun 23 13:30:57 panzor systemd-sleep[11837]: /usr/bin/phc-intel: line 11: echo: write error: Invalid argument
Jun 23 13:30:57 panzor systemd-sleep[11837]: /usr/bin/phc-intel: line 11: echo: write error: Invalid argument
Jun 23 13:30:57 panzor systemd-sleep[11837]: ERROR: The control display is undefined; please run `nvidia-settings
Jun 23 13:30:57 panzor systemd-sleep[11837]: --help` for usage information.
Jun 23 13:30:57 panzor logger: ACPI group/action undefined: processor / LNXCPU:00
Jun 23 13:30:57 panzor logger: ACPI group/action undefined: processor / LNXCPU:00
Jun 23 13:30:57 panzor logger: ACPI group/action undefined: processor / LNXCPU:01
Jun 23 13:30:57 panzor dnsmasq[1149]: reading /etc/resolv.conf
Jun 23 13:30:57 panzor dnsmasq[1149]: using nameserver 208.67.222.222#53
Jun 23 13:30:57 panzor dnsmasq[1149]: using nameserver 8.8.8.8#53
Jun 23 13:30:57 panzor dnsmasq[1149]: ignoring nameserver 127.0.0.1 - local interface
Jun 23 13:30:59 panzor systemd[1]: Stopped Wicd sleep hook.
Jun 23 13:31:02 panzor wicd[467]: dhcpcd[12037]: dhcpcd not running
Jun 23 13:31:02 panzor dhcpcd[12037]: dhcpcd not running
Jun 23 13:31:03 panzor kernel: [54408.612716] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jun 23 13:31:03 panzor wicd[467]: Failed to connect to non-global ctrl_ifname: wlan0  error: No such file or directory
Jun 23 13:31:03 panzor wicd[467]: dhcpcd[12043]: dhcpcd not running
Jun 23 13:31:03 panzor dhcpcd[12043]: dhcpcd not running
Jun 23 13:31:03 panzor kernel: [54409.276781] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jun 23 13:31:03 panzor kernel: [54409.378052] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
Jun 23 13:31:03 panzor kernel: [54409.378183] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jun 23 13:31:03 panzor wicd[467]: Failed to connect to non-global ctrl_ifname: eth0  error: No such file or directory
Jun 23 13:31:04 panzor wicd[467]: dhcpcd[12054]: dhcpcd not running
Jun 23 13:31:04 panzor dhcpcd[12054]: dhcpcd not running
Jun 23 13:31:04 panzor kernel: [54409.660329] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jun 23 13:31:04 panzor wicd[467]: Failed to connect to non-global ctrl_ifname: wlan0  error: No such file or directory
Jun 23 13:31:06 panzor kernel: [54411.834223] wlan0: authenticate with f4:ca:e5:bf:36:d0
Jun 23 13:31:06 panzor kernel: [54411.834276] wlan0: send auth to f4:ca:e5:bf:36:d0 (try 1/3)
Jun 23 13:31:06 panzor kernel: [54411.836189] wlan0: authenticated
Jun 23 13:31:06 panzor kernel: [54411.838102] wlan0: associate with f4:ca:e5:bf:36:d0 (try 1/3)
Jun 23 13:31:06 panzor kernel: [54411.841116] wlan0: RX AssocResp from f4:ca:e5:bf:36:d0 (capab=0x411 status=0 aid=2)
Jun 23 13:31:06 panzor kernel: [54411.872002] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Jun 23 13:31:06 panzor kernel: [54411.872028] wlan0: associated
Jun 23 13:31:07 panzor dhcpcd[12081]: version 5.6.8 starting
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: sending IPv6 Router Solicitation
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: sendmsg: Cannot assign requested address
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: broadcasting for a lease
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: offered 192.168.1.7 from 192.168.1.254
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: acknowledged 192.168.1.7 from 192.168.1.254
Jun 23 13:31:07 panzor dhcpcd[12081]: wlan0: checking for 192.168.1.7
Jun 23 13:31:11 panzor dhcpcd[12081]: wlan0: sending IPv6 Router Solicitation
Jun 23 13:31:12 panzor dhcpcd[12081]: wlan0: leased 192.168.1.7 for 43200 seconds
Jun 23 13:31:12 panzor dhcpcd[12081]: forked to background, child pid 12127
Jun 23 13:31:15 panzor dhcpcd[12127]: wlan0: sending IPv6 Router Solicitation
Jun 23 13:31:19 panzor dhcpcd[12127]: wlan0: sending IPv6 Router Solicitation
Jun 23 13:31:19 panzor dhcpcd[12127]: wlan0: no IPv6 Routers available
Jun 23 13:32:01 panzor CROND[12307]: (root) CMD (/usr/bin/modprobed_db store &> /dev/null)
Jun 23 13:32:04 panzor dnsmasq[1149]: reading /etc/resolv.conf
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 208.67.220.220#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 8.8.4.4#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 208.67.222.222#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 8.8.8.8#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 192.168.1.254#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 208.67.222.222#53
Jun 23 13:32:04 panzor dnsmasq[1149]: using nameserver 8.8.8.8#53
Jun 23 13:32:04 panzor dnsmasq[1149]: ignoring nameserver 127.0.0.1 - local interface
Jun 23 13:32:10 panzor systemd[1]: Unmounting Arbitrary Executable File Formats File System...
Jun 23 13:32:11 panzor kernel: [54476.144548] wlan0: deauthenticating from f4:ca:e5:bf:36:d0 by local choice (reason=3)
Jun 23 13:32:11 panzor kernel: [54476.178570] cfg80211: Calling CRDA to update world regulatory domain
Jun 23 13:32:10 panzor systemd[1]: Deactivating swap /dev/sdb2...
Jun 23 13:32:11 panzor syslog-ng[419]: syslog-ng shutting down; version='3.4.2'
Jun 23 13:32:10 panzor systemd[1]: Deactivating swap /dev/sdb2...
Jun 23 13:32:10 panzor systemd[1]: Deactivating swap /dev/sdb2...
Jun 23 13:32:10 panzor systemd[1]: Stopping Sound Card.
Jun 23 13:32:10 panzor systemd[1]: Stopped target Sound Card.
Jun 23 13:32:10 panzor systemd[1]: Stopping Multi-User System.
Jun 23 13:32:10 panzor systemd[1]: Stopped target Multi-User System.
Jun 23 13:32:10 panzor systemd[1]: Stopping Profile-sync-daemon...
Jun 23 13:32:10 panzor systemd[1]: Stopping System Logger Daemon...
Jun 23 13:32:10 panzor systemd[1]: Stopping Run missed cronjobs with cronwhip....
Jun 23 13:32:10 panzor systemd[1]: Stopped Run missed cronjobs with cronwhip..
Jun 23 13:32:10 panzor acpid: exiting
Jun 23 13:32:11 panzor iptables-flush[12372]: /usr/sbin/iptables

errors.log

Jun 23 13:30:13 panzor kernel: [54391.448037] Failed to launch userspace program '/usr/local/sbin/tuxoniceui_text': Error -2
Jun 23 13:30:13 panzor kernel: [54391.454544] Starting other threads.
Jun 23 13:30:56 panzor kernel: [54393.168602] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 1 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54393.208287] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 0 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54393.248438] iwl4965 0000:03:00.0: Failed to alloc_pages with GFP_KERNEL. Only 0 free buffers remaining.
Jun 23 13:30:56 panzor kernel: [54401.551167] NVRM: Xid (0000:01:00): 13, 0001 00000000 00005097 0000194c 00000000 00000080
Jun 23 13:30:56 panzor kernel: [54401.716780] TuxOnIce debugging info:
Jun 23 13:30:56 panzor kernel: [54401.716780] - TuxOnIce core  : 3.3
Jun 23 13:30:56 panzor kernel: [54401.716780] - Kernel Version : 3.9.4-pf-ARCH
Jun 23 13:30:56 panzor kernel: [54401.716780] - Compiler vers. : 4.8
Jun 23 13:30:56 panzor kernel: [54401.716780] - Attempt number : 2
Jun 23 13:30:56 panzor kernel: [54401.716780] - Parameters     : 0 667648 0 0 -2 0
Jun 23 13:30:56 panzor kernel: [54401.716780] - Overall expected compression percentage: 0.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Compressor is 'lzo'.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Compressed 2073235456 bytes into 853404129 (58 percent compression).
Jun 23 13:30:56 panzor kernel: [54401.716780] - Block I/O active.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Used 210370 pages from swap on /dev/sdb2.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Max outstanding reads 1. Max writes 0.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Memory_needed: 1024 x (4096 + 368 + 120) = 4694016 bytes.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Free mem throttle point reached 0.
Jun 23 13:30:56 panzor kernel: [54401.716780] - Swap Allocator enabled.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Swap available for image: 987373 pages.
Jun 23 13:30:56 panzor kernel: [54401.716780] - File Allocator active.
Jun 23 13:30:56 panzor kernel: [54401.716780]   Storage available for image: 0 pages.
Jun 23 13:30:56 panzor kernel: [54401.716780] - I/O speed: Write 443 MB/s, Read 532 MB/s.
Jun 23 13:30:56 panzor systemd-sleep[11837]: /usr/lib/systemd/system-sleep/phc-intel exited with exit status 1.
Jun 23 13:30:57 panzor systemd-sleep[11837]: /usr/lib/systemd/system-sleep/example.sh exited with exit status 1.

I assume reinitialising the video card upon resume is the answer, but although it was possible through quirks in the HAL days, I can find no way to do that with systemd and/or tuxonice.

Countrarywise, running

/usr/bin/pm-hibernate

does resume properly BUT it stops twice for one minute each at those stages:

Doing atomic copy/restore

<black screen>

while doing COMPLETELY nothing. Not using CPU, not reading anything from the disk. Just waiting.
Those two stages take a blink of an eye if the first hibernation method is used.

Last edited by Lockheed (2013-06-23 12:14:32)

Lockheed · 2013-06-23 11:47:51

I had this problem since months, and no one even was able to have any stab at it.

I updated the original post with more details.

ewaller · 2013-06-24 16:26:57

Moved per request.

orschiro · 2013-06-26 12:16:10

Did you try not using TuxOnIce?

Lockheed · 2013-06-26 12:17:26

Yes, the part starting with "Countrarywise" describes experience with regular hibernation.

Arch Linux

#1 2013-02-13 10:17:43

Screen remains OFF after resume from hibernation

#2 2013-06-23 11:47:51

Re: Screen remains OFF after resume from hibernation

#3 2013-06-24 16:26:57

Re: Screen remains OFF after resume from hibernation

#4 2013-06-26 12:16:10

Re: Screen remains OFF after resume from hibernation

#5 2013-06-26 12:17:26

Re: Screen remains OFF after resume from hibernation

Board footer