TuxOnIce stalls 3 times before resuming


 
Thread Tools Search this Thread
Operating Systems Linux TuxOnIce stalls 3 times before resuming
# 1  
Old 11-10-2012
Question TuxOnIce stalls 3 times before resuming

I am having trouble resuming from hibernation using TuxOnIce method.
The thing works, but in a very strange manner. Here's how it looks:

1. Computer boots and finds resume image and starts resume. It reads image from disk (takes ~10 seconds)
Reading kernel & process data...
Atomic restore.
Doing atomic copy/restore.


2. Resume pauses for about ~30 seconds displaying above message. There is NO disk or any other activity visible.

3. Screen goes blank, it beeps. and pauses for another ~30 seconds. There is NO disk or any other activity visible.

4. It beeps and pauses for another ~30 seconds. There is NO disk or any other activity visible. The screen is blank.

5. Screen blinks once, then it beeps and pauses for another ~30 seconds. There is NO disk or any other activity visible.

6. Resume continues normally without displaying any errors. Disk resumes activity. Desktop visible within seconds.
Post atomic.
Cleaning up...



Here is the logs: <link removed>

And my config files: <link removed>

Hibernate debug log: <link removed>


This is obviously not a question or reading image from the disk. The issue is elsewhere. It is the same if I unplug all external USB devices. I tried playing around with various options in /etc/hibernate/common.conf and tuxonice.conf but it didn't change anything...

I am on my wits' end.

Moderator's Comments:
Mod Comment Please do not link to external sites. Especially the likes of pastebin. You can post representative samples of your files in your post (preferred), or upload the files here. Thanks.

Last edited by Scott; 11-10-2012 at 08:57 AM.. Reason: Removed links
# 2  
Old 11-10-2012
Do you have version 3.2 installed. You do realize that tux compresses RAM on the start of hibernate, then decompresses it. This would account for some stuttering and disk activity.

If you have a load of resident processes you increase the problem. On Suse 12 we stopped using it because it interfered with launching: systemctl (systemd) relaunching services had issues.

Since this thing is not a mission critical deal we knocked it off desktop Suse boxes. Do you have a business requirement to "hibernate"?
# 3  
Old 11-10-2012
I don't think we understood each other.

The system is not reading anything from the disk.
The system is not computing anything.
What the system IS doing is sitting idly doing absolutely nothing (except for waiting for something) in three distinctive, consecutive sessions of ~30 seconds.

Here is a hibernation log:
Code:
$ sudo hibernate -v 4 > /home/juha/Desktop/hiber.txt
+ + tee -a -i /var/log/hibernate.log
date
+ echo Starting suspend at Sat 10 Nov 17:56:40 CET 2012
+ EXIT_CODE=0
+ [ tee -a -i /var/log/hibernate.log = cat ]
+ [ -n  ]
+ trap  INT
+ exec
+ exec
+ + tee -aDoWork
 -i /var/log/hibernate.log
+ trap ctrlc_handler INT HUP
+ local ret
+ local CHAIN_UP_TO
+ local bit
+ CHAIN_UP_TO=0
+ SortSuspendBits
+ /bin/echo -ne+  12AcpiVideoFlagsSuspend\n12IbmAcpiStartSuspend\n95XHacksSuspendHook2\n11XHacksSuspendHook1\n98FullSpeedCPUSuspend\n98TuxOnIceConfigSet\n99DoTuxOnIce\n97ChangeToTuxOnIceVT\n10EnsureTuxOnIceCapable\n59RemountXFSBootRO\n01NewKernelFileCheck\n89SaveKernelModprobe\n98CheckRunlevel\n01CheckRunlevel\n01CheckLastResume\n01LockFileGet\n
sort -n
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("01CheckLastResume", 1, 2)}
+ new_CHAIN_UP_TO=01
+ [ -n 01 ]
+ CHAIN_UP_TO=01
+ bit=CheckLastResume
+ vecho 1 hibernate: [01] Executing CheckLastResume ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.11 hibernate: [01] Executing CheckLastResume ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.11 hibernate: [01] Executing CheckLastResume ...
+ [ -n  ]
+ CheckLastResume
+ [ -f /var/run/hibernate-last-resume ]
+ local last_resume now
+ read last_resume
+ date +%s
+ now=1352566600
+ [ 1352566600 -gt 1352566590 ]
+ rm -f /var/run/hibernate-last-resume
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("01CheckRunlevel", 1, 2)}
+ new_CHAIN_UP_TO=01
+ [ -n 01 ]
+ CHAIN_UP_TO=01
+ bit=CheckRunlevel
+ vecho 1 hibernate: [01] Executing CheckRunlevel ... 
+ local v
+ v=1h
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.12 hibernate: [01] Executing CheckRunlevel ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.12 hibernate: [01] Executing CheckRunlevel ...
+ [ -n  ]
+ CheckRunlevel
+ [ -z  ]
+ /sbin/runlevel
+ awk {print $2}
+ RUNLEVEL=3
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("01LockFileGet", 1, 2)}
+ new_CHAIN_UP_TO=01
+ [ -n 01 ]
+ CHAIN_UP_TO=01
+ bit=LockFileGet
+ vecho 1 hibernate: [01] Executing LockFileGet ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.14 hibernate: [01] Executing LockFileGet ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.14 hibernate: [01] Executing LockFileGet ...
+ [ -n  ]
+ LockFileGet
+ local other_pid
+ [ -f /var/run/hibernate-script.pid ]
+ echo 3922
+ LOCKFILE_IN_USE=1
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("01NewKernelFileCheck", 1, 2)}
+ new_CHAIN_UP_TO=01
+ [ -n 01 ]
+ CHAIN_UP_TO=01
+ bit=NewKernelFileCheck
+ vecho 1 hibernate: [01] Executing NewKernelFileCheck ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.15 hibernate: [01] Executing NewKernelFileCheck ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.15 hibernate: [01] Executing NewKernelFileCheck ...
+ [ -n  ]
+ NewKernelFileCheck
+ [ -f /var/run/tuxonice-new-kernel ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("10EnsureTuxOnIceCapable", 1, 2)}
+ new_CHAIN_UP_TO=10
+ [ -n 10 ]
+ CHAIN_UP_TO=10
+ bit=EnsureTuxOnIceCapable
+ vecho 1 hibernate: [10] Executing EnsureTuxOnIceCapable ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.16 hibernate: [10] Executing EnsureTuxOnIceCapable ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.16 hibernate: [10] Executing EnsureTuxOnIceCapable ...
+ [ -n  ]
+ EnsureTuxOnIceCapable
+ local ver
+ [ -d /sys/power/tuxonice ]
+ [ -f /sys/power/tuxonice/activate ]
+ [ -f /sys/power/tuxonice/do_suspend ]
+ [ -f /sys/power/tuxonice/do_hibernate ]
+ [ ! -f /sys/power/tuxonice/version ]
+ TuxOnIceIsAtLeastVersion 33554535
+ awk BEGIN{FS="[^0-9]"}{print($1*16777216)+($2*65536)+($3*256)+$4} /sys/power/tuxonice/version
+ ver=50528256
+ [ 50528256 -ge 33554535 ]
+ return 0
+ [ x1 != x1 ]
+ [ -f /sys/power/tuxonice/resume2 ]
+ [ -f /sys/power/tuxonice/resume ]
+ RESUME2_FILE=resume
+ [ -n resume ]
+ [ -n swap:/dev/sda5 ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("11XHacksSuspendHook1", 1, 2)}
+ new_CHAIN_UP_TO=11
+ [ -n 11 ]
+ CHAIN_UP_TO=11
+ bit=XHacksSuspendHook1
+ vecho 1 hibernate: [11] Executing XHacksSuspendHook1 ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.17 hibernate: [11] Executing XHacksSuspendHook1 ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.17 hibernate: [11] Executing XHacksSuspendHook1 ...
+ [ -n  ]
+ XHacksSuspendHook1
+ [ x = x1 ]
+ [ x = x1 ]
+ [ -n  ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("12AcpiVideoFlagsSuspend", 1, 2)}
+ new_CHAIN_UP_TO=12
+ [ -n 12 ]
+ CHAIN_UP_TO=12
+ bit=AcpiVideoFlagsSuspend
+ vecho 1 hibernate: [12] Executing AcpiVideoFlagsSuspend ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.19 hibernate: [12] Executing AcpiVideoFlagsSuspend ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.19 hibernate: [12] Executing AcpiVideoFlagsSuspend ...
+ [ -n  ]
+ AcpiVideoFlagsSuspend
+ echo 3
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("12IbmAcpiStartSuspend", 1, 2)}
+ new_CHAIN_UP_TO=12
+ [ -n 12 ]
+ CHAIN_UP_TO=12
+ bit=IbmAcpiStartSuspend
+ vecho 1 hibernate: [12] Executing IbmAcpiStartSuspend ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.19 hibernate: [12] Executing IbmAcpiStartSuspend ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.19 hibernate: [12] Executing IbmAcpiStartSuspend ...
+ [ -n  ]
+ IbmAcpiStartSuspend
+ IbmAcpiLed 7 blink
+ [ -f /proc/acpi/ibm/led ]
+ echo 7 blink
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("59RemountXFSBootRO", 1, 2)}
+ new_CHAIN_UP_TO=59
+ [ -n 59 ]
+ CHAIN_UP_TO=59
+ bit=RemountXFSBootRO
+ vecho 1 hibernate: [59] Executing RemountXFSBootRO ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.20 hibernate: [59] Executing RemountXFSBootRO ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.20 hibernate: [59] Executing RemountXFSBootRO ...
+ [ -n  ]
+ RemountXFSBootRO
+ [  = 1 ]
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("89SaveKernelModprobe", 1, 2)}
+ new_CHAIN_UP_TO=89
+ [ -n 89 ]
+ CHAIN_UP_TO=89
+ bit=SaveKernelModprobe
+ vecho 1 hibernate: [89] Executing SaveKernelModprobe ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.21 hibernate: [89] Executing SaveKernelModprobe ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.21 hibernate: [89] Executing SaveKernelModprobe ...
+ [ -n  ]
+ SaveKernelModprobe
+ [ -n  ]
+ [ -r /proc/sys/kernel/modprobe ]
+ cat /proc/sys/kernel/modprobe
+ KERNEL_MODPROBE=/sbin/modprobe
+ [ -n /sbin/modprobe ]
+ vecho 3 Saved /proc/sys/kernel/modprobe is /sbin/modprobe
+ local v
+ v=3
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.22 Saved /proc/sys/kernel/modprobe is /sbin/modprobe
+ [ 3 -le 4 ]
+ echo Nov 10 17:56:40.22 Saved /proc/sys/kernel/modprobe is /sbin/modprobe
+ echo /doesnt/exist
+ [ -r /proc/sys/kernel/hotplug ]
+ cat /proc/sys/kernel/hotplug
+ KERNEL_HOTPLUG=
+ [ -n  ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("95XHacksSuspendHook2", 1, 2)}
+ new_CHAIN_UP_TO=95
+ [ -n 95 ]
+ CHAIN_UP_TO=95
+ bit=XHacksSuspendHook2
+ vecho 1 hibernate: [95] Executing XHacksSuspendHook2 ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.22 hibernate: [95] Executing XHacksSuspendHook2 ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:40.22 hibernate: [95] Executing XHacksSuspendHook2 ...
+ [ -n  ]
+ XHacksSuspendHook2
+ [ -z  ]
+ XHacksSuspend
+ [ x1 = x1 ]
+ command -v fgconsole
+ fgconsole
+ XHACKS_ORIGINAL_VT=1
+ [ x1 = x1 ]
+ local dest_vt
+ [ -z  ]
+ dest_vt=15
+ vecho 3 xhacks: changing console from 1 to 15
+ local v
+ v=3
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:40.23 xhacks: changing console from 1 to 15
+ [ 3 -le 4 ]
+ echo Nov 10 17:56:40.23 xhacks: changing console from 1 to 15
+ chvt 15
+ return 0
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("97ChangeToTuxOnIceVT", 1, 2)}
+ new_CHAIN_UP_TO=97
+ [ -n 97 ]
+ CHAIN_UP_TO=97
+ bit=ChangeToTuxOnIceVT
+ vecho 1 hibernate: [97] Executing ChangeToTuxOnIceVT ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.08 hibernate: [97] Executing ChangeToTuxOnIceVT ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.08 hibernate: [97] Executing ChangeToTuxOnIceVT ...
+ [ -n  ]
+ ChangeToTuxOnIceVT
+ [ -n  ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("98CheckRunlevel", 1, 2)}
+ new_CHAIN_UP_TO=98
+ [ -n 98 ]
+ CHAIN_UP_TO=98
+ bit=CheckRunlevel
+ vecho 1 hibernate: [98] Executing CheckRunlevel ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.09 hibernate: [98] Executing CheckRunlevel ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.09 hibernate: [98] Executing CheckRunlevel ...
+ [ -n  ]
+ CheckRunlevel
+ [ -z 3 ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("98FullSpeedCPUSuspend", 1, 2)}
+ new_CHAIN_UP_TO=98
+ [ -n 98 ]
+ CHAIN_UP_TO=98
+ bit=FullSpeedCPUSuspend
+ vecho 1 hibernate: [98] Executing FullSpeedCPUSuspend ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.10 hibernate: [98] Executing FullSpeedCPUSuspend ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.10 hibernate: [98] Executing FullSpeedCPUSuspend ...
+ [ -n  ]
+ FullSpeedCPUSuspend
+ local cpu
+ mktemp /tmp/tmp.hibernate.XXXXXX
+ HW_FULLSPEEDCPU_RESTORER=/tmp/tmp.hibernate.YxHIL6
+ local cpunum min_freq setspeed governor i
+ [ -d /sys/devices/system/cpu/cpu0/cpufreq ]
+ cpunum=0/cpufreq
+ cpunum=0
+ IsANumber 0
+ return 0
+ eval done_this=$hw_cpu_0_done
+ done_this=
+ [ x = xcpudone ]
+ cat /sys/devices/system/cpu/cpu0/cpufreq/affected_cpus
+ IsANumber 0
+ return 0
+ eval hw_cpu_0_done=cpudone
+ hw_cpu_0_done=cpudone
+ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq
+ max_freq=2101000
+ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq
+ min_freq=800000
+ [ -f /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed ]
+ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed
+ setspeed=<unsupported>
+ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
+ governor=ondemand
+ cat
+ grep -q performance /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors
+ echo performance
+ echo 2101000
+ vecho 2 Switched to performance, with min freq at 2101000
+ local v
+ v=2
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.12 Switched to performance, with min freq at 2101000
+ [ 2 -le 4 ]
+ echo Nov 10 17:56:43.12 Switched to performance, with min freq at 2101000
+ local cpunum min_freq setspeed governor i
+ [ -d /sys/devices/system/cpu/cpu1/cpufreq ]
+ cpunum=1/cpufreq
+ cpunum=1
+ IsANumber 1
+ return 0
+ eval done_this=$hw_cpu_1_done
+ done_this=
+ [ x = xcpudone ]
+ cat /sys/devices/system/cpu/cpu1/cpufreq/affected_cpus
+ IsANumber 1
+ return 0
+ eval hw_cpu_1_done=cpudone
+ hw_cpu_1_done=cpudone
+ cat /sys/devices/system/cpu/cpu1/cpufreq/scaling_max_freq
+ max_freq=2101000
+ cat /sys/devices/system/cpu/cpu1/cpufreq/scaling_min_freq
+ min_freq=800000
+ [ -f /sys/devices/system/cpu/cpu1/cpufreq/scaling_setspeed ]
+ cat /sys/devices/system/cpu/cpu1/cpufreq/scaling_setspeed
+ setspeed=<unsupported>
+ cat /sys/devices/system/cpu/cpu1/cpufreq/scaling_governor
+ governor=ondemand
+ cat
+ grep -q performance /sys/devices/system/cpu/cpu1/cpufreq/scaling_available_governors
+ echo performance
+ echo 2101000
+ vecho 2 Switched to performance, with min freq at 2101000
+ local v
+ v=2
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.13 Switched to performance, with min freq at 2101000
+ [ 2 -le 4 ]
+ echo Nov 10 17:56:43.13 Switched to performance, with min freq at 2101000
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("98TuxOnIceConfigSet", 1, 2)}
+ new_CHAIN_UP_TO=98
+ [ -n 98 ]
+ CHAIN_UP_TO=98
+ bit=TuxOnIceConfigSet
+ vecho 1 hibernate: [98] Executing TuxOnIceConfigSet ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.14 hibernate: [98] Executing TuxOnIceConfigSet ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.14 hibernate: [98] Executing TuxOnIceConfigSet ...
+ [ -n  ]
+ TuxOnIceConfigSet
+ [ x = xnocache ]
+ [ -n  ]
+ [ -n 0 ]
+ [ -f /sys/power/tuxonice/reboot ]
+ echo 0
+ [ -n 1 ]
+ [ -f /sys/power/tuxonice/user_interface/enable_escape ]
+ echo 1
+ [ -n 1 ]
+ [ -f /sys/power/tuxonice/user_interface/default_console_level ]
+ echo 1
+ [ -n  ]
+ [ -n swap:/dev/sda5 ]
+ [ -f /sys/power/tuxonice/resume ]
+ echo swap:/dev/sda5
+ [ -n swap:/dev/sda5 ]
+ [ -f /sys/power/tuxonice/resume2 ]
+ [ -n  ]
+ TuxOnIceSetupCryptoAPI
+ TuxOnIceIsAtLeastVersion 33622277
+ awk BEGIN{FS="[^0-9]"}{print($1*16777216)+($2*65536)+($3*256)+$4} /sys/power/tuxonice/version
+ ver=50528256
+ [ 50528256 -ge 33622277 ]
+ return 0
+ TUXONICE_MODULES_LOADED=
+ [ -n lzo ]
+ [ lzo != none ]
+ grep -q ^name.*: lzo$ /proc/crypto
+ [ lzo != none ]
+ compression_algorithm=lzo
+ disable_value=0
+ [ -f /sys/power/tuxonice/compression/disable_compression ]
+ [ -f /sys/power/tuxonice/compression/enabled ]
+ echo 1
+ [ -f /sys/power/tuxonice/compression/compressor ]
+ [ -f /sys/power/tuxonice/compression/algorithm ]
+ echo lzo
+ [ -n none ]
+ [ none != none ]
+ [ none != none ]
+ encryption_algorithm=
+ disable_value=1
+ [ -f /sys/power/tuxonice/disable_encryption ]
+ [ -f /sys/power/tuxonice/enabled ]
+ [ -f /sys/power/tuxonice/encryptor ]
+ [ -f /sys/power/tuxonice/algorithm ]
+ [ -n /tmp/tmp.hibernate.GFeFNE ]
+ [ -f /tmp/tmp.hibernate.GFeFNE ]
+ . /tmp/tmp.hibernate.GFeFNE
+ echo 7500
+ echo 1
+ echo 7500
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ local new_CHAIN_UP_TO
+ awk BEGIN{print substr("99DoTuxOnIce", 1, 2)}
+ new_CHAIN_UP_TO=99
+ [ -n 99 ]
+ CHAIN_UP_TO=99
+ bit=DoTuxOnIce
+ vecho 1 hibernate: [99] Executing DoTuxOnIce ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.16 hibernate: [99] Executing DoTuxOnIce ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.16 hibernate: [99] Executing DoTuxOnIce ...
+ [ -n  ]
+ DoTuxOnIce
+ local error
+ [ -n  ]
+ [ -z  ]
+ vecho 1 hibernate: Activating TuxOnIce ...
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:56:43.16 hibernate: Activating TuxOnIce ...
+ [ 1 -le 4 ]
+ echo Nov 10 17:56:43.16 hibernate: Activating TuxOnIce ...
+ SaveDmesg
+ mktemp /tmp/tmp.hibernate.XXXXXX
+ DMESG_ORIG=/tmp/tmp.hibernate.mofxLo
+ dmesg
+ return 0
+ DoSuspend
+ [ -f /sys/power/tuxonice/do_hibernate ]
+ echo
+ read REPLY
+ echo 0
+ return 0
+ error=0
+ [ -n 0 ]
+ [ 0 -ne 0 ]
+ PrintErrors 0
+ local code bit_num
+ code=0
+ [ -n 0 ]
+ [ 0 -eq 0 ]
+ return 0
+ [ -n  ]
+ CleanupDmesg
+ [ -n /tmp/tmp.hibernate.mofxLo ]
+ rm -f /tmp/tmp.hibernate.mofxLo
+ return 0
+ [ -f /sys/power/tuxonice/freezer_test ]
+ echo 0
+ [ -n  ]
+ return 0
+ ret=0
+ [ 0 -ge 2 ]
+ [ 0 -gt 0 ]
+ [ -n  ]
+ SortResumeBits
+ /bin/echo -ne 90ModulesLoad\n12IbmAcpiEndResume\n85XHacksResumeHook2\n11XHacksResumeHook1\n98FullSpeedCPUResume\n00RemoveTuxOnIceProcCruft\n97ChangeFromTuxOnIceVT\n59RemountXFSBootRW\n89RestoreKernelModprobe\n01NoteLastResume\n01LockFilePut\n
+ sort -rn
+ awk BEGIN{print substr("98FullSpeedCPUResume", 1, 2)}
+ THIS_POS=98
+ [ -z 98 ]
+ bit=FullSpeedCPUResume
+ [ 98 -gt 99 ]
+ vecho 1 hibernate: [98] Executing FullSpeedCPUResume ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:04.95 hibernate: [98] Executing FullSpeedCPUResume ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:04.95 hibernate: [98] Executing FullSpeedCPUResume ...
+ [ -n  ]
+ FullSpeedCPUResume
+ [ -f /tmp/tmp.hibernate.YxHIL6 ]
+ . /tmp/tmp.hibernate.YxHIL6
+ echo 800000
+ echo ondemand
+ [ -f /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed ]
+ echo <unsupported>
+ echo 800000
+ echo ondemand
+ [ -f /sys/devices/system/cpu/cpu1/cpufreq/scaling_setspeed ]
+ echo <unsupported>
+ rm -f /tmp/tmp.hibernate.YxHIL6
+ return 0
+ awk BEGIN{print substr("97ChangeFromTuxOnIceVT", 1, 2)}
+ THIS_POS=97
+ [ -z 97 ]
+ bit=ChangeFromTuxOnIceVT
+ [ 97 -gt 99 ]
+ vecho 1 hibernate: [97] Executing ChangeFromTuxOnIceVT ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.18 hibernate: [97] Executing ChangeFromTuxOnIceVT ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.18 hibernate: [97] Executing ChangeFromTuxOnIceVT ...
+ [ -n  ]
+ ChangeFromTuxOnIceVT
+ [ -n  ]
+ return 0
+ awk BEGIN{print substr("90ModulesLoad", 1, 2)}
+ THIS_POS=90
+ [ -z 90 ]
+ bit=ModulesLoad
+ [ 90 -gt 99 ]
+ vecho 1 hibernate: [90] Executing ModulesLoad ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.18 hibernate: [90] Executing ModulesLoad ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.18 hibernate: [90] Executing ModulesLoad ...
+ [ -n  ]
+ ModulesLoad
+ [ -z  auto ]
+ CheckModuleSupport
+ [ -f /proc/modules ]
+ return 0
+ RestoreKernelModprobe
+ [ -n /sbin/modprobe ]
+ echo /sbin/modprobe
+ unset KERNEL_MODPROBE
+ [ -n  ]
+ return 0
+ local mod
+ [ auto = auto ]
+ continue
+ return 0
+ awk BEGIN{print substr("89RestoreKernelModprobe", 1, 2)}
+ THIS_POS=89
+ [ -z 89 ]
+ bit=RestoreKernelModprobe
+ [ 89 -gt 99 ]
+ vecho 1 hibernate: [89] Executing RestoreKernelModprobe ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.19 hibernate: [89] Executing RestoreKernelModprobe ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.19 hibernate: [89] Executing RestoreKernelModprobe ...
+ [ -n  ]
+ RestoreKernelModprobe
+ [ -n  ]
+ [ -n  ]
+ return 0
+ awk BEGIN{print substr("85XHacksResumeHook2", 1, 2)}
+ THIS_POS=85
+ [ -z 85 ]
+ bit=XHacksResumeHook2
+ [ 85 -gt 99 ]
+ vecho 1 hibernate: [85] Executing XHacksResumeHook2 ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.19 hibernate: [85] Executing XHacksResumeHook2 ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.19 hibernate: [85] Executing XHacksResumeHook2 ...
+ [ -n  ]
+ XHacksResumeHook2
+ [ -z  ]
+ XHacksResume
+ [ x = x1 ]
+ [ -n 1 ]
+ vecho 3 xhacks: changing to text mode
+ local v
+ v=3
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.20 xhacks: changing to text mode
+ [ 3 -le 4 ]
+ echo Nov 10 17:59:05.20 xhacks: changing to text mode
+ local dest_vt
+ [ -z  ]
+ dest_vt=15
+ chvt 15
+ [ -n 1 ]
+ vecho 3 xhacks: changing console back to 1
+ local v
+ v=3
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.39 xhacks: changing console back to 1
+ [ 3 -le 4 ]
+ echo Nov 10 17:59:05.39 xhacks: changing console back to 1
+ chvt 1
+ return 0
+ awk BEGIN{print substr("59RemountXFSBootRW", 1, 2)}
+ THIS_POS=59
+ [ -z 59 ]
+ bit=RemountXFSBootRW
+ [ 59 -gt 99 ]
+ vecho 1 hibernate: [59] Executing RemountXFSBootRW ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.40 hibernate: [59] Executing RemountXFSBootRW ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.40 hibernate: [59] Executing RemountXFSBootRW ...
+ [ -n  ]
+ RemountXFSBootRW
+ [  = 1 ]
+ awk BEGIN{print substr("12IbmAcpiEndResume", 1, 2)}
+ THIS_POS=12
+ [ -z 12 ]
+ bit=IbmAcpiEndResume
+ [ 12 -gt 99 ]
+ vecho 1 hibernate: [12] Executing IbmAcpiEndResume ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.41 hibernate: [12] Executing IbmAcpiEndResume ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.41 hibernate: [12] Executing IbmAcpiEndResume ...
+ [ -n  ]
+ IbmAcpiEndResume
+ IbmAcpiLed 7 off
+ [ -f /proc/acpi/ibm/led ]
+ echo 7 off
+ [ 0 -gt 1 ]
+ return 0
+ awk BEGIN{print substr("11XHacksResumeHook1", 1, 2)}
+ THIS_POS=11
+ [ -z 11 ]
+ bit=XHacksResumeHook1
+ [ 11 -gt 99 ]
+ vecho 1 hibernate: [11] Executing XHacksResumeHook1 ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.42 hibernate: [11] Executing XHacksResumeHook1 ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.42 hibernate: [11] Executing XHacksResumeHook1 ...
+ [ -n  ]
+ XHacksResumeHook1
+ [ -n  ]
+ return 0
+ awk BEGIN{print substr("01NoteLastResume", 1, 2)}
+ THIS_POS=01
+ [ -z 01 ]
+ bit=NoteLastResume
+ [ 01 -gt 99 ]
+ vecho 1 hibernate: [01] Executing NoteLastResume ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.43 hibernate: [01] Executing NoteLastResume ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.43 hibernate: [01] Executing NoteLastResume ...
+ [ -n  ]
+ NoteLastResume
+ [ -f /var/run/hibernate-last-resume ]
+ date +%s
+ return 0
+ awk BEGIN{print substr("01LockFilePut", 1, 2)}
+ THIS_POS=01
+ [ -z 01 ]
+ bit=LockFilePut
+ [ 01 -gt 99 ]
+ vecho 1 hibernate: [01] Executing LockFilePut ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.44 hibernate: [01] Executing LockFilePut ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.44 hibernate: [01] Executing LockFilePut ...
+ [ -n  ]
+ LockFilePut
+ [ -z 1 ]
+ local lockfile_pid
+ read lockfile_pid
+ IsANumber 3922
+ return 0
+ [ 3922 -eq 3922 ]
+ rm -f /var/run/hibernate-script.pid
+ return 0
+ awk BEGIN{print substr("00RemoveTuxOnIceProcCruft", 1, 2)}
+ THIS_POS=00
+ [ -z 00 ]
+ bit=RemoveTuxOnIceProcCruft
+ [ 00 -gt 99 ]
+ vecho 1 hibernate: [00] Executing RemoveTuxOnIceProcCruft ... 
+ local v
+ v=1
+ shift
+ [ x1 = x1 ]
+ date +%b %e %H:%M:%S.%2N
+ set -- Nov 10 17:59:05.44 hibernate: [00] Executing RemoveTuxOnIceProcCruft ... 
+ [ 1 -le 4 ]
+ echo Nov 10 17:59:05.44 hibernate: [00] Executing RemoveTuxOnIceProcCruft ...
+ [ -n  ]
+ RemoveTuxOnIceProcCruft
+ [ -f /tmp/tmp.hibernate.GFeFNE ]
+ rm -f /tmp/tmp.hibernate.GFeFNE
+ return 0
+ return 0
+ echo EXIT_CODE=0
+ eval EXIT_CODE=0
+ EXIT_CODE=0
+ PluginTermination
+ local i
+ TuxOnIceTermination
+ return 0
+ return 0
+ tee -a -i /var/log/hibernate.log
+ date
+ echo Resumed at Sat 10 Nov 17:59:05 CET 2012
+ exit 0

# 4  
Old 11-10-2012
Because Tux is not doing "something" does not mean that something is not going on.

I am assuming you got Tux pre-built into the kernel.

Unless you can produce data from all other processes and the kernel showing that cpu usage is zero you need to reconsider what is going on. A blank time period in a log or on the screen is meaningless if other operations are going on. I am being somewhat facetitious - however just because you don't like my answer is not a reason to dismiss it. My experience with Tux was that processes got hung up.

Tuxonice is part of the kernel, either by insmod or pre-built. On hibernate it stores current system state on disk, and powers down. On power up it boots the kernel then restores system state from disk.
It is a nifty idea, but IMO, apparently runs afoul of some kinds of system software (add on kernel modules for one).

Let's look at the boot log:
Code:
dmesg | less
less /var/log/boot.log
# and also in case you bounced the system so many times something important got aged off
ls -l /var/log/boot*

Please post what you see.

If this does not work for you then try the TUX website.
# 5  
Old 11-11-2012
Thanks for the reply.

I am fairly aware of how Tux works and I used to have it resume normally in the long, distant past. I know that it is not 'nothing' going on, but what is going on has nothing to do with normal operations like image read or processing stuff. Nothing can be processed on resume in three equal stages of 30 seconds each, and without ANY disk activity.

$ ls -l /var/log/boot*
-rw-r--r-- 1 root root 224621 Oct 26 01:01 /var/log/boot
-rw-r--r-- 1 root root 82467 Sep 27 19:47 /var/log/boot.1.gz

Code:
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Linux version 3.6-pf (juha@panzor) (gcc version 4.7.2 (GCC) ) #1 SMP PREEMPT Wed Nov 7 14:35:09 CET 2012
[    0.000000] Command line: root=/dev/sda2 ro loglevel=3 sr0=ide-scsi pcie_aspm=force i915.i915_enable_rc6=1 vga=0x0369 resume=swap:/dev/sda5 init=/usr/lib/systemd/systemd
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009d7ff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009d800-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000e0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bfeaffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000bfeb0000-0x00000000bfecbfff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000bfecc000-0x00000000bfefffff] ACPI NVS
[    0.000000] BIOS-e820: [mem 0x00000000bff00000-0x00000000bfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000f0000000-0x00000000f3ffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fec00000-0x00000000fec0ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fed00000-0x00000000fed003ff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fed14000-0x00000000fed19fff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fed1c000-0x00000000fed8ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fee00000-0x00000000fee00fff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000ff000000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000013fffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI present.
[    0.000000] DMI: LENOVO 8918DEG/8918DEG, BIOS 7KETC9WW (2.29 ) 04/07/2010
[    0.000000] e820: update [mem 0x00000000-0x0000ffff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] No AGP bridge found
[    0.000000] e820: last_pfn = 0x140000 max_arch_pfn = 0x400000000
[    0.000000] MTRR default type: uncachable
[    0.000000] MTRR fixed ranges enabled:
[    0.000000]   00000-9FFFF write-back
[    0.000000]   A0000-BFFFF uncachable
[    0.000000]   C0000-CFFFF write-protect
[    0.000000]   D0000-DFFFF uncachable
[    0.000000]   E0000-FFFFF write-protect
[    0.000000] MTRR variable ranges enabled:
[    0.000000]   0 base 0C0000000 mask FC0000000 uncachable
[    0.000000]   1 base 000000000 mask F00000000 write-back
[    0.000000]   2 base 100000000 mask FC0000000 write-back
[    0.000000]   3 base 0BFF00000 mask FFFF00000 uncachable
[    0.000000]   4 disabled
[    0.000000]   5 disabled
[    0.000000]   6 disabled
[    0.000000]   7 disabled
[    0.000000] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[    0.000000] e820: update [mem 0xbff00000-0xffffffff] usable ==> reserved
[    0.000000] e820: last_pfn = 0xbfeb0 max_arch_pfn = 0x400000000
[    0.000000] found SMP MP-table at [mem 0x000f69e0-0x000f69ef] mapped at [ffff8800000f69e0]
[    0.000000] initial memory mapped: [mem 0x00000000-0x1fffffff]
[    0.000000] Base memory trampoline at [ffff880000097000] 97000 size 24576
[    0.000000] init_memory_mapping: [mem 0x00000000-0xbfeaffff]
[    0.000000]  [mem 0x00000000-0xbfdfffff] page 2M
[    0.000000]  [mem 0xbfe00000-0xbfeaffff] page 4k
[    0.000000] kernel direct mapping tables up to 0xbfeaffff @ [mem 0x1fffb000-0x1fffffff]
[    0.000000] init_memory_mapping: [mem 0x100000000-0x13fffffff]
[    0.000000]  [mem 0x100000000-0x13fffffff] page 2M
[    0.000000] kernel direct mapping tables up to 0x13fffffff @ [mem 0xbfeae000-0xbfeaffff]
[    0.000000] RAMDISK: [mem 0x37d06000-0x37feffff]
[    0.000000] ACPI: RSDP 00000000000f69b0 00024 (v02 LENOVO)
[    0.000000] ACPI: XSDT 00000000bfebb100 00094 (v01 LENOVO TP-7V    00002290  LTP 00000000)
[    0.000000] ACPI: FACP 00000000bfebb200 000F4 (v03 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI BIOS Bug: Warning: 32/64X length mismatch in FADT/Gpe1Block: 0/32 (20120711/tbfadt-567)
[    0.000000] ACPI BIOS Bug: Warning: Optional FADT field Gpe1Block has zero address or length: 0x000000000000102C/0x0 (20120711/tbfadt-598)
[    0.000000] ACPI: DSDT 00000000bfebb61d 1044C (v01 LENOVO TP-7V    00002290 MSFT 03000000)
[    0.000000] ACPI: FACS 00000000bfee4000 00040
[    0.000000] ACPI: SSDT 00000000bfebb3b4 00269 (v01 LENOVO TP-7V    00002290 MSFT 03000000)
[    0.000000] ACPI: ECDT 00000000bfecba69 00052 (v01 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI: TCPA 00000000bfecbabb 00032 (v02 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI: APIC 00000000bfecbaed 00068 (v01 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI: MCFG 00000000bfecbb55 0003C (v01 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI: HPET 00000000bfecbb91 00038 (v01 LENOVO TP-7V    00002290 LNVO 00000001)
[    0.000000] ACPI: SLIC 00000000bfecbbc9 00176 (v01 LENOVO TP-7V    00002290 SLIC 00000000)
[    0.000000] ACPI: SLAC 00000000bfecbe62 00176 (v01 LENOVO TP-7V    00002290  LTP 00000000)
[    0.000000] ACPI: BOOT 00000000bfecbfd8 00028 (v01 LENOVO TP-7V    00002290  LTP 00000001)
[    0.000000] ACPI: SSDT 00000000bfee26d9 0025F (v01 LENOVO TP-7V    00002290 INTL 20050513)
[    0.000000] ACPI: SSDT 00000000bfee2938 000A6 (v01 LENOVO TP-7V    00002290 INTL 20050513)
[    0.000000] ACPI: SSDT 00000000bfee29de 004F7 (v01 LENOVO TP-7V    00002290 INTL 20050513)
[    0.000000] ACPI: SSDT 00000000bfee2ed5 001D8 (v01 LENOVO TP-7V    00002290 INTL 20050513)
[    0.000000] ACPI: DMI detected: Lenovo ThinkPad R61
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000013fffffff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x13fffffff]
[    0.000000]   NODE_DATA [mem 0x13fffc000-0x13fffffff]
[    0.000000]  [ffffea0000000000-ffffea0004ffffff] PMD -> [ffff88013b600000-ffff88013f5fffff] on node 0
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x00010000-0x00ffffff]
[    0.000000]   DMA32    [mem 0x01000000-0xffffffff]
[    0.000000]   Normal   [mem 0x100000000-0x13fffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x00010000-0x0009cfff]
[    0.000000]   node   0: [mem 0x00100000-0xbfeaffff]
[    0.000000]   node   0: [mem 0x100000000-0x13fffffff]
[    0.000000] On node 0 totalpages: 1048125
[    0.000000]   DMA zone: 64 pages used for memmap
[    0.000000]   DMA zone: 6 pages reserved
[    0.000000]   DMA zone: 3911 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 16320 pages used for memmap
[    0.000000]   DMA32 zone: 765680 pages, LIFO batch:31
[    0.000000]   Normal zone: 4096 pages used for memmap
[    0.000000]   Normal zone: 258048 pages, LIFO batch:31
[    0.000000] ACPI: PM-Timer IO Port: 0x1008
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
[    0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
[    0.000000] IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ2 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.000000] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[    0.000000] nr_irqs_gsi: 40
[    0.000000] PM: Registered nosave memory: 000000000009d000 - 000000000009e000
[    0.000000] PM: Registered nosave memory: 000000000009e000 - 00000000000a0000
[    0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000e0000
[    0.000000] PM: Registered nosave memory: 00000000000e0000 - 0000000000100000
[    0.000000] PM: Registered nosave memory: 00000000bfeb0000 - 00000000bfecc000
[    0.000000] PM: Registered nosave memory: 00000000bfecc000 - 00000000bff00000
[    0.000000] PM: Registered nosave memory: 00000000bff00000 - 00000000c0000000
[    0.000000] PM: Registered nosave memory: 00000000c0000000 - 00000000f0000000
[    0.000000] PM: Registered nosave memory: 00000000f0000000 - 00000000f4000000
[    0.000000] PM: Registered nosave memory: 00000000f4000000 - 00000000fec00000
[    0.000000] PM: Registered nosave memory: 00000000fec00000 - 00000000fec10000
[    0.000000] PM: Registered nosave memory: 00000000fec10000 - 00000000fed00000
[    0.000000] PM: Registered nosave memory: 00000000fed00000 - 00000000fed14000
[    0.000000] PM: Registered nosave memory: 00000000fed14000 - 00000000fed1a000
[    0.000000] PM: Registered nosave memory: 00000000fed1a000 - 00000000fed1c000
[    0.000000] PM: Registered nosave memory: 00000000fed1c000 - 00000000fed90000
[    0.000000] PM: Registered nosave memory: 00000000fed90000 - 00000000fee00000
[    0.000000] PM: Registered nosave memory: 00000000fee00000 - 00000000fee01000
[    0.000000] PM: Registered nosave memory: 00000000fee01000 - 00000000ff000000
[    0.000000] PM: Registered nosave memory: 00000000ff000000 - 0000000100000000
[    0.000000] e820: [mem 0xc0000000-0xefffffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on bare hardware
[    0.000000] setup_percpu: NR_CPUS:4 nr_cpumask_bits:4 nr_cpu_ids:2 nr_node_ids:1
[    0.000000] PERCPU: Embedded 28 pages/cpu @ffff88013fc00000 s82240 r8192 d24256 u1048576
[    0.000000] pcpu-alloc: s82240 r8192 d24256 u1048576 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 0 1 
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 1027639
[    0.000000] Policy zone: Normal
[    0.000000] Kernel command line: root=/dev/sda2 ro loglevel=3 sr0=ide-scsi pcie_aspm=force i915.i915_enable_rc6=1 vga=0x0369 resume=swap:/dev/sda5 init=/usr/lib/systemd/systemd
[    0.000000] PCIe ASPM is forcibly enabled
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] __ex_table already sorted, skipping sort
[    0.000000] Checking aperture...
[    0.000000] No AGP bridge found
[    0.000000] Calgary: detecting Calgary via BIOS EBDA area
[    0.000000] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
[    0.000000] Memory: 4046496k/5242880k available (4580k kernel code, 1050380k absent, 146004k reserved, 4268k data, 764k init)
[    0.000000] SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] 	RCU dyntick-idle grace-period acceleration is enabled.
[    0.000000] 	Dump stacks of tasks blocking RCU-preempt GP.
[    0.000000] NR_IRQS:4352 nr_irqs:712 16
[    0.000000] Extended CMOS year: 2000
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [tty0] enabled
[    0.000000] hpet clockevent registered
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] tsc: Detected 2094.652 MHz processor
[    0.001004] Calibrating delay loop (skipped), value calculated using timer frequency.. 4189.30 BogoMIPS (lpj=2094652)
[    0.001007] pid_max: default: 32768 minimum: 301
[    0.001037] Security Framework initialized
[    0.001042] AppArmor: AppArmor disabled by boot time parameter
[    0.001347] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    0.003936] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.005084] Mount-cache hash table entries: 256
[    0.005338] Initializing cgroup subsys devices
[    0.005342] Initializing cgroup subsys freezer
[    0.005344] Initializing cgroup subsys net_cls
[    0.005345] Initializing cgroup subsys blkio
[    0.005348] Initializing cgroup subsys bfqio
[    0.005378] CPU: Physical Processor ID: 0
[    0.005379] CPU: Processor Core ID: 0
[    0.005381] mce: CPU supports 6 MCE banks
[    0.005390] CPU0: Thermal monitoring enabled (TM2)
[    0.005395] process: using mwait in idle threads
[    0.005400] Last level iTLB entries: 4KB 128, 2MB 4, 4MB 4
Last level dTLB entries: 4KB 256, 2MB 0, 4MB 32
tlb_flushall_shift is 0xffffffff
[    0.006704] ACPI: Core revision 20120711
[    0.014014] ftrace: allocating 17765 entries in 70 pages
[    0.020178] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.030181] smpboot: CPU0: Intel(R) Core(TM)2 Duo CPU     T8100  @ 2.10GHz stepping 06
[    0.030995] Performance Events: PEBS fmt0+, 4-deep LBR, Core2 events, Intel PMU driver.
[    0.030995] ... version:                2
[    0.030995] ... bit width:              40
[    0.030995] ... generic registers:      2
[    0.030995] ... value mask:             000000ffffffffff
[    0.030995] ... max period:             000000007fffffff
[    0.030995] ... fixed-purpose events:   3
[    0.030995] ... event mask:             0000000700000003
[    0.034108] NMI watchdog: enabled on all CPUs, permanently consumes one hw-PMU counter.
[    0.038002] smpboot: Booting Node   0, Processors  #1
[    0.049992] TSC synchronization [CPU#0 -> CPU#1]:
[    0.049992] Measured 384510 cycles TSC warp between CPUs, turning off TSC clock.
[    0.049992] tsc: Marking TSC unstable due to check_tsc_sync_source failed
[    0.050083] Brought up 2 CPUs
[    0.050086] smpboot: Total of 2 processors activated (8378.60 BogoMIPS)
[    0.051201] devtmpfs: initialized
[    0.052794] PM: Registering ACPI NVS region [mem 0xbfecc000-0xbfefffff] (212992 bytes)
[    0.053602] NET: Registered protocol family 16
[    0.053771] ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
[    0.053773] ACPI: bus type pci registered
[    0.053846] PCI: MMCONFIG for domain 0000 [bus 00-3f] at [mem 0xf0000000-0xf3ffffff] (base 0xf0000000)
[    0.053849] PCI: MMCONFIG at [mem 0xf0000000-0xf3ffffff] reserved in E820
[    0.059898] PCI: Using configuration type 1 for base access
[    0.060497] bio: create slab <bio-0> at 0
[    0.060561] ACPI: Added _OSI(Module Device)
[    0.060563] ACPI: Added _OSI(Processor Device)
[    0.060565] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.060567] ACPI: Added _OSI(Processor Aggregator Device)
[    0.060568] ACPI: Added _OSI(Linux)
[    0.062613] ACPI: EC: EC description table is found, configuring boot EC
[    0.068056] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query honored via DMI
[    0.074392] ACPI: SSDT 00000000bfee1b32 002C4 (v01  PmRef  Cpu0Ist 00000100 INTL 20050513)
[    0.075281] ACPI: Dynamic OEM Table Load:
[    0.075285] ACPI: SSDT           (null) 002C4 (v01  PmRef  Cpu0Ist 00000100 INTL 20050513)
[    0.075417] ACPI: SSDT 00000000bfee1e7b 0085E (v01  PmRef  Cpu0Cst 00000100 INTL 20050513)
[    0.075944] ACPI: Dynamic OEM Table Load:
[    0.075947] ACPI: SSDT           (null) 0085E (v01  PmRef  Cpu0Cst 00000100 INTL 20050513)
[    0.076055] ACPI: SSDT 00000000bfee1a6a 000C8 (v01  PmRef  Cpu1Ist 00000100 INTL 20050513)
[    0.076550] ACPI: Dynamic OEM Table Load:
[    0.076553] ACPI: SSDT           (null) 000C8 (v01  PmRef  Cpu1Ist 00000100 INTL 20050513)
[    0.076633] ACPI: SSDT 00000000bfee1df6 00085 (v01  PmRef  Cpu1Cst 00000100 INTL 20050513)
[    0.077122] ACPI: Dynamic OEM Table Load:
[    0.077125] ACPI: SSDT           (null) 00085 (v01  PmRef  Cpu1Cst 00000100 INTL 20050513)
[    0.077180] ACPI: Interpreter enabled
[    0.077184] ACPI: (supports S0 S3 S4 S5)
[    0.077200] ACPI: Using IOAPIC for interrupt routing
[    0.080296] ACPI: Power Resource [PUBS] (on)
[    0.084138] ACPI: EC: GPE = 0x12, I/O: command/status = 0x66, data = 0x62
[    0.086122] ACPI: ACPI Dock Station Driver: 3 docks/bays found
[    0.086127] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.086355] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.086391] pci_root PNP0A08:00: [Firmware Info]: MMCONFIG for domain 0000 [bus 00-3f] only partially covers this bridge
[    0.086427] PCI host bridge to bus 0000:00
[    0.086431] pci_bus 0000:00: busn_res: [bus 00-ff] is inserted under domain [bus 00-ff]
[    0.086433] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.086435] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7]
[    0.086438] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff]
[    0.086440] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff]
[    0.086442] pci_bus 0000:00: root bus resource [mem 0x000d0000-0x000d3fff]
[    0.086445] pci_bus 0000:00: root bus resource [mem 0x000d4000-0x000d7fff]
[    0.086447] pci_bus 0000:00: root bus resource [mem 0x000d8000-0x000dbfff]
[    0.086449] pci_bus 0000:00: root bus resource [mem 0x000dc000-0x000dffff]
[    0.086452] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff]
[    0.086454] pci_bus 0000:00: root bus resource [mem 0xfed40000-0xfed4bfff]
[    0.086464] pci 0000:00:00.0: [8086:2a00] type 00 class 0x060000
[    0.086513] pci 0000:00:01.0: [8086:2a01] type 01 class 0x060400
[    0.086558] pci 0000:00:01.0: PME# supported from D0 D3hot D3cold
[    0.086677] pci 0000:00:19.0: [8086:104d] type 00 class 0x020000
[    0.086721] pci 0000:00:19.0: reg 10: [mem 0xfe200000-0xfe21ffff]
[    0.086735] pci 0000:00:19.0: reg 14: [mem 0xfe224000-0xfe224fff]
[    0.086754] pci 0000:00:19.0: reg 18: [io  0x1800-0x181f]
[    0.086915] pci 0000:00:19.0: PME# supported from D0 D3hot D3cold
[    0.087021] pci 0000:00:1a.0: [8086:2834] type 00 class 0x0c0300
[    0.087133] pci 0000:00:1a.0: reg 20: [io  0x1820-0x183f]
[    0.087221] pci 0000:00:1a.1: [8086:2835] type 00 class 0x0c0300
[    0.087328] pci 0000:00:1a.1: reg 20: [io  0x1840-0x185f]
[    0.087438] pci 0000:00:1a.7: [8086:283a] type 00 class 0x0c0320
[    0.087470] pci 0000:00:1a.7: reg 10: [mem 0xfe225800-0xfe225bff]
[    0.087643] pci 0000:00:1a.7: PME# supported from D0 D3hot D3cold
[    0.087697] pci 0000:00:1b.0: [8086:284b] type 00 class 0x040300
[    0.087732] pci 0000:00:1b.0: reg 10: [mem 0xfe220000-0xfe223fff 64bit]
[    0.087873] pci 0000:00:1b.0: PME# supported from D0 D3hot D3cold
[    0.087924] pci 0000:00:1c.0: [8086:283f] type 01 class 0x060400
[    0.088060] pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
[    0.088113] pci 0000:00:1c.1: [8086:2841] type 01 class 0x060400
[    0.088243] pci 0000:00:1c.1: PME# supported from D0 D3hot D3cold
[    0.088292] pci 0000:00:1c.2: [8086:2843] type 01 class 0x060400
[    0.088425] pci 0000:00:1c.2: PME# supported from D0 D3hot D3cold
[    0.088474] pci 0000:00:1c.3: [8086:2845] type 01 class 0x060400
[    0.088600] pci 0000:00:1c.3: PME# supported from D0 D3hot D3cold
[    0.088649] pci 0000:00:1c.4: [8086:2847] type 01 class 0x060400
[    0.088779] pci 0000:00:1c.4: PME# supported from D0 D3hot D3cold
[    0.088832] pci 0000:00:1d.0: [8086:2830] type 00 class 0x0c0300
[    0.088952] pci 0000:00:1d.0: reg 20: [io  0x1860-0x187f]
[    0.089047] pci 0000:00:1d.1: [8086:2831] type 00 class 0x0c0300
[    0.089155] pci 0000:00:1d.1: reg 20: [io  0x1880-0x189f]
[    0.089244] pci 0000:00:1d.2: [8086:2832] type 00 class 0x0c0300
[    0.089357] pci 0000:00:1d.2: reg 20: [io  0x18a0-0x18bf]
[    0.089475] pci 0000:00:1d.7: [8086:2836] type 00 class 0x0c0320
[    0.089517] pci 0000:00:1d.7: reg 10: [mem 0xfe225c00-0xfe225fff]
[    0.089711] pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
[    0.089758] pci 0000:00:1e.0: [8086:2448] type 01 class 0x060401
[    0.089887] pci 0000:00:1f.0: [8086:2815] type 00 class 0x060100
[    0.090059] pci 0000:00:1f.0: quirk: [io  0x1000-0x107f] claimed by ICH6 ACPI/GPIO/TCO
[    0.090067] pci 0000:00:1f.0: quirk: [io  0x1180-0x11bf] claimed by ICH6 GPIO
[    0.090074] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 1 PIO at 1600 (mask 007f)
[    0.090080] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 2 PIO at 15e0 (mask 000f)
[    0.090086] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 3 PIO at 1680 (mask 001f)
[    0.090178] pci 0000:00:1f.1: [8086:2850] type 00 class 0x01018a
[    0.090211] pci 0000:00:1f.1: reg 10: [io  0x0000-0x0007]
[    0.090235] pci 0000:00:1f.1: reg 14: [io  0x0000-0x0003]
[    0.090258] pci 0000:00:1f.1: reg 18: [io  0x0000-0x0007]
[    0.090282] pci 0000:00:1f.1: reg 1c: [io  0x0000-0x0003]
[    0.090301] pci 0000:00:1f.1: reg 20: [io  0x18c0-0x18cf]
[    0.090397] pci 0000:00:1f.2: [8086:2829] type 00 class 0x010601
[    0.090430] pci 0000:00:1f.2: reg 10: [io  0x18f8-0x18ff]
[    0.090451] pci 0000:00:1f.2: reg 14: [io  0x18ec-0x18ef]
[    0.090464] pci 0000:00:1f.2: reg 18: [io  0x18f0-0x18f7]
[    0.090478] pci 0000:00:1f.2: reg 1c: [io  0x18e8-0x18eb]
[    0.090496] pci 0000:00:1f.2: reg 20: [io  0x1c00-0x1c1f]
[    0.090509] pci 0000:00:1f.2: reg 24: [mem 0xfe225000-0xfe2257ff]
[    0.090590] pci 0000:00:1f.2: PME# supported from D3hot
[    0.090625] pci 0000:00:1f.3: [8086:283e] type 00 class 0x0c0500
[    0.090648] pci 0000:00:1f.3: reg 10: [mem 0xfe226000-0xfe2260ff]
[    0.090696] pci 0000:00:1f.3: reg 20: [io  0x1c20-0x1c3f]
[    0.090781] pci_bus 0000:01: busn_res: [bus 01] is inserted under [bus 00-ff]
[    0.090806] pci 0000:01:00.0: [10de:0429] type 00 class 0x030000
[    0.090825] pci 0000:01:00.0: reg 10: [mem 0xd6000000-0xd6ffffff]
[    0.090847] pci 0000:01:00.0: reg 14: [mem 0xe0000000-0xefffffff 64bit pref]
[    0.090868] pci 0000:01:00.0: reg 1c: [mem 0xd4000000-0xd5ffffff 64bit]
[    0.090882] pci 0000:01:00.0: reg 24: [io  0x2000-0x207f]
[    0.090896] pci 0000:01:00.0: reg 30: [mem 0x00000000-0x0001ffff pref]
[    0.091006] pci 0000:00:01.0: PCI bridge to [bus 01]
[    0.091010] pci 0000:00:01.0:   bridge window [io  0x2000-0x2fff]
[    0.091014] pci 0000:00:01.0:   bridge window [mem 0xd4000000-0xd6ffffff]
[    0.091018] pci 0000:00:01.0:   bridge window [mem 0xe0000000-0xefffffff 64bit pref]
[    0.091086] pci_bus 0000:02: busn_res: [bus 02] is inserted under [bus 00-ff]
[    0.091092] pci 0000:00:1c.0: PCI bridge to [bus 02]
[    0.091099] pci 0000:00:1c.0:   bridge window [io  0x3000-0x3fff]
[    0.091108] pci 0000:00:1c.0:   bridge window [mem 0xfc000000-0xfdffffff]
[    0.091120] pci 0000:00:1c.0:   bridge window [mem 0xf8000000-0xf80fffff 64bit pref]
[    0.091189] pci_bus 0000:03: busn_res: [bus 03] is inserted under [bus 00-ff]
[    0.091261] pci 0000:03:00.0: [8086:4230] type 00 class 0x028000
[    0.091317] pci 0000:03:00.0: reg 10: [mem 0xdf2fe000-0xdf2fffff 64bit]
[    0.091538] pci 0000:03:00.0: PME# supported from D0 D3hot D3cold
[    0.093031] pci 0000:00:1c.1: PCI bridge to [bus 03]
[    0.093039] pci 0000:00:1c.1:   bridge window [io  0x4000-0x4fff]
[    0.093048] pci 0000:00:1c.1:   bridge window [mem 0xdc100000-0xdf2fffff]
[    0.093063] pci 0000:00:1c.1:   bridge window [mem 0xdfd00000-0xdfdfffff 64bit pref]
[    0.093137] pci_bus 0000:04: busn_res: [bus 04] is inserted under [bus 00-ff]
[    0.093143] pci 0000:00:1c.2: PCI bridge to [bus 04]
[    0.093152] pci 0000:00:1c.2:   bridge window [io  0x5000-0x5fff]
[    0.093159] pci 0000:00:1c.2:   bridge window [mem 0xd8000000-0xd9ffffff]
[    0.093176] pci 0000:00:1c.2:   bridge window [mem 0xdfa00000-0xdfafffff 64bit pref]
[    0.093242] pci_bus 0000:05: busn_res: [bus 05-0c] is inserted under [bus 00-ff]
[    0.093248] pci 0000:00:1c.3: PCI bridge to [bus 05-0c]
[    0.093257] pci 0000:00:1c.3:   bridge window [io  0x6000-0x6fff]
[    0.093264] pci 0000:00:1c.3:   bridge window [mem 0xd0000000-0xd1ffffff]
[    0.093274] pci 0000:00:1c.3:   bridge window [mem 0xdf700000-0xdf7fffff 64bit pref]
[    0.093344] pci_bus 0000:0d: busn_res: [bus 0d-14] is inserted under [bus 00-ff]
[    0.093350] pci 0000:00:1c.4: PCI bridge to [bus 0d-14]
[    0.093357] pci 0000:00:1c.4:   bridge window [io  0x7000-0x7fff]
[    0.093364] pci 0000:00:1c.4:   bridge window [mem 0xcc000000-0xcdffffff]
[    0.093374] pci 0000:00:1c.4:   bridge window [mem 0xdf400000-0xdf4fffff 64bit pref]
[    0.093415] pci_bus 0000:15: busn_res: [bus 15-18] is inserted under [bus 00-ff]
[    0.093442] pci 0000:15:00.0: [1180:0476] type 02 class 0x060700
[    0.093480] pci 0000:15:00.0: proprietary Ricoh MMC controller disabled (via cardbus function)
[    0.093482] pci 0000:15:00.0: MMC cards are now supported by standard SDHCI controller
[    0.093512] pci 0000:15:00.0: reg 10: [mem 0xf8100000-0xf8100fff]
[    0.093580] pci 0000:15:00.0: supports D1 D2
[    0.093582] pci 0000:15:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.093635] pci 0000:15:00.1: [1180:0832] type 00 class 0x0c0010
[    0.093679] pci 0000:15:00.1: reg 10: [mem 0xf8101000-0xf81017ff]
[    0.093863] pci 0000:15:00.1: supports D1 D2
[    0.093865] pci 0000:15:00.1: PME# supported from D0 D1 D2 D3hot D3cold
[    0.093912] pci 0000:15:00.2: [1180:0822] type 00 class 0x080500
[    0.093958] pci 0000:15:00.2: reg 10: [mem 0xf8101800-0xf81018ff]
[    0.094144] pci 0000:15:00.2: supports D1 D2
[    0.094147] pci 0000:15:00.2: PME# supported from D0 D1 D2 D3hot D3cold
[    0.094199] pci 0000:15:00.4: [1180:0592] type 00 class 0x088000
[    0.094243] pci 0000:15:00.4: reg 10: [mem 0xf8102000-0xf81020ff]
[    0.094439] pci 0000:15:00.4: supports D1 D2
[    0.094441] pci 0000:15:00.4: PME# supported from D0 D1 D2 D3hot D3cold
[    0.094484] pci 0000:15:00.5: [1180:0852] type 00 class 0x088000
[    0.094528] pci 0000:15:00.5: reg 10: [mem 0xf8102400-0xf81024ff]
[    0.094713] pci 0000:15:00.5: supports D1 D2
[    0.094715] pci 0000:15:00.5: PME# supported from D0 D1 D2 D3hot D3cold
[    0.094856] pci 0000:00:1e.0: PCI bridge to [bus 15-18] (subtractive decode)
[    0.094863] pci 0000:00:1e.0:   bridge window [io  0x8000-0xbfff]
[    0.094870] pci 0000:00:1e.0:   bridge window [mem 0xf8100000-0xfbffffff]
[    0.094880] pci 0000:00:1e.0:   bridge window [mem 0xf4000000-0xf7ffffff 64bit pref]
[    0.094882] pci 0000:00:1e.0:   bridge window [io  0x0000-0x0cf7] (subtractive decode)
[    0.094885] pci 0000:00:1e.0:   bridge window [io  0x0d00-0xffff] (subtractive decode)
[    0.094887] pci 0000:00:1e.0:   bridge window [mem 0x000a0000-0x000bffff] (subtractive decode)
[    0.094890] pci 0000:00:1e.0:   bridge window [mem 0x000d0000-0x000d3fff] (subtractive decode)
[    0.094892] pci 0000:00:1e.0:   bridge window [mem 0x000d4000-0x000d7fff] (subtractive decode)
[    0.094894] pci 0000:00:1e.0:   bridge window [mem 0x000d8000-0x000dbfff] (subtractive decode)
[    0.094896] pci 0000:00:1e.0:   bridge window [mem 0x000dc000-0x000dffff] (subtractive decode)
[    0.094899] pci 0000:00:1e.0:   bridge window [mem 0xc0000000-0xfebfffff] (subtractive decode)
[    0.094901] pci 0000:00:1e.0:   bridge window [mem 0xfed40000-0xfed4bfff] (subtractive decode)
[    0.094976] pci_bus 0000:16: busn_res: can not insert [bus 16-ff] under [bus 15-18] (conflicts with (null) [bus 15-18])
[    0.094988] pci_bus 0000:16: busn_res: [bus 16-ff] end is updated to 17
[    0.094991] pci_bus 0000:16: busn_res: [bus 16-17] is inserted under [bus 15-18]
[    0.095056] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[    0.095128] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGP_._PRT]
[    0.095157] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP0._PRT]
[    0.095182] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP1._PRT]
[    0.095207] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP2._PRT]
[    0.095231] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP3._PRT]
[    0.095259] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP4._PRT]
[    0.095286] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCI1._PRT]
[    0.095549]  pci0000:00: Requesting ACPI _OSC control (0x1d)
[    0.095910]  pci0000:00: ACPI _OSC control (0x1d) granted
[    0.100680] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 *10 11)
[    0.100747] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 *11)
[    0.100816] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11)
[    0.100880] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11)
[    0.100944] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 10 *11)
[    0.101014] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11)
[    0.101079] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 *11)
[    0.101143] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 *11)
[    0.101266] vgaarb: device added: PCI:0000:01:00.0,decodes=io+mem,owns=io+mem,locks=none
[    0.101271] vgaarb: loaded
[    0.101272] vgaarb: bridge control possible 0000:01:00.0
[    0.101323] PCI: Using ACPI for IRQ routing
[    0.103847] PCI: pci_cache_line_size set to 64 bytes
[    0.103980] e820: reserve RAM buffer [mem 0x0009d800-0x0009ffff]
[    0.103986] e820: reserve RAM buffer [mem 0xbfeb0000-0xbfffffff]
[    0.104094] NetLabel: Initializing
[    0.104095] NetLabel:  domain hash size = 128
[    0.104096] NetLabel:  protocols = UNLABELED CIPSOv4
[    0.104110] NetLabel:  unlabeled traffic allowed by default
[    0.104131] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[    0.104136] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[    0.104140] hpet0: 3 comparators, 64-bit 14.318180 MHz counter
[    0.109005] Switching to clocksource hpet
[    0.116502] pnp: PnP ACPI init
[    0.116528] ACPI: bus type pnp registered
[    0.116922] pnp 00:00: [mem 0x00000000-0x0009ffff]
[    0.116925] pnp 00:00: [mem 0x000c0000-0x000c3fff]
[    0.116927] pnp 00:00: [mem 0x000c4000-0x000c7fff]
[    0.116930] pnp 00:00: [mem 0x000c8000-0x000cbfff]
[    0.116932] pnp 00:00: [mem 0x000cc000-0x000cffff]
[    0.116934] pnp 00:00: [mem 0x000d0000-0x000cffff disabled]
[    0.116936] pnp 00:00: [mem 0x000d4000-0x000d3fff disabled]
[    0.116939] pnp 00:00: [mem 0x000d8000-0x000d7fff disabled]
[    0.116941] pnp 00:00: [mem 0x000dc000-0x000dbfff disabled]
[    0.116943] pnp 00:00: [mem 0x000e0000-0x000e3fff]
[    0.116945] pnp 00:00: [mem 0x000e4000-0x000e7fff]
[    0.116947] pnp 00:00: [mem 0x000e8000-0x000ebfff]
[    0.116949] pnp 00:00: [mem 0x000ec000-0x000effff]
[    0.116952] pnp 00:00: [mem 0x000f0000-0x000fffff]
[    0.116954] pnp 00:00: [mem 0x00100000-0xbfffffff]
[    0.116956] pnp 00:00: [mem 0xfec00000-0xfed3ffff]
[    0.116958] pnp 00:00: [mem 0xfed4c000-0xffffffff]
[    0.117069] system 00:00: [mem 0x00000000-0x0009ffff] could not be reserved
[    0.117073] system 00:00: [mem 0x000c0000-0x000c3fff] could not be reserved
[    0.117075] system 00:00: [mem 0x000c4000-0x000c7fff] could not be reserved
[    0.117078] system 00:00: [mem 0x000c8000-0x000cbfff] could not be reserved
[    0.117081] system 00:00: [mem 0x000cc000-0x000cffff] could not be reserved
[    0.117084] system 00:00: [mem 0x000e0000-0x000e3fff] could not be reserved
[    0.117086] system 00:00: [mem 0x000e4000-0x000e7fff] could not be reserved
[    0.117089] system 00:00: [mem 0x000e8000-0x000ebfff] could not be reserved
[    0.117092] system 00:00: [mem 0x000ec000-0x000effff] could not be reserved
[    0.117094] system 00:00: [mem 0x000f0000-0x000fffff] could not be reserved
[    0.117097] system 00:00: [mem 0x00100000-0xbfffffff] could not be reserved
[    0.117100] system 00:00: [mem 0xfec00000-0xfed3ffff] could not be reserved
[    0.117103] system 00:00: [mem 0xfed4c000-0xffffffff] could not be reserved
[    0.117107] system 00:00: Plug and Play ACPI device, IDs PNP0c01 (active)
[    0.117131] pnp 00:01: [bus 00-ff]
[    0.117134] pnp 00:01: [io  0x0cf8-0x0cff]
[    0.117136] pnp 00:01: [io  0x0000-0x0cf7 window]
[    0.117138] pnp 00:01: [io  0x0d00-0xffff window]
[    0.117141] pnp 00:01: [mem 0x000a0000-0x000bffff window]
[    0.117143] pnp 00:01: [mem 0x000c0000-0x000c3fff window]
[    0.117145] pnp 00:01: [mem 0x000c4000-0x000c7fff window]
[    0.117148] pnp 00:01: [mem 0x000c8000-0x000cbfff window]
[    0.117150] pnp 00:01: [mem 0x000cc000-0x000cffff window]
[    0.117152] pnp 00:01: [mem 0x000d0000-0x000d3fff window]
[    0.117154] pnp 00:01: [mem 0x000d4000-0x000d7fff window]
[    0.117156] pnp 00:01: [mem 0x000d8000-0x000dbfff window]
[    0.117159] pnp 00:01: [mem 0x000dc000-0x000dffff window]
[    0.117161] pnp 00:01: [mem 0x000e0000-0x000e3fff window]
[    0.117163] pnp 00:01: [mem 0x000e4000-0x000e7fff window]
[    0.117165] pnp 00:01: [mem 0x000e8000-0x000ebfff window]
[    0.117168] pnp 00:01: [mem 0x000ec000-0x000effff window]
[    0.117170] pnp 00:01: [mem 0xc0000000-0xfebfffff window]
[    0.117172] pnp 00:01: [mem 0xfed40000-0xfed4bfff window]
[    0.117244] pnp 00:01: Plug and Play ACPI device, IDs PNP0a08 PNP0a03 (active)
[    0.117284] pnp 00:02: [io  0x0010-0x001f]
[    0.117289] pnp 00:02: [io  0x0090-0x009f]
[    0.117291] pnp 00:02: [io  0x0024-0x0025]
[    0.117294] pnp 00:02: [io  0x0028-0x0029]
[    0.117296] pnp 00:02: [io  0x002c-0x002d]
[    0.117298] pnp 00:02: [io  0x0030-0x0031]
[    0.117300] pnp 00:02: [io  0x0034-0x0035]
[    0.117302] pnp 00:02: [io  0x0038-0x0039]
[    0.117304] pnp 00:02: [io  0x003c-0x003d]
[    0.117306] pnp 00:02: [io  0x00a4-0x00a5]
[    0.117308] pnp 00:02: [io  0x00a8-0x00a9]
[    0.117310] pnp 00:02: [io  0x00ac-0x00ad]
[    0.117312] pnp 00:02: [io  0x00b0-0x00b5]
[    0.117314] pnp 00:02: [io  0x00b8-0x00b9]
[    0.117316] pnp 00:02: [io  0x00bc-0x00bd]
[    0.117318] pnp 00:02: [io  0x0050-0x0053]
[    0.117320] pnp 00:02: [io  0x0072-0x0077]
[    0.117322] pnp 00:02: [io  0x164e-0x164f]
[    0.117324] pnp 00:02: [io  0x002e-0x002f]
[    0.117327] pnp 00:02: [io  0x1000-0x107f]
[    0.117329] pnp 00:02: [io  0x1180-0x11bf]
[    0.117331] pnp 00:02: [io  0x0800-0x080f]
[    0.117333] pnp 00:02: [io  0x15e0-0x15ef]
[    0.117335] pnp 00:02: [io  0x1600-0x165f]
[    0.117337] pnp 00:02: [mem 0xf0000000-0xf3ffffff]
[    0.117339] pnp 00:02: [mem 0xfed1c000-0xfed1ffff]
[    0.117342] pnp 00:02: [mem 0xfed14000-0xfed17fff]
[    0.117344] pnp 00:02: [mem 0xfed18000-0xfed18fff]
[    0.117346] pnp 00:02: [mem 0xfed19000-0xfed19fff]
[    0.117348] pnp 00:02: [mem 0xfed45000-0xfed4bfff]
[    0.117443] system 00:02: [io  0x164e-0x164f] has been reserved
[    0.117446] system 00:02: [io  0x1000-0x107f] has been reserved
[    0.117449] system 00:02: [io  0x1180-0x11bf] has been reserved
[    0.117452] system 00:02: [io  0x0800-0x080f] has been reserved
[    0.117455] system 00:02: [io  0x15e0-0x15ef] has been reserved
[    0.117457] system 00:02: [io  0x1600-0x165f] could not be reserved
[    0.117460] system 00:02: [mem 0xf0000000-0xf3ffffff] has been reserved
[    0.117463] system 00:02: [mem 0xfed1c000-0xfed1ffff] has been reserved
[    0.117466] system 00:02: [mem 0xfed14000-0xfed17fff] has been reserved
[    0.117469] system 00:02: [mem 0xfed18000-0xfed18fff] has been reserved
[    0.117471] system 00:02: [mem 0xfed19000-0xfed19fff] has been reserved
[    0.117474] system 00:02: [mem 0xfed45000-0xfed4bfff] has been reserved
[    0.117478] system 00:02: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.117513] pnp 00:03: [mem 0xfed00000-0xfed003ff]
[    0.117545] pnp 00:03: Plug and Play ACPI device, IDs PNP0103 (active)
[    0.117555] pnp 00:04: [io  0x0000-0x000f]
[    0.117558] pnp 00:04: [io  0x0080-0x008f]
[    0.117560] pnp 00:04: [io  0x00c0-0x00df]
[    0.117562] pnp 00:04: [dma 4]
[    0.117589] pnp 00:04: Plug and Play ACPI device, IDs PNP0200 (active)
[    0.117597] pnp 00:05: [io  0x0061]
[    0.117627] pnp 00:05: Plug and Play ACPI device, IDs PNP0800 (active)
[    0.117637] pnp 00:06: [io  0x00f0]
[    0.117652] pnp 00:06: [irq 13]
[    0.117679] pnp 00:06: Plug and Play ACPI device, IDs PNP0c04 (active)
[    0.117688] pnp 00:07: [io  0x0070-0x0071]
[    0.117694] pnp 00:07: [irq 8]
[    0.117725] pnp 00:07: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.117734] pnp 00:08: [io  0x0060]
[    0.117736] pnp 00:08: [io  0x0064]
[    0.117742] pnp 00:08: [irq 1]
[    0.117773] pnp 00:08: Plug and Play ACPI device, IDs PNP0303 (active)
[    0.117788] pnp 00:09: [irq 12]
[    0.117817] pnp 00:09: Plug and Play ACPI device, IDs LEN0005 PNP0f13 (active)
[    0.118194] pnp 00:0a: [mem 0xfed40000-0xfed44fff]
[    0.118229] pnp 00:0a: Plug and Play ACPI device, IDs ATM1200 PNP0c31 (active)
[    0.118696] pnp: PnP ACPI: found 11 devices
[    0.118698] ACPI: ACPI bus type pnp unregistered
[    0.125295] pci 0000:01:00.0: BAR 6: can't assign mem pref (size 0x20000)
[    0.125300] pci 0000:00:01.0: PCI bridge to [bus 01]
[    0.125303] pci 0000:00:01.0:   bridge window [io  0x2000-0x2fff]
[    0.125308] pci 0000:00:01.0:   bridge window [mem 0xd4000000-0xd6ffffff]
[    0.125311] pci 0000:00:01.0:   bridge window [mem 0xe0000000-0xefffffff 64bit pref]
[    0.125316] pci 0000:00:1c.0: PCI bridge to [bus 02]
[    0.125320] pci 0000:00:1c.0:   bridge window [io  0x3000-0x3fff]
[    0.125327] pci 0000:00:1c.0:   bridge window [mem 0xfc000000-0xfdffffff]
[    0.125332] pci 0000:00:1c.0:   bridge window [mem 0xf8000000-0xf80fffff 64bit pref]
[    0.125340] pci 0000:00:1c.1: PCI bridge to [bus 03]
[    0.125344] pci 0000:00:1c.1:   bridge window [io  0x4000-0x4fff]
[    0.125351] pci 0000:00:1c.1:   bridge window [mem 0xdc100000-0xdf2fffff]
[    0.125356] pci 0000:00:1c.1:   bridge window [mem 0xdfd00000-0xdfdfffff 64bit pref]
[    0.125364] pci 0000:00:1c.2: PCI bridge to [bus 04]
[    0.125368] pci 0000:00:1c.2:   bridge window [io  0x5000-0x5fff]
[    0.125375] pci 0000:00:1c.2:   bridge window [mem 0xd8000000-0xd9ffffff]
[    0.125380] pci 0000:00:1c.2:   bridge window [mem 0xdfa00000-0xdfafffff 64bit pref]
[    0.125388] pci 0000:00:1c.3: PCI bridge to [bus 05-0c]
[    0.125392] pci 0000:00:1c.3:   bridge window [io  0x6000-0x6fff]
[    0.125399] pci 0000:00:1c.3:   bridge window [mem 0xd0000000-0xd1ffffff]
[    0.125404] pci 0000:00:1c.3:   bridge window [mem 0xdf700000-0xdf7fffff 64bit pref]
[    0.125412] pci 0000:00:1c.4: PCI bridge to [bus 0d-14]
[    0.125416] pci 0000:00:1c.4:   bridge window [io  0x7000-0x7fff]
[    0.125423] pci 0000:00:1c.4:   bridge window [mem 0xcc000000-0xcdffffff]
[    0.125428] pci 0000:00:1c.4:   bridge window [mem 0xdf400000-0xdf4fffff 64bit pref]
[    0.125442] pci 0000:15:00.0: res[15]=[mem 0x04000000-0x03ffffff pref] get_res_add_size add_size 4000000
[    0.125444] pci 0000:15:00.0: res[16]=[mem 0x04000000-0x03ffffff] get_res_add_size add_size 4000000
[    0.125447] pci 0000:15:00.0: res[13]=[io  0x0100-0x00ff] get_res_add_size add_size 100
[    0.125449] pci 0000:15:00.0: res[14]=[io  0x0100-0x00ff] get_res_add_size add_size 100
[    0.125453] pci 0000:15:00.0: BAR 15: assigned [mem 0xf4000000-0xf7ffffff pref]
[    0.125458] pci 0000:15:00.0: BAR 16: assigned [mem 0xc0000000-0xc3ffffff]
[    0.125460] pci 0000:15:00.0: BAR 13: assigned [io  0x8000-0x80ff]
[    0.125463] pci 0000:15:00.0: BAR 14: assigned [io  0x8400-0x84ff]
[    0.125466] pci 0000:15:00.0: CardBus bridge to [bus 16-17]
[    0.125468] pci 0000:15:00.0:   bridge window [io  0x8000-0x80ff]
[    0.125474] pci 0000:15:00.0:   bridge window [io  0x8400-0x84ff]
[    0.125480] pci 0000:15:00.0:   bridge window [mem 0xf4000000-0xf7ffffff pref]
[    0.125486] pci 0000:15:00.0:   bridge window [mem 0xc0000000-0xc3ffffff]
[    0.125493] pci 0000:00:1e.0: PCI bridge to [bus 15-18]
[    0.125496] pci 0000:00:1e.0:   bridge window [io  0x8000-0xbfff]
[    0.125503] pci 0000:00:1e.0:   bridge window [mem 0xf8100000-0xfbffffff]
[    0.125508] pci 0000:00:1e.0:   bridge window [mem 0xf4000000-0xf7ffffff 64bit pref]
[    0.125570] pci 0000:00:1e.0: enabling device (0005 -> 0007)
[    0.125576] pci 0000:00:1e.0: setting latency timer to 64
[    0.125591] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7]
[    0.125593] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff]
[    0.125595] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff]
[    0.125598] pci_bus 0000:00: resource 7 [mem 0x000d0000-0x000d3fff]
[    0.125600] pci_bus 0000:00: resource 8 [mem 0x000d4000-0x000d7fff]
[    0.125602] pci_bus 0000:00: resource 9 [mem 0x000d8000-0x000dbfff]
[    0.125605] pci_bus 0000:00: resource 10 [mem 0x000dc000-0x000dffff]
[    0.125607] pci_bus 0000:00: resource 11 [mem 0xc0000000-0xfebfffff]
[    0.125609] pci_bus 0000:00: resource 12 [mem 0xfed40000-0xfed4bfff]
[    0.125612] pci_bus 0000:01: resource 0 [io  0x2000-0x2fff]
[    0.125614] pci_bus 0000:01: resource 1 [mem 0xd4000000-0xd6ffffff]
[    0.125617] pci_bus 0000:01: resource 2 [mem 0xe0000000-0xefffffff 64bit pref]
[    0.125619] pci_bus 0000:02: resource 0 [io  0x3000-0x3fff]
[    0.125622] pci_bus 0000:02: resource 1 [mem 0xfc000000-0xfdffffff]
[    0.125624] pci_bus 0000:02: resource 2 [mem 0xf8000000-0xf80fffff 64bit pref]
[    0.125627] pci_bus 0000:03: resource 0 [io  0x4000-0x4fff]
[    0.125629] pci_bus 0000:03: resource 1 [mem 0xdc100000-0xdf2fffff]
[    0.125631] pci_bus 0000:03: resource 2 [mem 0xdfd00000-0xdfdfffff 64bit pref]
[    0.125634] pci_bus 0000:04: resource 0 [io  0x5000-0x5fff]
[    0.125636] pci_bus 0000:04: resource 1 [mem 0xd8000000-0xd9ffffff]
[    0.125639] pci_bus 0000:04: resource 2 [mem 0xdfa00000-0xdfafffff 64bit pref]
[    0.125641] pci_bus 0000:05: resource 0 [io  0x6000-0x6fff]
[    0.125643] pci_bus 0000:05: resource 1 [mem 0xd0000000-0xd1ffffff]
[    0.125646] pci_bus 0000:05: resource 2 [mem 0xdf700000-0xdf7fffff 64bit pref]
[    0.125648] pci_bus 0000:0d: resource 0 [io  0x7000-0x7fff]
[    0.125651] pci_bus 0000:0d: resource 1 [mem 0xcc000000-0xcdffffff]
[    0.125653] pci_bus 0000:0d: resource 2 [mem 0xdf400000-0xdf4fffff 64bit pref]
[    0.125656] pci_bus 0000:15: resource 0 [io  0x8000-0xbfff]
[    0.125658] pci_bus 0000:15: resource 1 [mem 0xf8100000-0xfbffffff]
[    0.125660] pci_bus 0000:15: resource 2 [mem 0xf4000000-0xf7ffffff 64bit pref]
[    0.125663] pci_bus 0000:15: resource 4 [io  0x0000-0x0cf7]
[    0.125665] pci_bus 0000:15: resource 5 [io  0x0d00-0xffff]
[    0.125667] pci_bus 0000:15: resource 6 [mem 0x000a0000-0x000bffff]
[    0.125670] pci_bus 0000:15: resource 7 [mem 0x000d0000-0x000d3fff]
[    0.125672] pci_bus 0000:15: resource 8 [mem 0x000d4000-0x000d7fff]
[    0.125674] pci_bus 0000:15: resource 9 [mem 0x000d8000-0x000dbfff]
[    0.125676] pci_bus 0000:15: resource 10 [mem 0x000dc000-0x000dffff]
[    0.125679] pci_bus 0000:15: resource 11 [mem 0xc0000000-0xfebfffff]
[    0.125681] pci_bus 0000:15: resource 12 [mem 0xfed40000-0xfed4bfff]
[    0.125683] pci_bus 0000:16: resource 0 [io  0x8000-0x80ff]
[    0.125686] pci_bus 0000:16: resource 1 [io  0x8400-0x84ff]
[    0.125688] pci_bus 0000:16: resource 2 [mem 0xf4000000-0xf7ffffff pref]
[    0.125690] pci_bus 0000:16: resource 3 [mem 0xc0000000-0xc3ffffff]
[    0.125736] NET: Registered protocol family 2
[    0.126509] TCP established hash table entries: 524288 (order: 11, 8388608 bytes)
[    0.130644] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[    0.131205] TCP: Hash tables configured (established 524288 bind 65536)
[    0.131279] TCP: reno registered
[    0.131289] UDP hash table entries: 2048 (order: 4, 65536 bytes)
[    0.131332] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes)
[    0.131474] NET: Registered protocol family 1
[    0.131544] pci 0000:00:1a.1: power state changed by ACPI to D0
[    0.131646] pci 0000:00:1d.0: power state changed by ACPI to D0
[    0.131710] pci 0000:00:1d.2: power state changed by ACPI to D0
[    0.131801] pci 0000:01:00.0: Boot video device
[    0.131815] PCI: CLS mismatch (64 != 32), using 64 bytes
[    0.131884] Unpacking initramfs...
[    0.201295] Freeing initrd memory: 2984k freed
[    0.202673] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.202679] software IO TLB [mem 0xbbeae000-0xbfeadfff] (64MB) mapped at [ffff8800bbeae000-ffff8800bfeadfff]
[    0.202716] Simple Boot Flag at 0x35 set to 0x1
[    0.203089] audit: initializing netlink socket (disabled)
[    0.203106] type=2000 audit(1352591413.202:1): initialized
[    0.214828] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.217104] VFS: Disk quotas dquot_6.5.2
[    0.217154] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.217274] msgmni has been set to 7909
[    0.217453] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.217475] io scheduler noop registered
[    0.217510] io scheduler bfq registered (default)
[    0.217654] pcieport 0000:00:01.0: irq 40 for MSI/MSI-X
[    0.217801] pcieport 0000:00:1c.0: irq 41 for MSI/MSI-X
[    0.217975] pcieport 0000:00:1c.1: irq 42 for MSI/MSI-X
[    0.218172] pcieport 0000:00:1c.2: irq 43 for MSI/MSI-X
[    0.218348] pcieport 0000:00:1c.3: irq 44 for MSI/MSI-X
[    0.218525] pcieport 0000:00:1c.4: irq 45 for MSI/MSI-X
[    0.218662] pcieport 0000:00:01.0: Signaling PME through PCIe PME interrupt
[    0.218665] pci 0000:01:00.0: Signaling PME through PCIe PME interrupt
[    0.218669] pcie_pme 0000:00:01.0:pcie01: service driver pcie_pme loaded
[    0.218692] pcieport 0000:00:1c.0: Signaling PME through PCIe PME interrupt
[    0.218697] pcie_pme 0000:00:1c.0:pcie01: service driver pcie_pme loaded
[    0.218721] pcieport 0000:00:1c.1: Signaling PME through PCIe PME interrupt
[    0.218723] pci 0000:03:00.0: Signaling PME through PCIe PME interrupt
[    0.218729] pcie_pme 0000:00:1c.1:pcie01: service driver pcie_pme loaded
[    0.218751] pcieport 0000:00:1c.2: Signaling PME through PCIe PME interrupt
[    0.218756] pcie_pme 0000:00:1c.2:pcie01: service driver pcie_pme loaded
[    0.218778] pcieport 0000:00:1c.3: Signaling PME through PCIe PME interrupt
[    0.218784] pcie_pme 0000:00:1c.3:pcie01: service driver pcie_pme loaded
[    0.218807] pcieport 0000:00:1c.4: Signaling PME through PCIe PME interrupt
[    0.218813] pcie_pme 0000:00:1c.4:pcie01: service driver pcie_pme loaded
[    0.218885] vesafb: mode is 1680x1050x32, linelength=6720, pages=1
[    0.218887] vesafb: scrolling: redraw
[    0.218889] vesafb: Truecolor: size=8:8:8:8, shift=24:16:8:0
[    0.220317] vesafb: framebuffer at 0xd5000000, mapped to 0xffffc90005000000, using 13781k, total 14336k
[    0.327560] Console: switching to colour frame buffer device 210x65
[    0.434192] fb0: VESA VGA frame buffer device
[    0.434203] intel_idle: does not run on family 6 model 23
[    0.434240] GHES: HEST is not enabled!
[    0.434297] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.434679] Linux agpgart interface v0.103
[    0.434766] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    0.442853] serio: i8042 KBD port at 0x60,0x64 irq 1
[    0.442886] serio: i8042 AUX port at 0x60,0x64 irq 12
[    0.442971] mousedev: PS/2 mouse device common for all mice
[    0.443057] rtc_cmos 00:07: RTC can wake from S4
[    0.443196] rtc_cmos 00:07: rtc core: registered rtc_cmos as rtc0
[    0.443231] rtc0: alarms up to one month, y3k, 114 bytes nvram, hpet irqs
[    0.443239] cpuidle: using governor ladder
[    0.443241] cpuidle: using governor menu
[    0.443349] drop_monitor: Initializing network drop monitor service
[    0.443426] TCP: cubic registered
[    0.443543] NET: Registered protocol family 10
[    0.443708] NET: Registered protocol family 17
[    0.443719] Key type dns_resolver registered
[    0.443851] TuxOnIce 3.3 (http://tuxonice.net)
[    0.443972] TuxOnIce: No storage allocators have been registered. Hibernating will be disabled.
[    0.443988] TuxOnIce: No storage allocators have been registered. Hibernating will be disabled.
[    0.443990] TuxOnIce: No storage allocators have been registered.
[    0.444561] Restarting tasks ... done.
[    0.444573] PM: Checking hibernation image partition swap:/dev/sda5
[    0.448048] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    0.454569] PM: Hibernation image not present or could not be loaded.
[    0.454592] registered taskstats version 1
[    0.581181] UKSM: relative memcmp_cost = 276 hash=468166930 cmp_ret=0.
[    0.583993] rtc_cmos 00:07: setting system clock to 2012-11-10 23:50:14 UTC (1352591414)
[    0.585297] Freeing unused kernel memory: 764k freed
[    0.585567] Write protecting the kernel read-only data: 8192k
[    0.590537] Freeing unused kernel memory: 1552k freed
[    0.593232] Freeing unused kernel memory: 692k freed
[    0.593512] BFS CPU scheduler v0.425 by Con Kolivas.
[    0.602484] systemd-udevd[44]: starting version 195
[    0.644034] SCSI subsystem initialized
[    0.648675] ACPI: bus type scsi registered
[    0.648854] libata version 3.00 loaded.
[    0.650211] ata_piix 0000:00:1f.1: version 2.13
[    0.650267] ata_piix 0000:00:1f.1: setting latency timer to 64
[    0.651255] scsi0 : ata_piix
[    0.651934] scsi1 : ata_piix
[    0.652017] ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x18c0 irq 14
[    0.652019] ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x18c8 irq 15
[    0.652187] ata2: port disabled--ignoring
[    0.806546] ata1.00: ATAPI: HL-DT-ST DVDRAM GMA-4082N, EX01, max UDMA/33
[    0.812287] ata1.00: configured for UDMA/33
[    0.817590] scsi 0:0:0:0: CD-ROM            HL-DT-ST DVDRAM GMA-4082N EX01 PQ: 0 ANSI: 5
[    0.818392] ahci 0000:00:1f.2: version 3.0
[    0.818472] ahci 0000:00:1f.2: irq 46 for MSI/MSI-X
[    0.818537] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 3 ports 3 Gbps 0x1 impl SATA mode
[    0.818541] ahci 0000:00:1f.2: flags: 64bit ncq sntf pm led clo pio slum part ccc 
[    0.818547] ahci 0000:00:1f.2: setting latency timer to 64
[    0.819055] scsi2 : ahci
[    0.819124] scsi3 : ahci
[    0.819193] scsi4 : ahci
[    0.819246] ata3: SATA max UDMA/133 abar m2048@0xfe225000 port 0xfe225100 irq 46
[    0.819248] ata4: DUMMY
[    0.819250] ata5: DUMMY
[    1.124033] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[    1.125040] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[    1.125044] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[    1.125047] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[    1.126068] ata3.00: ATA-8: Hitachi HTS543232L9A300, FB4OC40C, max UDMA/133
[    1.126070] ata3.00: 625142448 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
[    1.127216] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[    1.127219] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[    1.127221] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[    1.128244] ata3.00: configured for UDMA/133
[    1.128346] scsi 2:0:0:0: Direct-Access     ATA      Hitachi HTS54323 FB4O PQ: 0 ANSI: 5
[    0.817907] ACPI: Invalid Power Resource to register!
[    1.128506] ACPI: Invalid Power Resource to register!
[    1.132240] sd 2:0:0:0: [sda] 625142448 512-byte logical blocks: (320 GB/298 GiB)
[    1.132284] sd 2:0:0:0: [sda] Write Protect is off
[    1.132287] sd 2:0:0:0: [sda] Mode Sense: 00 3a 00 00
[    1.132305] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.137592] sr0: scsi3-mmc drive: 24x/24x writer dvd-ram cd/rw xa/form2 cdda tray
[    1.137595] cdrom: Uniform CD-ROM driver Revision: 3.20
[    1.137808] sr 0:0:0:0: Attached scsi CD-ROM sr0
[    1.188537]  sda: sda1 sda2 sda3 sda4 < sda5 >
[    1.188916] sd 2:0:0:0: [sda] Attached SCSI disk
[    1.789105] TuxOnIce: No image found.
[    1.790352] Restarting tasks ... done.
[    1.806215] Pid: 1, comm: init Not tainted 3.6-pf #1
[    1.806217] Call Trace:
[    1.806226]  [<ffffffff8108dbcd>] free_update_stats+0x7d/0x90
[    1.806229]  [<ffffffff8108dcaa>] toi_free_page+0x5a/0x70
[    1.806236]  [<ffffffffa0004d35>] forget_signature_page+0x45/0xe0 [tuxonice_bio]
[    1.806240]  [<ffffffffa0002223>] toi_bio_cleanup+0x33/0x70 [tuxonice_bio]
[    1.806243]  [<ffffffff8108d6c7>] toi_cleanup_modules+0x47/0x70
[    1.806245]  [<ffffffff8108fa15>] toi_finish_anything+0x15/0x90
[    1.806248]  [<ffffffff8108e1e5>] toi_attr_store+0x85/0x310
[    1.806252]  [<ffffffff811ea8fd>] sysfs_write_file+0xcd/0x140
[    1.806256]  [<ffffffff8117ad28>] vfs_write+0xa8/0x180
[    1.806259]  [<ffffffff8117b06a>] sys_write+0x4a/0xa0
[    1.806262]  [<ffffffff81059fa0>] ? task_stopped_code+0x60/0x60
[    1.806266]  [<ffffffff81475729>] system_call_fastpath+0x16/0x1b
[    1.806268] Idx  Allocs   Frees   Tests   Fails     Max Description
[    1.806271]  38       0       1       0       0       0 setting swap signature
[    1.951672] EXT4-fs (sda2): INFO: recovery required on readonly filesystem
[    1.951676] EXT4-fs (sda2): write access will be enabled during recovery
[    5.069360] EXT4-fs (sda2): recovery complete
[    5.080511] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
[    6.534186] systemd[1]: systemd 195 running in system mode. (+PAM -LIBWRAP -AUDIT -SELINUX -IMA -SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ; arch)
[    6.953389] systemd[1]: could not find module by name='autofs4'
[    6.953394] systemd[1]: Failed to insert 'autofs4'
[    6.961110] systemd[1]: Set hostname to <panzor>.
[    7.623047] systemd[1]: [/etc/systemd/system/timer_spotify_fix.service:5] Invalid executable path in command line, ignoring: rm /home/juha/.cache/spotify/Storage/index.dat
[    7.623079] systemd[1]: timer_spotify_fix.service lacks ExecStart setting. Refusing.
[    7.741461] systemd[1]: [/etc/systemd/system/rc-local.service:5] Failed to parse service type, ignoring: fork # https://bbs.archlinux.org/viewtopic.php?pid=1152496
[    8.093359] systemd[1]: Cannot add dependency job for unit timer_spotify_fix.service, ignoring: Unit timer_spotify_fix.service failed to load: Invalid argument. See system logs and 'systemctl status timer_spotify_fix.service' for details.
[    8.093622] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
[    8.093682] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    8.093699] systemd[1]: Starting Remote File Systems.
[    8.094267] systemd[1]: Reached target Remote File Systems.
[    8.094281] systemd[1]: Starting Delayed Shutdown Socket.
[    8.094843] systemd[1]: Listening on Delayed Shutdown Socket.
[    8.094856] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[    8.095530] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    8.095572] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
[    8.095588] systemd[1]: Failed to open /dev/autofs: No such file or directory
[    8.095592] systemd[1]: Failed to initialize automounter: No such file or directory
[    8.097191] systemd[1]: Failed to set up automount Arbitrary Executable File Formats File System Automount Point.
[    8.097197] systemd[1]: Unit proc-sys-fs-binfmt_misc.automount entered failed state
[    8.097207] systemd[1]: Starting Encrypted Volumes.
[    8.097715] systemd[1]: Reached target Encrypted Volumes.
[    8.097784] systemd[1]: Starting udev Kernel Socket.
[    8.098316] systemd[1]: Listening on udev Kernel Socket.
[    8.098373] systemd[1]: Starting udev Control Socket.
[    8.098898] systemd[1]: Listening on udev Control Socket.
[    8.098917] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
[    8.098965] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    8.098977] systemd[1]: Expecting device dev-sda5.device...
[    8.099463] systemd[1]: Expecting device dev-sda1.device...
[    8.099935] systemd[1]: Expecting device dev-sda3.device...
[    8.100418] systemd[1]: Starting Journal Socket.
[    8.100931] systemd[1]: Listening on Journal Socket.
[    8.100953] systemd[1]: Starting File System Check on Root Device...
[    8.125806] systemd[1]: Starting Apply Kernel Variables...
[    8.132145] systemd[1]: Mounting POSIX Message Queue File System...
[    8.136079] systemd[1]: Mounting Debug File System...
[    8.140078] systemd[1]: Mounting Huge Pages File System...
[    8.154123] systemd[1]: Starting Load Kernel Modules...
[    8.204982] systemd[1]: Starting Set Up Additional Binary Formats...
[    8.212179] systemd[1]: Starting udev Kernel Device Manager...
[    8.216155] systemd[1]: Starting udev Coldplug all Devices...
[    8.220127] systemd[1]: Starting Setup Virtual Console...
[    8.224107] systemd[1]: Starting Journal Service...
[    8.228600] systemd[1]: Started Journal Service.
[    8.778822] vboxdrv: Found 2 processor cores.
[    8.778950] vboxdrv: fAsync=1 offMin=0x5b433 offMax=0x5b433
[    8.779021] vboxdrv: TSC mode is 'asynchronous', kernel timer mode is 'normal'.
[    8.779022] vboxdrv: Successfully loaded version 4.2.2_OSE (interface 0x001a0004).
[    8.825924] ACPI: Requesting acpi_cpufreq
[    9.142992] systemd-udevd[114]: starting version 195
[    9.873129] Monitor-Mwait will be used to enter C-1 state
[    9.873135] Monitor-Mwait will be used to enter C-2 state
[    9.873139] Monitor-Mwait will be used to enter C-3 state
[    9.873153] ACPI: acpi_idle registered with cpuidle
[   10.782316] acpi device:07: registered as cooling_device2
[   10.782362] ACPI: Video Device [VID1] (multi-head: yes  rom: no  post: no)
[   10.782479] input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/device:06/LNXVIDEO:01/input/input1
[   10.782598] ACPI: AC Adapter [AC] (on-line)
[   10.787451] input: Lid Switch as /devices/LNXSYSTM:00/device:00/PNP0C0D:00/input/input2
[   10.788301] ACPI: Lid Switch [LID]
[   10.788390] input: Sleep Button as /devices/LNXSYSTM:00/device:00/PNP0C0E:00/input/input3
[   10.788420] ACPI: Sleep Button [SLPB]
[   10.788486] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4
[   10.788490] ACPI: Power Button [PWRF]
[   10.794165] thermal LNXTHERM:00: registered as thermal_zone0
[   10.794170] ACPI: Thermal Zone [THM0] (35 C)
[   10.795493] thermal LNXTHERM:01: registered as thermal_zone1
[   10.795496] ACPI: Thermal Zone [THM1] (32 C)
[   10.802313] ACPI: Battery Slot [BAT0] (battery present)
[   11.018664] microcode: CPU0 sig=0x10676, pf=0x80, revision=0x60c
[   11.066715] microcode: CPU1 sig=0x10676, pf=0x80, revision=0x60c
[   11.067218] microcode: Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
[   11.352013] ACPI Warning: 0x0000000000001028-0x000000000000102f SystemIO conflicts with Region \_SB_.PCI0.LPC_.PMIO 1 (20120711/utaddress-251)
[   11.352021] ACPI: If an ACPI driver is available for this device, you should use it instead of the native driver
[   11.352026] ACPI Warning: 0x0000000000001180-0x00000000000011bf SystemIO conflicts with Region \_SB_.PCI0.LPC_.LPIO 1 (20120711/utaddress-251)
[   11.352030] ACPI: If an ACPI driver is available for this device, you should use it instead of the native driver
[   11.352031] lpc_ich: Resource conflict(s) found affecting gpio_ich
[   11.371856] r592 0000:15:00.4: setting latency timer to 64
[   11.371975] r592: driver successfully loaded
[   11.396865] e1000e: Intel(R) PRO/1000 Network Driver - 2.0.0-k
[   11.396869] e1000e: Copyright(c) 1999 - 2012 Intel Corporation.
[   11.396909] e1000e 0000:00:19.0: setting latency timer to 64
[   11.396999] e1000e 0000:00:19.0: Interrupt Throttling Rate (ints/sec) set to dynamic conservative mode
[   11.397069] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[   11.434842] wmi: Mapper loaded
[   11.451205] tpm_tis 00:0a: 1.2 TPM (device-id 0x3203, rev-id 9)
[   12.361222] tpm_tis 00:0a: TPM is disabled/deactivated (0x6)
[   12.375896] r852 0000:15:00.5: setting latency timer to 64
[   12.375975] r852: driver loaded successfully
[   12.504768] EXT4-fs (sda2): re-mounted. Opts: user_xattr
[   12.537133] e1000e 0000:00:19.0: eth0: (PCI Express:2.5GT/s:Width x1) 00:1c:25:94:c6:f7
[   12.537138] e1000e 0000:00:19.0: eth0: Intel(R) PRO/1000 Network Connection
[   12.537166] e1000e 0000:00:19.0: eth0: MAC: 6, PHY: 6, PBA No: 1008FF-0FF
[   12.741046] iTCO_vendor_support: vendor-support=0
[   12.767669] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.10
[   12.767718] iTCO_wdt: Found a ICH8M TCO device (Version=2, TCOBASE=0x1060)
[   12.767855] iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
[   12.817606] sdhci: Secure Digital Host Controller Interface driver
[   12.817609] sdhci: Copyright(c) Pierre Ossman
[   12.913381] ACPI: bus type usb registered
[   12.913538] usbcore: registered new interface driver usbfs
[   12.913556] usbcore: registered new interface driver hub
[   12.913910] usbcore: registered new device driver usb
[   13.074736] hda_intel: probe_mask set to 0x1 for device 17aa:20ac
[   13.074838] snd_hda_intel 0000:00:1b.0: irq 48 for MSI/MSI-X
[   13.245451] sdhci-pci 0000:15:00.2: SDHCI controller found [1180:0822] (rev 21)
[   13.246518] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.246526] sdhci-pci 0000:15:00.2: setting latency timer to 64
[   13.247776] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.247817] Registered led device: mmc0::
[   13.269034] mmc0: SDHCI controller on PCI [0000:15:00.2] using DMA
[   13.302287] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.317814] Non-volatile memory driver v1.3
[   13.335300] thinkpad_acpi: ThinkPad ACPI Extras v0.24
[   13.335305] thinkpad_acpi: http://ibm-acpi.sf.net/
[   13.335306] thinkpad_acpi: ThinkPad BIOS 7KETC9WW (2.29 ), EC 7KHT24WW-1.08
[   13.335308] thinkpad_acpi: Lenovo ThinkPad R61, model 8918DEG
[   13.335744] thinkpad_acpi: detected a 8-level brightness capable ThinkPad
[   13.337082] thinkpad_acpi: ACPI backlight control delay disabled
[   13.337247] thinkpad_acpi: radio switch found; radios are enabled
[   13.337263] thinkpad_acpi: This ThinkPad has standard ACPI backlight brightness control, supported by the ACPI video driver
[   13.337265] thinkpad_acpi: Disabling thinkpad-acpi brightness events by default...
[   13.344977] thinkpad_acpi: rfkill switch tpacpi_bluetooth_sw: radio is blocked
[   13.350028] Registered led device: tpacpi::thinklight
[   13.350341] Registered led device: tpacpi::power
[   13.350641] Registered led device: tpacpi::standby
[   13.350949] Registered led device: tpacpi::thinkvantage
[   13.360144] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.361574] thinkpad_acpi: Standard ACPI backlight interface available, not loading native one
[   13.361660] thinkpad_acpi: Console audio control enabled, mode: monitor (read only)
[   13.363052] input: ThinkPad Extra Buttons as /devices/platform/thinkpad_acpi/input/input5
[   13.417333] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.474271] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[   13.697916] input: HDA Digital PCBeep as /devices/pci0000:00/0000:00:1b.0/input/input6
[   13.733195] psmouse serio1: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3
[   13.749252] input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/input/input7
[   14.400747] i801_smbus 0000:00:1f.3: SMBus using PCI Interrupt
[   14.607086] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[   14.607149] ehci_hcd 0000:00:1a.7: setting latency timer to 64
[   14.607154] ehci_hcd 0000:00:1a.7: EHCI Host Controller
[   14.607162] ehci_hcd 0000:00:1a.7: new USB bus registered, assigned bus number 1
[   14.611079] ehci_hcd 0000:00:1a.7: cache line size of 64 is not supported
[   14.611105] ehci_hcd 0000:00:1a.7: irq 22, io mem 0xfe225800
[   14.617056] ehci_hcd 0000:00:1a.7: USB 2.0 started, EHCI 1.00
[   14.617295] hub 1-0:1.0: USB hub found
[   14.617300] hub 1-0:1.0: 4 ports detected
[   14.617467] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[   14.617471] ehci_hcd 0000:00:1d.7: EHCI Host Controller
[   14.617478] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 2
[   14.621384] ehci_hcd 0000:00:1d.7: debug port 1
[   14.621392] ehci_hcd 0000:00:1d.7: cache line size of 64 is not supported
[   14.621408] ehci_hcd 0000:00:1d.7: irq 19, io mem 0xfe225c00
[   14.627087] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[   14.627226] hub 2-0:1.0: USB hub found
[   14.627231] hub 2-0:1.0: 6 ports detected
[   15.125689] uhci_hcd: USB Universal Host Controller Interface driver
[   15.125735] uhci_hcd 0000:00:1a.0: setting latency timer to 64
[   15.125739] uhci_hcd 0000:00:1a.0: UHCI Host Controller
[   15.125748] uhci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 3
[   15.125793] uhci_hcd 0000:00:1a.0: irq 20, io base 0x00001820
[   15.125961] hub 3-0:1.0: USB hub found
[   15.125966] hub 3-0:1.0: 2 ports detected
[   15.126071] uhci_hcd 0000:00:1a.1: setting latency timer to 64
[   15.126075] uhci_hcd 0000:00:1a.1: UHCI Host Controller
[   15.126081] uhci_hcd 0000:00:1a.1: new USB bus registered, assigned bus number 4
[   15.126117] uhci_hcd 0000:00:1a.1: irq 21, io base 0x00001840
[   15.126266] hub 4-0:1.0: USB hub found
[   15.126271] hub 4-0:1.0: 2 ports detected
[   15.126349] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[   15.126353] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[   15.126359] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 5
[   15.126393] uhci_hcd 0000:00:1d.0: irq 16, io base 0x00001860
[   15.126537] hub 5-0:1.0: USB hub found
[   15.126541] hub 5-0:1.0: 2 ports detected
[   15.126616] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[   15.126620] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[   15.126627] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 6
[   15.126663] uhci_hcd 0000:00:1d.1: irq 17, io base 0x00001880
[   15.126809] hub 6-0:1.0: USB hub found
[   15.126813] hub 6-0:1.0: 2 ports detected
[   15.126894] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[   15.126898] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[   15.126904] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 7
[   15.126936] uhci_hcd 0000:00:1d.2: irq 18, io base 0x000018a0
[   15.127115] hub 7-0:1.0: USB hub found
[   15.127120] hub 7-0:1.0: 2 ports detected
[   15.537048] usb 3-1: new full-speed USB device number 2 using uhci_hcd
[   15.729844] fuse init (API version 7.20)
[   15.796049] usb 3-2: new full-speed USB device number 3 using uhci_hcd
[   16.063054] usb 5-1: new full-speed USB device number 2 using uhci_hcd
[   16.230859] nvidia: module license 'NVIDIA' taints kernel.
[   16.230865] Disabling lock debugging due to kernel taint
[   16.251695] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=io+mem,decodes=none:owns=io+mem
[   16.251885] NVRM: loading NVIDIA UNIX x86_64 Kernel Module  304.64  Tue Oct 30 10:58:20 PDT 2012
[   16.781814] thinkpad_ec: thinkpad_ec 0.41 loaded.
[   16.792088] tp_smapi 0.41 loading...
[   16.792233] tp_smapi successfully loaded (smapi_port=0xb2).
[   16.809134] hdaps: initial mode latch is 0x05
[   16.809262] hdaps: setting ec_rate=250, filter_order=2
[   16.809483] hdaps: device successfully initialized.
[   16.809551] input: ThinkPad HDAPS joystick emulation as /devices/virtual/input/input8
[   16.809665] input: ThinkPad HDAPS accelerometer data as /devices/virtual/input/input9
[   16.809700] hdaps: driver successfully loaded.
[   16.866856] Bluetooth: Core ver 2.16
[   16.866875] NET: Registered protocol family 31
[   16.866877] Bluetooth: HCI device and connection manager initialized
[   16.866879] Bluetooth: HCI socket layer initialized
[   16.866881] Bluetooth: L2CAP socket layer initialized
[   16.866886] Bluetooth: SCO socket layer initialized
[   17.317682] usbcore: registered new interface driver btusb
[   17.659512] usbcore: registered new interface driver usbhid
[   17.659515] usbhid: USB HID core driver
[   17.686578] logitech-djreceiver 0003:046D:C52B.0003: hiddev0,hidraw0: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:1d.0-1/input2
[   17.690790] input: Logitech Unifying Device. Wireless PID:101a as /devices/pci0000:00/0000:00:1d.0/usb5/5-1/5-1:1.2/0003:046D:C52B.0003/input/input10
[   17.690914] logitech-djdevice 0003:046D:C52B.0004: input,hidraw1: USB HID v1.11 Mouse [Logitech Unifying Device. Wireless PID:101a] on usb-0000:00:1d.0-1:1
[   17.757462] cfg80211: Calling CRDA to update world regulatory domain
[   17.810131] iwl4965: Intel(R) Wireless WiFi 4965 driver for Linux, in-tree:
[   17.810135] iwl4965: Copyright(c) 2003-2011 Intel Corporation
[   17.810268] iwl4965 0000:03:00.0: Detected Intel(R) Wireless WiFi Link 4965AGN, REV=0x4
[   17.848954] iwl4965 0000:03:00.0: device EEPROM VER=0x36, CALIB=0x5
[   17.848968] iwl4965 0000:03:00.0: Tunable channels: 13 802.11bg, 19 802.11a channels
[   17.849073] iwl4965 0000:03:00.0: irq 49 for MSI/MSI-X
[   17.905284] iwl4965 0000:03:00.0: loaded firmware version 228.61.2.24
[   17.905516] Registered led device: phy0-led
[   18.683979] ieee80211 phy0: Selected rate control algorithm 'iwl-4965-rs'
[   19.805972] Adding 2184188k swap on /dev/sda5.  Priority:-1 extents:1 across:2184188k 
[   20.047061] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
[   20.241157] systemd-journald[117]: Received SIGUSR1
[   20.571184] systemd-journald[117]: File /var/log/journal/8ed49f4f63fc90478b051d8f00000121/system.journal corrupted or uncleanly shut down, renaming and replacing.
[   22.861671] /dev/vmmon[388]: Module vmmon: registered with major=10 minor=165
[   22.861679] /dev/vmmon[388]: Module vmmon: initialized
[   23.123675] [418]: VMCI: shared components initialized.
[   23.123771] [418]: VMCI: host components initialized.
[   23.123972] [418]: VMCI: Module registered (name=vmci,major=10,minor=57).
[   23.123975] [418]: VMCI: Using host personality
[   23.123977] [418]: VMCI: Module (name=vmci) is initialized
[   23.851810] vsock: disagrees about version of symbol skb_free_datagram
[   23.851815] vsock: Unknown symbol skb_free_datagram (err -22)
[   23.851822] vsock: disagrees about version of symbol skb_put
[   23.851824] vsock: Unknown symbol skb_put (err -22)
[   23.851833] vsock: disagrees about version of symbol skb_dequeue
[   23.851834] vsock: Unknown symbol skb_dequeue (err -22)
[   23.851856] vsock: disagrees about version of symbol sk_receive_skb
[   23.851858] vsock: Unknown symbol sk_receive_skb (err -22)
[   23.851863] vsock: disagrees about version of symbol skb_copy_datagram_iovec
[   23.851865] vsock: Unknown symbol skb_copy_datagram_iovec (err -22)
[   23.851875] vsock: disagrees about version of symbol proto_unregister
[   23.851877] vsock: Unknown symbol proto_unregister (err -22)
[   23.851879] vsock: disagrees about version of symbol kfree_skb
[   23.851880] vsock: Unknown symbol kfree_skb (err -22)
[   23.851884] vsock: disagrees about version of symbol sock_register
[   23.851886] vsock: Unknown symbol sock_register (err -22)
[   23.851893] vsock: disagrees about version of symbol __alloc_skb
[   23.851895] vsock: Unknown symbol __alloc_skb (err -22)
[   23.851898] vsock: disagrees about version of symbol proto_register
[   23.851900] vsock: Unknown symbol proto_register (err -22)
[   23.851908] vsock: disagrees about version of symbol sk_free
[   23.851910] vsock: Unknown symbol sk_free (err -22)
[   23.851912] vsock: disagrees about version of symbol sock_no_accept
[   23.851914] vsock: Unknown symbol sock_no_accept (err -22)
[   23.851917] vsock: disagrees about version of symbol sock_no_listen
[   23.851919] vsock: Unknown symbol sock_no_listen (err -22)
[   23.851922] vsock: disagrees about version of symbol lock_sock_nested
[   23.851924] vsock: Unknown symbol lock_sock_nested (err -22)
[   23.851930] vsock: disagrees about version of symbol sk_alloc
[   23.851932] vsock: Unknown symbol sk_alloc (err -22)
[   23.851934] vsock: disagrees about version of symbol sock_no_socketpair
[   23.851936] vsock: Unknown symbol sock_no_socketpair (err -22)
[   23.851941] vsock: disagrees about version of symbol sock_no_mmap
[   23.851942] vsock: Unknown symbol sock_no_mmap (err -22)
[   23.851944] vsock: disagrees about version of symbol sock_no_sendpage
[   23.851946] vsock: Unknown symbol sock_no_sendpage (err -22)
[   23.851953] vsock: disagrees about version of symbol skb_recv_datagram
[   23.851955] vsock: Unknown symbol skb_recv_datagram (err -22)
[   23.851959] vsock: disagrees about version of symbol sock_queue_rcv_skb
[   23.851960] vsock: Unknown symbol sock_queue_rcv_skb (err -22)
[   23.851966] vsock: disagrees about version of symbol sock_no_ioctl
[   23.851968] vsock: Unknown symbol sock_no_ioctl (err -22)
[   23.851970] vsock: disagrees about version of symbol sock_no_getsockopt
[   23.851971] vsock: Unknown symbol sock_no_getsockopt (err -22)
[   23.851974] vsock: disagrees about version of symbol sock_no_setsockopt
[   23.851976] vsock: Unknown symbol sock_no_setsockopt (err -22)
[   23.851980] vsock: disagrees about version of symbol sock_init_data
[   23.851982] vsock: Unknown symbol sock_init_data (err -22)
[   23.851986] vsock: disagrees about version of symbol release_sock
[   23.851988] vsock: Unknown symbol release_sock (err -22)
[   24.961923] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   25.577998] Bluetooth: RFCOMM TTY layer initialized
[   25.578144] Bluetooth: RFCOMM socket layer initialized
[   25.578146] Bluetooth: RFCOMM ver 1.11
[   25.589642] vmnet: disagrees about version of symbol sock_wfree
[   25.589647] vmnet: Unknown symbol sock_wfree (err -22)
[   25.589651] vmnet: disagrees about version of symbol skb_put
[   25.589652] vmnet: Unknown symbol skb_put (err -22)
[   25.589656] vmnet: disagrees about version of symbol dev_queue_xmit
[   25.589658] vmnet: Unknown symbol dev_queue_xmit (err -22)
[   25.589661] vmnet: disagrees about version of symbol consume_skb
[   25.589663] vmnet: Unknown symbol consume_skb (err -22)
[   25.589666] vmnet: disagrees about version of symbol dev_add_pack
[   25.589668] vmnet: Unknown symbol dev_add_pack (err -22)
[   25.589671] vmnet: disagrees about version of symbol unregister_netdev
[   25.589673] vmnet: Unknown symbol unregister_netdev (err -22)
[   25.589676] vmnet: disagrees about version of symbol skb_dequeue
[   25.589678] vmnet: Unknown symbol skb_dequeue (err -22)
[   25.589689] vmnet: disagrees about version of symbol dev_set_promiscuity
[   25.589691] vmnet: Unknown symbol dev_set_promiscuity (err -22)
[   25.589696] vmnet: disagrees about version of symbol nf_unregister_hook
[   25.589697] vmnet: Unknown symbol nf_unregister_hook (err -22)
[   25.589708] vmnet: disagrees about version of symbol skb_copy_datagram_iovec
[   25.589710] vmnet: Unknown symbol skb_copy_datagram_iovec (err -22)
[   25.589713] vmnet: disagrees about version of symbol __dev_get_by_name
[   25.589715] vmnet: Unknown symbol __dev_get_by_name (err -22)
[   25.589717] vmnet: disagrees about version of symbol ether_setup
[   25.589719] vmnet: Unknown symbol ether_setup (err -22)
[   25.589723] vmnet: disagrees about version of symbol eth_type_trans
[   25.589725] vmnet: Unknown symbol eth_type_trans (err -22)
[   25.589727] vmnet: disagrees about version of symbol alloc_netdev_mqs
[   25.589729] vmnet: Unknown symbol alloc_netdev_mqs (err -22)
[   25.589731] vmnet: disagrees about version of symbol kfree_skb
[   25.589733] vmnet: Unknown symbol kfree_skb (err -22)
[   25.589744] vmnet: disagrees about version of symbol skb_queue_tail
[   25.589746] vmnet: Unknown symbol skb_queue_tail (err -22)
[   25.589749] vmnet: disagrees about version of symbol init_net
[   25.589750] vmnet: Unknown symbol init_net (err -22)
[   25.589754] vmnet: disagrees about version of symbol dev_remove_pack
[   25.589755] vmnet: Unknown symbol dev_remove_pack (err -22)
[   25.589758] vmnet: disagrees about version of symbol sk_free
[   25.589760] vmnet: Unknown symbol sk_free (err -22)
[   25.589763] vmnet: disagrees about version of symbol skb_push
[   25.589765] vmnet: Unknown symbol skb_push (err -22)
[   25.589771] vmnet: disagrees about version of symbol register_netdev
[   25.589772] vmnet: Unknown symbol register_netdev (err -22)
[   25.589775] vmnet: disagrees about version of symbol free_netdev
[   25.589777] vmnet: Unknown symbol free_netdev (err -22)
[   25.589786] vmnet: disagrees about version of symbol sk_alloc
[   25.589787] vmnet: Unknown symbol sk_alloc (err -22)
[   25.589790] vmnet: disagrees about version of symbol netif_rx_ni
[   25.589792] vmnet: Unknown symbol netif_rx_ni (err -22)
[   25.589799] vmnet: disagrees about version of symbol __pskb_pull_tail
[   25.589800] vmnet: Unknown symbol __pskb_pull_tail (err -22)
[   25.589803] vmnet: disagrees about version of symbol __netdev_alloc_skb
[   25.589805] vmnet: Unknown symbol __netdev_alloc_skb (err -22)
[   25.589814] vmnet: disagrees about version of symbol nf_register_hook
[   25.589816] vmnet: Unknown symbol nf_register_hook (err -22)
[   25.589824] vmnet: disagrees about version of symbol skb_copy
[   25.589825] vmnet: Unknown symbol skb_copy (err -22)
[   25.589827] vmnet: disagrees about version of symbol skb_clone
[   25.589829] vmnet: Unknown symbol skb_clone (err -22)
[   25.589838] vmnet: disagrees about version of symbol skb_gso_segment
[   25.589840] vmnet: Unknown symbol skb_gso_segment (err -22)
[   25.589842] vmnet: disagrees about version of symbol sock_init_data
[   25.589844] vmnet: Unknown symbol sock_init_data (err -22)
[   35.861524] NVRM: Your system is not currently configured to drive a VGA console
[   35.861529] NVRM: on the primary VGA device. The NVIDIA Linux graphics driver
[   35.861531] NVRM: requires the use of a text-mode VGA console. Use of other console
[   35.861532] NVRM: drivers including, but not limited to, vesafb, may result in
[   35.861534] NVRM: corruption and stability problems, and is not supported.
[   35.983121] NET: Registered protocol family 3
[   36.037470] NET: Registered protocol family 6
[   36.285999] NET: Registered protocol family 11
[   36.341048] NET: Registered protocol family 4
[   36.351059] NET: Registered protocol family 5
[   36.597608] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   45.501261] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[   45.602133] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[   45.602278] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   51.072266] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   51.894236] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[   51.995130] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[   51.995244] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   52.374829] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   64.747163] wlan0: authenticate with 00:25:15:22:1d:74
[   64.769086] wlan0: send auth to 00:25:15:22:1d:74 (try 1/3)
[   64.970028] wlan0: send auth to 00:25:15:22:1d:74 (try 2/3)
[   65.171017] wlan0: send auth to 00:25:15:22:1d:74 (try 3/3)
[   65.372016] wlan0: authentication with 00:25:15:22:1d:74 timed out
[   67.620252] wlan0: authenticate with 00:25:15:22:1d:74
[   67.631300] wlan0: send auth to 00:25:15:22:1d:74 (try 1/3)
[   67.633087] wlan0: authenticated
[   67.641784] wlan0: waiting for beacon from 00:25:15:22:1d:74
[   67.642048] wlan0: associate with 00:25:15:22:1d:74 (try 1/3)
[   67.644600] wlan0: RX AssocResp from 00:25:15:22:1d:74 (capab=0x411 status=0 aid=1)
[   67.675334] wlan0: associated
[   67.675473] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  101.954109] usb 3-1: USB disconnect, device number 2
[ 1009.179916] PM: Syncing filesystems ... done.
[ 1009.575155] PM: Preparing system for mem sleep
[ 1013.104130] Freezing user space processes ... (elapsed 4.59 seconds) done.
[ 1017.702104] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[ 1017.713091] PM: Entering mem sleep
[ 1017.713118] Suspending console(s) (use no_console_suspend to debug)
[ 1017.729039] hdaps: setting ec_rate=0, filter_order=1
[ 1017.730071] sd 2:0:0:0: [sda] Synchronizing SCSI cache
[ 1017.730206] sd 2:0:0:0: [sda] Stopping disk
[ 1018.016745] e1000e 0000:00:19.0: wake-up capability enabled by ACPI
[ 1018.242113] PM: suspend of devices complete after 528.596 msecs
[ 1018.242739] PM: late suspend of devices complete after 0.621 msecs
[ 1018.276474] ehci_hcd 0000:00:1d.7: wake-up capability enabled by ACPI
[ 1018.287077] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3hot
[ 1018.287249] uhci_hcd 0000:00:1d.2: wake-up capability enabled by ACPI
[ 1018.287259] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D2
[ 1018.287386] uhci_hcd 0000:00:1d.1: wake-up capability enabled by ACPI
[ 1018.297058] uhci_hcd 0000:00:1d.0: wake-up capability enabled by ACPI
[ 1018.297069] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D2
[ 1018.297200] ehci_hcd 0000:00:1a.7: wake-up capability enabled by ACPI
[ 1018.308054] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3hot
[ 1018.308201] uhci_hcd 0000:00:1a.1: wake-up capability enabled by ACPI
[ 1018.308210] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D2
[ 1018.308335] uhci_hcd 0000:00:1a.0: wake-up capability enabled by ACPI
[ 1018.308461] PM: noirq suspend of devices complete after 65.717 msecs
[ 1018.309520] ACPI: Preparing to enter system sleep state S3
[ 1018.355100] PM: Saving platform NVS memory
[ 1018.356164] Disabling non-boot CPUs ...
[ 1018.357870] smpboot: CPU 1 is now offline
[ 1018.359029] Extended CMOS year: 2000
[ 1018.359029] ACPI: Low-level resume complete
[ 1018.359029] PM: Restoring platform NVS memory
[ 1018.359029] Extended CMOS year: 2000
[ 1018.360206] Enabling non-boot CPUs ...
[ 1018.360289] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 1018.379117] CPU1 is up
[ 1018.382469] ACPI: Waking up from system sleep state S3
[ 1018.479434] uhci_hcd 0000:00:1a.0: wake-up capability disabled by ACPI
[ 1018.479449] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
[ 1018.479581] uhci_hcd 0000:00:1a.1: wake-up capability disabled by ACPI
[ 1018.479592] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
[ 1018.490283] ehci_hcd 0000:00:1a.7: wake-up capability disabled by ACPI
[ 1018.502549] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
[ 1018.512158] uhci_hcd 0000:00:1d.0: wake-up capability disabled by ACPI
[ 1018.512295] uhci_hcd 0000:00:1d.1: wake-up capability disabled by ACPI
[ 1018.512307] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
[ 1018.512437] uhci_hcd 0000:00:1d.2: wake-up capability disabled by ACPI
[ 1018.512447] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
[ 1018.523306] ehci_hcd 0000:00:1d.7: wake-up capability disabled by ACPI
[ 1018.534463] nvidia 0000:01:00.0: power state changed by ACPI to D0
[ 1018.578606] PM: noirq resume of devices complete after 110.434 msecs
[ 1018.578996] PM: early resume of devices complete after 0.316 msecs
[ 1018.579120] e1000e 0000:00:19.0: wake-up capability disabled by ACPI
[ 1018.579272] uhci_hcd 0000:00:1a.1: setting latency timer to 64
[ 1018.579316] usb usb4: root hub lost power or was reset
[ 1018.579331] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[ 1018.579583] snd_hda_intel 0000:00:1b.0: irq 48 for MSI/MSI-X
[ 1018.579748] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 1018.579782] usb usb5: root hub lost power or was reset
[ 1018.579807] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 1018.579841] usb usb6: root hub lost power or was reset
[ 1018.579865] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 1018.579899] usb usb7: root hub lost power or was reset
[ 1018.579925] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 1018.579986] pci 0000:00:1e.0: setting latency timer to 64
[ 1018.580028] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 1018.580049] ahci 0000:00:1f.2: setting latency timer to 64
[ 1018.581034] ehci_hcd 0000:00:1a.7: setting latency timer to 64
[ 1018.581095] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1018.584182] ata2: port disabled--ignoring
[ 1018.584440] uhci_hcd 0000:00:1a.0: setting latency timer to 64
[ 1018.584465] usb usb3: root hub lost power or was reset
[ 1018.585114] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1019.453791] /dev/vmmon[8446]: HostIFReadUptimeWork: detected settimeofday: fixed uptimeBase old 18445391482272774128 new 18445391446215781686 attempts 1
[ 1019.472176] tpm_tis 00:0a: TPM is disabled/deactivated (0x6)
[ 1019.607474] ata1.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
[ 1019.607476] ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
[ 1019.608789] ata1.00: ACPI cmd e3/00:1f:00:00:00:a0 (IDLE) succeeded
[ 1019.609583] ata1.00: ACPI cmd e3/00:02:00:00:00:a0 (IDLE) succeeded
[ 1019.650491] ata1.00: configured for UDMA/33
[ 1019.657039] usb 5-1: reset full-speed USB device number 2 using uhci_hcd
[ 1019.885046] usb 3-2: reset full-speed USB device number 3 using uhci_hcd
[ 1020.831075] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 1020.843729] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[ 1020.843731] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[ 1020.843733] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[ 1020.846782] ata3.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[ 1020.846784] ata3.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[ 1020.846786] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[ 1020.848228] ata3.00: configured for UDMA/133
[ 1020.859075] sd 2:0:0:0: [sda] Starting disk
[ 1020.931955] thinkpad_acpi: ACPI backlight control delay disabled
[ 1020.933112] hdaps: initial mode latch is 0x05
[ 1020.933232] hdaps: setting ec_rate=250, filter_order=2
[ 1021.204917] PM: resume of devices complete after 2625.899 msecs
[ 1021.205269] PM: Finishing wakeup.
[ 1021.205270] Restarting tasks ... done.
[ 1021.218285] video LNXVIDEO:01: Restoring backlight state
[ 1021.219052] wlan0: deauthenticated from 00:25:15:22:1d:74 (Reason: 7)
[ 1021.251246] cfg80211: Calling CRDA to update world regulatory domain
[ 1021.294521] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1021.352490] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1021.409406] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1021.466230] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
[ 1021.790458] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1022.461283] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[ 1022.562161] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[ 1022.562289] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 1026.298676] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1029.337197] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1029.993512] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[ 1030.094257] e1000e 0000:00:19.0: irq 47 for MSI/MSI-X
[ 1030.094439] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 1030.377365] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1032.470485] wlan0: authenticate with 00:25:15:22:1d:74
[ 1032.470512] wlan0: send auth to 00:25:15:22:1d:74 (try 1/3)
[ 1032.472321] wlan0: authenticated
[ 1032.482014] wlan0: associate with 00:25:15:22:1d:74 (try 1/3)
[ 1032.484612] wlan0: RX AssocResp from 00:25:15:22:1d:74 (capab=0x411 status=0 aid=1)
[ 1032.513460] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1032.513519] wlan0: associated
[ 1034.092861] systemd-journald[117]: File /var/log/journal/8ed49f4f63fc90478b051d8f00000121/user-1001.journal corrupted or uncleanly shut down, renaming and replacing.

# 6  
Old 11-11-2012
This is where Tux is using the swap paritition to restore system/process stacks and RAM.
Code:
PM: Checking hibernation image partition swap:/dev/sda5

Look at vsock and vmnet - they are dynamically built by boot up and are having issues.

There are other similar issues. The short answer seems to me to be a conflict of user software with a "deferred" Tux startup. The actual delays reported by Tux are less than seconds. File sync is taking a looong time.

Here is the biggest Tux time consumer:
Code:
[  101.954109] usb 3-1: USB disconnect, device number 2
#start of this is not in the log so ^ this line I included. USB is not a big issue at all.
[ 1009.179916] PM: Syncing filesystems ... done.

My guess is that you have added a bunch of software, and you have a load of data on your filesystems, all of which conspire to make your life miserable.

By any chance did you add support for a new filesystem that did not come with the box?

If you have backups, make a full current backup, then try to restore system status (your system paritition is just system software, right) to a period way back when things were working well.
# 7  
Old 11-12-2012
Thanks for replying.

1. vsock and vmnet are VMware services and the issue existed before I even installed VMware.

2. The last time Tux worked properly was just after installed the system. I am not even sure whether it was on that system because it was nearly two years ago. I also never did system backups and only backup config files (started doing that a year after tux first had this issue).

3. I did not add any extra filesystems that are not already included in the kernel (I am using linux-pf kernel).

4. Resume from hibernating using 'systemctl hibernate' command resumes perfectly fine, without any delay (takes about 15 seconds, vs 180 seconds using tux). The only problem with it is that in the last stage of resume, it totally shuts down my laptop screen (including backlit) and I am not able to see anything, so I have to hard-reboot.
Login or Register to Ask a Question

Previous Thread | Next Thread

9 More Discussions You Might Find Interesting

1. Red Hat

Response Times

Hello all. Let me qualify my question by saying that I am struggling with how to ask the question I am semi green but have no issue reading up if pointed in the right direction. Please be gentle! A RHEL server 6.2. Hosts a statistical application that has some web apps and batch programming... (0 Replies)
Discussion started by: rsheikh01
0 Replies

2. UNIX for Dummies Questions & Answers

Pausing and resuming process on laptop

Hi, I'm wondering if it's possible to pause a process I'm running in the background, close my laptop (I need to leave the office), and continue the process (when I get home). I've been running a process for a really long time and I don't want to have to start it over. Thanks in advance! (9 Replies)
Discussion started by: ShiGua
9 Replies

3. What is on Your Mind?

Welcome in these 1337 times

Have you noticed that the Unix time right now starts with the combination "1337"? 1337 times indeed. ;-)) bakunin (10 Replies)
Discussion started by: bakunin
10 Replies

4. Shell Programming and Scripting

To get difference between 2 times.

Can anyone help me to write a script to get diffrence between 2 times. (platform- solaris) i.e., Diffence shoud be displayed in tems of hours. (Approximately) for eg: file1 = 05-Apr-2012 13:42:32 file2 = 04-Apr-2012 12:42:41 O/P is like : diff = 25 Hrs (2 Replies)
Discussion started by: thomasraj87
2 Replies

5. Programming

Problem with implementing the times() function in C (struct tms times return zero/negative values)

Hello, i'm trying to implement the times() function and i'm programming in C. I'm using the "struct tms" structure which consists of the fields: The tms_utime structure member is the CPU time charged for the execution of user instructions of the calling process. The tms_stime structure... (1 Reply)
Discussion started by: g_p
1 Replies

6. Shell Programming and Scripting

Executes many times

The code prints many times, "1st loop" and "2nd loop". How can I come out the if the condition is matched. Match should be only once and it should come out of the loop if the match is found time=$(date +"%H:%M:%S") echo $time while : do if then echo "1st loop" fi if then... (5 Replies)
Discussion started by: sandy1028
5 Replies

7. AIX

how would you know your server was rebooted 3 times or 5 times

Is there such location or command to know how many times did you reboot your server in that particular day?in AIX. (3 Replies)
Discussion started by: kenshinhimura
3 Replies

8. Solaris

solaris 10 not resuming from power save mode.

Dear Frnz, i have a ultra 45 with solaris 10 installed. I face a weird issue in that. once the machine goes to power save mode i am not able to bring the machine back by hitting the keys in keyboard or moving the mouse. I am able to rsh the machine from another machine. To bring the... (1 Reply)
Discussion started by: sriram.s
1 Replies

9. Solaris

System not resuming from stanby mode ---Solaris10

Dear Frnds, I have a weird issue with solaris 10. We bought a new Sun Ultra45 workstation and i installed solaris 10 in that. The problem is when it goes to standby mode i am not able to resume the system.The only thing i can do is to manually reboot and start working. The problem occurs... (0 Replies)
Discussion started by: sriram.s
0 Replies
Login or Register to Ask a Question