Bug 11794

Summary: The kernal makes normal boot instead of resume after hibernation
Product: Power Management Reporter: Michael Lashkevich (lashkevi)
Component: Hibernation/SuspendAssignee: Rafael J. Wysocki (rjw)
Status: CLOSED INVALID    
Severity: normal CC: htl10
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.27.2 Subsystem:
Regression: Yes Bisected commit-id:
Bug Depends on:    
Bug Blocks: 7216    
Attachments: /var/log/pm-suspend.log after failed resume
boot.msg after booting instead of resuming
dmesg output just after failed resume
the "/var/log/pm-suspend.log" file after a suspend INTERRUPTED by pressing the backspace key
Output of "dmesg" after a clean boot
Kernel compilation and git bisection instructions
lsmod output for 2.6.22
Dmesg output after 'echo core >/sys/power/pm_test; echo disk >/sys/power/state'
dmesg output just after failed resume (2.6.28-rc2-17-default, CONFIG_PM_DEBUG=y)
A comment of Alexander Prokofiev, the sysadmin of Landau Institute
Output of "dmesg |grep 'PM:'" after failed resume
Output of mkinitrd

Description Michael Lashkevich 2008-10-20 04:09:01 UTC
Latest working kernel version: 2.6.22.18-0.2 (standard OpenSUSE 10.3 kernel)
Earliest failing kernel version: 2.6.27.2
(From the repository "http://download.opensuse.org/repositories/home:/ervin:/kernel/openSUSE_10.3/" the files "kernel-*-2.6.27.2-16.1.i586.rpm" in the "i586" subdir.)
Distribution: OpenSUSE 10.3
Hardware Environment: Toshiba L300 11E
Software Environment:
Problem Description:

When I suspend to disk using the pm-utils (via kpowersave - powersaved) the computer seems to suspend normally, but when I power it on again it boots nomally instead of resuming the image saved to the swap space.

Steps to reproduce: 1. Boot the computer and log in a user.
2. Press suspend to disk line of the menu of the "kpowersave".
3. Wait till the cumputer create the image and shut down.
4. Power on the computer.

There are to log files below.

Here is the /var/log/pm-suspend.log file:

----------- Beginning of the file -------------------
Mon Oct 20 12:47:39 MSD 2008: running hibernate hooks.
===== Mon Oct 20 12:47:39 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/00clear =====
===== Mon Oct 20 12:47:39 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/01logging =====
hibernate initiated: Mon Oct 20 12:47:39 MSD 2008

Module                  Size  Used by
ip6t_LOG               10628  9 
nf_conntrack_ipv6      24892  4 
xt_pkttype              5888  4 
ipt_LOG                10116  10 
xt_limit                6404  19 
af_packet              20992  2 
autofs4                24964  1 
i915                   33024  1 
drm                    81192  2 i915
snd_pcm_oss            51456  0 
snd_mixer_oss          19456  1 snd_pcm_oss
snd_seq                57024  0 
snd_seq_device         11532  1 snd_seq
ip6t_REJECT             9344  3 
xt_tcpudp               7168  17 
ipt_REJECT              7040  3 
xt_state                6144  8 
iptable_mangle          6912  0 
iptable_nat            10248  0 
nf_nat                 24472  1 iptable_nat
iptable_filter          6784  1 
ip6table_mangle         6528  0 
nf_conntrack_ipv4      14984  7 iptable_nat,nf_nat
nf_conntrack           74336  5 nf_conntrack_ipv6,xt_state,iptable_nat,nf_nat,nf_conntrack_ipv4
ip_tables              16272  3 iptable_mangle,iptable_nat,iptable_filter
ip6table_filter         6656  1 
ip6_tables             17424  3 ip6t_LOG,ip6table_mangle,ip6table_filter
x_tables               18948  11 ip6t_LOG,xt_pkttype,ipt_LOG,xt_limit,ip6t_REJECT,xt_tcpudp,ipt_REJECT,xt_state,iptable_nat,ip_tables,ip6_tables
ipv6                  254376  19 nf_conntrack_ipv6,ip6t_REJECT,ip6table_mangle
dm_crypt               17412  0 
ext2                   67592  1 
mbcache                12292  1 ext2
loop                   19980  0 
dm_mod                 70204  1 dm_crypt
arc4                    6016  2 
ecb                     6912  2 
crypto_blkcipher       21508  2 dm_crypt,ecb
snd_hda_intel         383252  1 
rtl8187                48768  0 
snd_pcm                86148  2 snd_pcm_oss,snd_hda_intel
uvcvideo               56456  0 
snd_timer              26888  2 snd_seq,snd_pcm
snd_page_alloc         12552  2 snd_hda_intel,snd_pcm
snd_hwdep              11652  1 snd_hda_intel
compat_ioctl32          5376  1 uvcvideo
iTCO_wdt               14756  0 
battery                15876  0 
ac                      8836  0 
sr_mod                 18216  0 
button                 10896  0 
r8169                  32004  0 
videodev               35584  1 uvcvideo
v4l1_compat            17924  2 uvcvideo,videodev
iTCO_vendor_support     7940  1 iTCO_wdt
cdrom                  40472  1 sr_mod
output                  7040  0 
mac80211              209892  1 rtl8187
eeprom_93cx6            6656  1 rtl8187
i2c_i801               14864  0 
pcspkr                  6656  0 
rtc_cmos               15776  0 
snd                    62904  10 snd_pcm_oss,snd_mixer_oss,snd_seq,snd_seq_device,snd_hda_intel,snd_pcm,snd_timer,snd_hwdep
sg                     34740  0 
rtc_core               22684  1 rtc_cmos
soundcore              11336  1 snd
cfg80211               28040  2 rtl8187,mac80211
i2c_core               35092  1 i2c_i801
intel_agp              29116  1 
rtc_lib                 7040  1 rtc_core
joydev                 14144  0 
agpgart                38324  3 drm,intel_agp
usbhid                 52964  0 
hid                    40268  1 usbhid
ff_memless             11784  1 usbhid
sd_mod                 35992  4 
crc_t10dif              6016  1 sd_mod
uhci_hcd               29200  0 
ehci_hcd               50956  0 
usbcore               177868  6 rtl8187,uvcvideo,usbhid,uhci_hcd,ehci_hcd
piix                   10248  0 
ide_core              107032  1 piix
edd                    13000  0 
reiserfs              234164  1 
fan                     9092  0 
thermal                24732  0 
processor              50732  2 thermal
thermal_sys            15784  3 fan,thermal,processor
hwmon                   7324  1 thermal_sys
ata_piix               20740  0 
ahci                   33420  3 
libata                166888  2 ata_piix,ahci
scsi_mod              154284  4 sr_mod,sg,sd_mod,libata
dock                   16780  1 libata

             total       used       free     shared    buffers     cached
Mem:       1023020     527856     495164          0      44388     298188
-/+ buffers/cache:     185280     837740
Swap:      2008084          0    2008084

===== Mon Oct 20 12:47:39 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/05led =====
===== Mon Oct 20 12:47:39 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/06autofs =====
Shutting down automount ..done
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/10NetworkManager =====
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/24dock =====
Mon Oct 20 12:47:40 MSD 2008: running misc hooks for event undock.
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/30s2disk-check =====
INFO: checking for suspend-to-disk prerequisites...
  using userspace suspend method
  setting resume device to /dev/sda1
  setting image size to 471407616
  adding these parameters from /etc/suspend.conf:
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/45pcmcia =====
ejecting PCMCIA cards...
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/50modules =====
trying to unload: rtl8187
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/55battery =====
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/80acpi-fan =====
===== Mon Oct 20 12:47:40 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/80videobios =====
===== Mon Oct 20 12:47:43 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/94cpufreq =====
===== Mon Oct 20 12:47:43 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/95led =====
===== Mon Oct 20 12:47:43 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/99Zgrub =====
INFO: running prepare-grub
  Skipping grub entry #1, because it has the noresume option
  Skipping grub entry #3, because it has the noresume option
  running kernel is grub menu entry 0 (vmlinuz-2.6.27.2-16-default)
  preparing boot-loader: selecting entry 0, kernel /boot/2.6.27.2-16-default
  grub-once:   saving original /boot/grub/default
  running '/usr/sbin/grubonce 0'
Using entry #0: openSUSE 10.3 - 2.6.27.2-16
    time needed for sync: 1.2 seconds, time needed for grub: 0.0 seconds.
===== Mon Oct 20 12:47:46 MSD 2008: running hook: /usr/lib/pm-utils/sleep.d/99info =====
Mon Oct 20 12:47:46 MSD 2008: done running hibernate hooks.
+ /usr/sbin/s2disk --config /var/lib/s2disk.conf
------------- End of the file --------------------------------------------

Here is the /var/log/boot.msg file after this failed resume:

----------- Beginning of the file ---------------------
Inspecting /boot/System.map-2.6.27.2-16-default
Cannot find map file.
No module symbols loaded - kernel modules not enabled.

Cannot build symbol table - disabling symbol lookups
klogd 1.4.1, log source = ksyslog started.
<6>Initializing cgroup subsys cpuset
<6>Initializing cgroup subsys cpu
<5>Linux version 2.6.27.2-16-default (geeko@buildhost) (gcc version 4.2.1 (SUSE Linux)) #1 SMP 2008-10-18 21:19:27 +0200
<6>BIOS-provided physical RAM map:
<6> BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
<6> BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
<6> BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
<6> BIOS-e820: 0000000000100000 - 000000003f4de000 (usable)
<6> BIOS-e820: 000000003f4de000 - 000000003f4e9000 (reserved)
<6> BIOS-e820: 000000003f4e9000 - 000000003f543000 (usable)
<6> BIOS-e820: 000000003f543000 - 000000003f546000 (reserved)
<6> BIOS-e820: 000000003f546000 - 000000003f5bb000 (usable)
<6> BIOS-e820: 000000003f5bb000 - 000000003f5bf000 (reserved)
<6> BIOS-e820: 000000003f5bf000 - 000000003f66c000 (usable)
<6> BIOS-e820: 000000003f66c000 - 000000003f6bf000 (ACPI NVS)
<6> BIOS-e820: 000000003f6bf000 - 000000003f700000 (ACPI data)
<6> BIOS-e820: 000000003f700000 - 0000000040000000 (reserved)
<6> BIOS-e820: 00000000f8000000 - 00000000fc000000 (reserved)
<6> BIOS-e820: 00000000fec00000 - 00000000fec01000 (reserved)
<6> BIOS-e820: 00000000fed14000 - 00000000fed1a000 (reserved)
<6> BIOS-e820: 00000000fed1c000 - 00000000fed20000 (reserved)
<6> BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
<6> BIOS-e820: 00000000fff00000 - 0000000100000000 (reserved)
<6>last_pfn = 0x3f66c max_arch_pfn = 0x100000
<6>x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
<7>kernel direct mapping tables up to 38000000 @ 7000-c000
<6>RAMDISK: 37bc1000 - 37fef8da
<6>DMI 2.4 present.
<4>ACPI: RSDP 000FE020, 0024 (r2 TOSINV)
<4>ACPI: XSDT 3F6FE120, 006C (r1 TOSINV TOSINV00        1       1000013)
<4>ACPI: FACP 3F6FD000, 00F4 (r4 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: DSDT 3F6F5000, 78BB (r1 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: FACS 3F675000, 0040
<4>ACPI: APIC 3F6F4000, 0068 (r2 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: HPET 3F6F3000, 0038 (r1 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: MCFG 3F6F2000, 003C (r1 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: ASF! 3F6F1000, 00A5 (r32 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: SLIC 3F6F0000, 0176 (r1 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: BOOT 3F6EF000, 0028 (r1 TOSINV TOSINV00        1 MSFT  1000013)
<4>ACPI: SSDT 3F6EE000, 05B3 (r1  PmRef  Cpu0Cst     3001 INTL 20051117)
<4>ACPI: SSDT 3F6ED000, 04C4 (r1  PmRef    CpuPm     3000 INTL 20051117)
<5>ACPI: DMI detected: Toshiba
<5>118MB HIGHMEM available.
<5>896MB LOWMEM available.
<6>  mapped low ram: 0 - 38000000
<6>  low ram: 00000000 - 38000000
<6>  bootmap 00009000 - 00010000
<6>(9 early reservations) ==> bootmem [0000000000 - 0038000000]
<6>  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
<6>  #1 [0000001000 - 0000002000]    EX TRAMPOLINE ==> [0000001000 - 0000002000]
<6>  #2 [0000006000 - 0000007000]       TRAMPOLINE ==> [0000006000 - 0000007000]
<6>  #3 [0000100000 - 000066119c]    TEXT DATA BSS ==> [0000100000 - 000066119c]
<6>  #4 [0037bc1000 - 0037fef8da]          RAMDISK ==> [0037bc1000 - 0037fef8da]
<6>  #5 [0000662000 - 0000665000]    INIT_PG_TABLE ==> [0000662000 - 0000665000]
<6>  #6 [000009fc00 - 0000100000]    BIOS reserved ==> [000009fc00 - 0000100000]
<6>  #7 [0000007000 - 0000009000]          PGTABLE ==> [0000007000 - 0000009000]
<6>  #8 [0000009000 - 0000010000]          BOOTMAP ==> [0000009000 - 0000010000]
<6>found SMP MP-table at [c00fe230] 000fe230
<4>Zone PFN ranges:
<4>  DMA      0x00000000 -> 0x00001000
<4>  Normal   0x00001000 -> 0x00038000
<4>  HighMem  0x00038000 -> 0x0003f66c
<4>Movable zone start PFN for each node
<4>early_node_map[5] active PFN ranges
<4>    0: 0x00000000 -> 0x0000009f
<4>    0: 0x00000100 -> 0x0003f4de
<4>    0: 0x0003f4e9 -> 0x0003f543
<4>    0: 0x0003f546 -> 0x0003f5bb
<4>    0: 0x0003f5bf -> 0x0003f66c
<7>On node 0 totalpages: 259577
<7>free_area_init_node: node 0, pgdat c0532900, node_mem_map c1000000
<7>  DMA zone: 3963 pages, LIFO batch:0
<7>  Normal zone: 223300 pages, LIFO batch:31
<7>  HighMem zone: 30031 pages, LIFO batch:7
<6>Using APIC driver default
<6>ACPI: PM-Timer IO Port: 0x408
<7>ACPI: Local APIC address 0xfee00000
<6>ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
<6>ACPI: LAPIC (acpi_id[0x02] lapic_id[0x00] disabled)
<6>ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
<6>ACPI: LAPIC_NMI (acpi_id[0x02] high edge lint[0x1])
<6>ACPI: IOAPIC (id[0x04] address[0xfec00000] gsi_base[0])
<6>IOAPIC[0]: apic_id 4, version 32, address 0xfec00000, GSI 0-23
<6>ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
<6>ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
<7>ACPI: IRQ0 used by override.
<7>ACPI: IRQ2 used by override.
<7>ACPI: IRQ9 used by override.
<4>Enabling APIC mode:  Flat.  Using 1 I/O APICs
<6>ACPI: HPET id: 0x8086a201 base: 0xfed00000
<6>Using ACPI (MADT) for SMP configuration information
<6>SMP: Allowing 2 CPUs, 1 hotplug CPUs
<7>mapped APIC to ffffb000 (fee00000)
<7>mapped IOAPIC to ffffa000 (fec00000)
<6>PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
<6>PM: Registered nosave memory: 00000000000a0000 - 00000000000e0000
<6>PM: Registered nosave memory: 00000000000e0000 - 0000000000100000
<6>Allocating PCI resources starting at 50000000 (gap: 40000000:b8000000)
<6>PERCPU: Allocating 39068 bytes of per cpu data
<7>NR_CPUS: 32, nr_cpu_ids: 2, nr_node_ids 1
<4>Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 257294
<5>Kernel command line: root=/dev/sda3 vga=791 resume=/dev/sda1 splash=verbose acpi_osi=!Linux acpi_sleep=s4_nohwsig  showopts
<6>bootsplash: verbose mode.
<6>Enabling fast FPU save and restore... done.
<6>Enabling unmasked SIMD FPU exception support... done.
<6>Initializing CPU#0
<4>PID hash table entries: 4096 (order: 12, 16384 bytes)
<6>TSC: PIT calibration confirmed by PMTIMER.
<6>TSC: using PIT calibration value
<4>Detected 1995.200 MHz processor.
<4>Console: colour dummy device 80x25
<6>console [tty0] enabled
<6>Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
<6>Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
<6>Memory: 1018132k/1038768k available (2326k kernel code, 19876k reserved, 2056k data, 308k init, 121192k highmem)
<6>virtual kernel memory layout:
<6>    fixmap  : 0xffdf6000 - 0xfffff000   (2084 kB)
<6>    pkmap   : 0xff400000 - 0xff800000   (4096 kB)
<6>    vmalloc : 0xf8800000 - 0xff3fe000   ( 107 MB)
<6>    lowmem  : 0xc0000000 - 0xf8000000   ( 896 MB)
<6>      .init : 0xc054d000 - 0xc059a000   ( 308 kB)
<6>      .data : 0xc0345a8e - 0xc0547aa8   (2056 kB)
<6>      .text : 0xc0100000 - 0xc0345a8e   (2326 kB)
<6>Checking if this processor honours the WP bit even in supervisor mode...Ok.
<7>CPA: page pool initialized 1 of 1 pages preallocated
<7>hpet clockevent registered
<6>Calibrating delay loop (skipped), value calculated using timer frequency.. 3990.40 BogoMIPS (lpj=7980800)
<4>kdb version 4.4 by Keith Owens, Scott Lurndal. Copyright SGI, All Rights Reserved
<6>Security Framework initialized
<6>SELinux:  Disabled at boot.
<6>AppArmor: AppArmor initialized
<4>Mount-cache hash table entries: 512
<6>Initializing cgroup subsys ns
<6>Initializing cgroup subsys cpuacct
<6>Initializing cgroup subsys memory
<6>Initializing cgroup subsys devices
<6>CPU: L1 I cache: 32K, L1 D cache: 32K
<6>CPU: L2 cache: 1024K
<6>Intel machine check architecture supported.
<6>Intel machine check reporting enabled on CPU#0.
<6>using mwait in idle threads.
<6>Checking 'hlt' instruction... OK.
<6>SMP alternatives: switching to UP code
<6>ACPI: Core revision 20080609
<6>ACPI: Checking initramfs for custom DSDT
<4>Parsing all Control Methods:
<4>Table [DSDT](id 0001) - 1234 Objects with 71 Devices 234 Methods 34 Regions
<4>Parsing all Control Methods:
<4>Table [SSDT](id 0002) - 1 Objects with 0 Devices 1 Methods 0 Regions
<4>Parsing all Control Methods:
<4>Table [SSDT](id 0003) - 13 Objects with 0 Devices 4 Methods 0 Regions
<4> tbxface-0596 [00] tb_load_namespace     : ACPI Tables successfully acquired
<4>evxfevnt-0091 [00] enable                : Transition to ACPI mode successful
<4>ENABLING IO-APIC IRQs
<6>..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
<6>CPU0: Intel(R) Celeron(R) CPU          550  @ 2.00GHz stepping 01
<6>Brought up 1 CPUs
<6>Total of 1 processors activated (3990.40 BogoMIPS).
<7>CPU0 attaching sched-domain:
<7> domain 0: span 0 level CPU
<7>  groups: 0
<6>net_namespace: 1044 bytes
<6>Booting paravirtualized kernel on bare hardware
<6>NET: Registered protocol family 16
<6>ACPI: bus type pci registered
<5>PCI: MCFG configuration 0: base f8000000 segment 0 buses 0 - 63
<5>PCI: MCFG area at f8000000 reserved in E820
<6>PCI: Using MMCONFIG for extended config space
<6>PCI: Using configuration type 1 for base access
<4>evgpeblk-0957 [00] ev_create_gpe_block   : GPE 00 to 1F [_GPE] 4 regs on int 0x9
<7>ACPI: EC: Look up EC in DSDT
<4>Completing Region/Field/Buffer/Package initialization:..............................................................................
<4>Initialized 27/34 Regions 0/0 Fields 25/26 Buffers 26/27 Packages (1257 nodes)
<4>Initializing Device/Processor/Thermal objects by executing _INI methods:<5>ACPI: BIOS _OSI(Linux) query ignored via cmdline
<4>.
<4>Executed 1 _INI methods requiring 1 _STA executions (examined 76 objects)
<4>evgpeblk-1054 [00] ev_initialize_gpe_bloc: Found 6 Wake, Enabled 5 Runtime GPEs in this block
<6>ACPI: Interpreter enabled
<6>ACPI: (supports S0 S1 S3 S4 S5)
<6>ACPI: Using IOAPIC for interrupt routing
<6>ACPI: EC: non-query interrupt received, switching to interrupt mode
<3>ACPI: EC: GPE storm detected, disabling EC GPE
<6>ACPI: EC: GPE = 0x17, I/O: command/status = 0x66, data = 0x62
<6>ACPI: EC: driver started in poll mode
<6>ACPI: PCI Root Bridge [PCI0] (0000:00)
<7>PCI: 0000:00:02.0 reg 10 64bit mmio: [52100000, 521fffff]
<7>PCI: 0000:00:02.0 reg 18 32bit mmio: [40000000, 4fffffff]
<7>PCI: 0000:00:02.0 reg 20 io port: [5110, 5117]
<7>PCI: 0000:00:02.1 reg 10 64bit mmio: [52200000, 522fffff]
<7>PCI: 0000:00:1a.0 reg 20 io port: [50c0, 50df]
<7>PCI: 0000:00:1a.1 reg 20 io port: [50a0, 50bf]
<7>PCI: 0000:00:1a.7 reg 10 32bit mmio: [54304c00, 54304fff]
<6>pci 0000:00:1a.7: PME# supported from D0 D3hot D3cold
<6>pci 0000:00:1a.7: PME# disabled
<7>PCI: 0000:00:1b.0 reg 10 64bit mmio: [54300000, 54303fff]
<6>pci 0000:00:1b.0: PME# supported from D0 D3hot D3cold
<6>pci 0000:00:1b.0: PME# disabled
<6>pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
<6>pci 0000:00:1c.0: PME# disabled
<6>pci 0000:00:1c.4: PME# supported from D0 D3hot D3cold
<6>pci 0000:00:1c.4: PME# disabled
<7>PCI: 0000:00:1d.0 reg 20 io port: [5080, 509f]
<7>PCI: 0000:00:1d.1 reg 20 io port: [5060, 507f]
<7>PCI: 0000:00:1d.2 reg 20 io port: [5040, 505f]
<7>PCI: 0000:00:1d.7 reg 10 32bit mmio: [54304800, 54304bff]
<6>pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
<6>pci 0000:00:1d.7: PME# disabled
<6>pci 0000:00:1f.0: quirk: region 0400-047f claimed by ICH6 ACPI/GPIO/TCO
<6>pci 0000:00:1f.0: quirk: region 0500-053f claimed by ICH6 GPIO
<7>PCI: 0000:00:1f.1 reg 10 io port: [5108, 510f]
<7>PCI: 0000:00:1f.1 reg 14 io port: [5124, 5127]
<7>PCI: 0000:00:1f.1 reg 18 io port: [5100, 5107]
<7>PCI: 0000:00:1f.1 reg 1c io port: [5120, 5123]
<7>PCI: 0000:00:1f.1 reg 20 io port: [50e0, 50ef]
<7>PCI: 0000:00:1f.2 reg 10 io port: [50f8, 50ff]
<7>PCI: 0000:00:1f.2 reg 14 io port: [511c, 511f]
<7>PCI: 0000:00:1f.2 reg 18 io port: [50f0, 50f7]
<7>PCI: 0000:00:1f.2 reg 1c io port: [5118, 511b]
<7>PCI: 0000:00:1f.2 reg 20 io port: [5020, 503f]
<7>PCI: 0000:00:1f.2 reg 24 32bit mmio: [54304000, 543047ff]
<6>pci 0000:00:1f.2: PME# supported from D3hot
<6>pci 0000:00:1f.2: PME# disabled
<7>PCI: 0000:00:1f.3 reg 10 32bit mmio: [54305000, 543050ff]
<7>PCI: 0000:00:1f.3 reg 20 io port: [5000, 501f]
<7>PCI: 0000:02:00.0 reg 10 io port: [3000, 30ff]
<7>PCI: 0000:02:00.0 reg 18 32bit mmio: [50010000, 50010fff]
<7>PCI: 0000:02:00.0 reg 20 32bit mmio: [50000000, 5000ffff]
<3>pci 0000:02:00.0: unsupported PM cap regs version (7)
<7>PCI: bridge 0000:00:1c.0 io port: [3000, 4fff]
<7>PCI: bridge 0000:00:1c.0 32bit mmio: [53300000, 542fffff]
<7>PCI: bridge 0000:00:1c.0 64bit mmio pref: [50000000, 510fffff]
<7>PCI: bridge 0000:00:1c.4 io port: [2000, 2fff]
<7>PCI: bridge 0000:00:1c.4 32bit mmio: [52300000, 532fffff]
<7>PCI: bridge 0000:00:1c.4 64bit mmio pref: [51100000, 520fffff]
<6>pci 0000:00:1e.0: transparent bridge
<7>bus 00 -> node 0
<7>ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
<7>ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.P32_._PRT]
<7>ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP1._PRT]
<7>ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP5._PRT]
<6>ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 *5 7 9 10 11 12)
<6>ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 7 9 10 *11 12)
<6>ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 7 9 10 *11 12)
<6>ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 7 9 10 *11 12)
<6>ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 7 9 10 11 12) *0, disabled.
<6>ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 7 9 *10 11 12)
<6>ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 7 9 10 *11 12)
<6>ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 7 9 10 11 12) *0, disabled.
<6>ACPI: Power Resource [FN00] (on)
<6>Linux Plug and Play Support v0.97 (c) Adam Belay
<6>pnp: PnP ACPI init
<6>ACPI: bus type pnp registered
<6>pnp: PnP ACPI: found 9 devices
<6>ACPI: ACPI bus type pnp unregistered
<6>PnPBIOS: Disabled by ACPI PNP
<6>PCI: Using ACPI for IRQ routing
<6>hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
<6>hpet0: 3 64-bit timers, 14318180 Hz
<6>AppArmor: AppArmor Filesystem Enabled
<4>ACPI Error (nseval-0159): Insufficient arguments - method [_OSC] needs 5, found 4 [20080609]
<4>ACPI: RTC can wake from S4
<6>system 00:01: ioport range 0x164e-0x164f has been reserved
<6>system 00:01: ioport range 0x800-0x80f has been reserved
<6>system 00:01: ioport range 0x400-0x47f has been reserved
<6>system 00:01: ioport range 0x500-0x53f has been reserved
<6>system 00:01: iomem range 0xf8000000-0xfbffffff could not be reserved
<6>system 00:01: iomem range 0xfed1c000-0xfed1ffff could not be reserved
<6>system 00:01: iomem range 0xfed14000-0xfed17fff could not be reserved
<6>system 00:01: iomem range 0xfed18000-0xfed18fff could not be reserved
<6>system 00:01: iomem range 0xfed19000-0xfed19fff could not be reserved
<6>system 00:01: iomem range 0xfec00000-0xfec00fff could not be reserved
<6>system 00:01: iomem range 0xfee00000-0xfee00fff could not be reserved
<6>system 00:04: iomem range 0xfed00000-0xfed003ff has been reserved
<6>pci 0000:00:1c.0: PCI bridge, secondary bus 0000:02
<6>pci 0000:00:1c.0:   IO window: 0x3000-0x4fff
<6>pci 0000:00:1c.0:   MEM window: 0x53300000-0x542fffff
<6>pci 0000:00:1c.0:   PREFETCH window: 0x00000050000000-0x000000510fffff
<6>pci 0000:00:1c.4: PCI bridge, secondary bus 0000:08
<6>pci 0000:00:1c.4:   IO window: 0x2000-0x2fff
<6>pci 0000:00:1c.4:   MEM window: 0x52300000-0x532fffff
<6>pci 0000:00:1c.4:   PREFETCH window: 0x00000051100000-0x000000520fffff
<6>pci 0000:00:1e.0: PCI bridge, secondary bus 0000:06
<6>pci 0000:00:1e.0:   IO window: disabled
<6>pci 0000:00:1e.0:   MEM window: disabled
<6>pci 0000:00:1e.0:   PREFETCH window: disabled
<6>pci 0000:00:1c.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
<7>pci 0000:00:1c.0: setting latency timer to 64
<6>pci 0000:00:1c.4: PCI INT A -> GSI 17 (level, low) -> IRQ 17
<7>pci 0000:00:1c.4: setting latency timer to 64
<7>pci 0000:00:1e.0: setting latency timer to 64
<6>bus: 00 index 0 io port: [0, ffff]
<6>bus: 00 index 1 mmio: [0, ffffffff]
<6>bus: 02 index 0 io port: [3000, 4fff]
<6>bus: 02 index 1 mmio: [53300000, 542fffff]
<6>bus: 02 index 2 mmio: [50000000, 510fffff]
<6>bus: 02 index 3 mmio: [0, 0]
<6>bus: 08 index 0 io port: [2000, 2fff]
<6>bus: 08 index 1 mmio: [52300000, 532fffff]
<6>bus: 08 index 2 mmio: [51100000, 520fffff]
<6>bus: 08 index 3 mmio: [0, 0]
<6>bus: 06 index 0 mmio: [0, 0]
<6>bus: 06 index 1 mmio: [0, 0]
<6>bus: 06 index 2 mmio: [0, 0]
<6>bus: 06 index 3 io port: [0, ffff]
<6>bus: 06 index 4 mmio: [0, ffffffff]
<6>NET: Registered protocol family 2
<6>IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
<6>TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
<6>TCP bind hash table entries: 65536 (order: 7, 524288 bytes)
<6>TCP: Hash tables configured (established 131072 bind 65536)
<6>TCP reno registered
<6>NET: Registered protocol family 1
<6>Unpacking initramfs...<7>Switched to high resolution mode on CPU 0
<4> done
<6>Freeing initrd memory: 4282k freed
<6>Simple Boot Flag at 0x44 set to 0x1
<6>Machine check exception polling timer started.
<6>audit: initializing netlink socket (disabled)
<5>type=2000 audit(1224492506.604:1): initialized
<4>highmem bounce pool size: 64 pages
<6>HugeTLB registered 4 MB page size, pre-allocated 0 pages
<5>VFS: Disk quotas dquot_6.5.1
<4>Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
<6>msgmni has been set to 440
<6>Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
<6>io scheduler noop registered
<6>io scheduler anticipatory registered
<6>io scheduler deadline registered
<6>io scheduler cfq registered (default)
<7>pci 0000:00:02.0: Boot video device
<7>pcieport-driver 0000:00:1c.0: setting latency timer to 64
<6>pcieport-driver 0000:00:1c.0: found MSI capability
<7>pci_express 0000:00:1c.0:pcie00: allocate port service
<7>pci_express 0000:00:1c.0:pcie02: allocate port service
<7>pci_express 0000:00:1c.0:pcie03: allocate port service
<7>pcieport-driver 0000:00:1c.4: setting latency timer to 64
<6>pcieport-driver 0000:00:1c.4: found MSI capability
<7>pci_express 0000:00:1c.4:pcie00: allocate port service
<7>pci_express 0000:00:1c.4:pcie02: allocate port service
<7>pci_express 0000:00:1c.4:pcie03: allocate port service
<6>vesafb: framebuffer at 0x40000000, mapped to 0xf8880000, using 6144k, total 7616k
<6>vesafb: mode is 1024x768x16, linelength=2048, pages=3
<6>vesafb: scrolling: redraw
<6>vesafb: Truecolor: size=0:5:6:5, shift=0:11:5:0
<4>Console: switching to colour frame buffer device 128x48
<6>fb0: VESA VGA frame buffer device
<6>isapnp: Scanning for PnP cards...
<6>isapnp: No Plug & Play device found
<7>hpet_resources: 0xfed00000 is busy
<6>Serial: 8250/16550 driver8 ports, IRQ sharing enabled
<6>PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:MOUE] at 0x60,0x64 irq 1,12
<6>serio: i8042 KBD port at 0x60,0x64 irq 1
<6>serio: i8042 AUX port at 0x60,0x64 irq 12
<6>mice: PS/2 mouse device common for all mice
<6>cpuidle: using governor ladder
<6>cpuidle: using governor menu
<6>TCP cubic registered
<4>Using IPI No-Shortcut mode
<4>registered taskstats version 1
<6>Freeing unused kernel memory: 308k freed
<6>Write protecting the kernel text: 2328k
<6>Write protecting the kernel read-only data: 1864k
<6>input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
<6>ACPI: No dock devices found.
<5>SCSI subsystem initialized
<7>libata version 3.00 loaded.
<7>ahci 0000:00:1f.2: version 3.0
<6>ahci 0000:00:1f.2: PCI INT B -> GSI 19 (level, low) -> IRQ 19
<6>ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 3 ports 3 Gbps 0x3 impl SATA mode
<6>ahci 0000:00:1f.2: flags: 64bit ncq sntf ilck stag pm led clo pmp pio slum part ems 
<7>ahci 0000:00:1f.2: setting latency timer to 64
<6>scsi0 : ahci
<6>scsi1 : ahci
<6>scsi2 : ahci
<6>ata1: SATA max UDMA/133 abar m2048@0x54304000 port 0x54304100 irq 221
<6>ata2: SATA max UDMA/133 abar m2048@0x54304000 port 0x54304180 irq 221
<6>ata3: DUMMY
<6>ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
<6>ata1.00: ATA-8: FUJITSU MHY2120BH, 0040020B, max UDMA/100
<6>ata1.00: 234441648 sectors, multi 16: LBA48 NCQ (depth 31/32)
<6>ata1.00: configured for UDMA/100
<6>Synaptics Touchpad, model: 1, fw: 6.3, id: 0x9280b1, caps: 0xa04711/0xa04000
<6>synaptics: Toshiba Satellite L300 detected, limiting rate to 40pps.
<6>ata2: SATA link down (SStatus 0 SControl 300)
<5>scsi 0:0:0:0: Direct-Access     ATA      FUJITSU MHY2120B 0040 PQ: 0 ANSI: 5
<7>ata_piix 0000:00:1f.1: version 2.12
<6>ata_piix 0000:00:1f.1: PCI INT A -> GSI 19 (level, low) -> IRQ 19
<7>ata_piix 0000:00:1f.1: setting latency timer to 64
<6>scsi3 : ata_piix
<6>scsi4 : ata_piix
<6>ata4: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x50e0 irq 14
<6>ata5: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x50e8 irq 15
<6>input: SynPS/2 Synaptics TouchPad as /devices/platform/i8042/serio1/input/input1
<6>ata4.00: ATAPI: MATSHITADVD-RAM UJ-850S, 1.40, max UDMA/33
<6>ata4.00: configured for UDMA/33
<5>scsi 3:0:0:0: CD-ROM            MATSHITA DVD-RAM UJ-850S  1.40 PQ: 0 ANSI: 5
<7>Monitor-Mwait will be used to enter C-1 state
<7>Monitor-Mwait will be used to enter C-2 state
<7>Monitor-Mwait will be used to enter C-3 state
<6>ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
<6>processor ACPI0007:00: registered as cooling_device0
<6>ACPI: Processor [CPU0] (supports 8 throttling states)
<6>thermal LNXTHERM:01: registered as thermal_zone0
<4>ACPI: Transitioning device [FAN] to D3
<6>ACPI: Thermal Zone [THRM] (47 C)
<6>fan PNP0C0B:00: registered as cooling_device1
<6>ACPI: Fan [FAN] (on)
<6>BIOS EDD facility v0.16 2004-Jun-25, 1 devices found
<6>Uniform Multi-Platform E-IDE driver
<6>udevd version 128 started
<6>usbcore: registered new interface driver usbfs
<6>usbcore: registered new interface driver hub
<6>usbcore: registered new device driver usb
<6>ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 18 (level, low) -> IRQ 18
<7>ehci_hcd 0000:00:1a.7: setting latency timer to 64
<6>ehci_hcd 0000:00:1a.7: EHCI Host Controller
<6>USB Universal Host Controller Interface driver v3.0
<6>ehci_hcd 0000:00:1a.7: new USB bus registered, assigned bus number 1
<6>ehci_hcd 0000:00:1a.7: debug port 1
<7>ehci_hcd 0000:00:1a.7: cache line size of 32 is not supported
<6>ehci_hcd 0000:00:1a.7: irq 18, io mem 0x54304c00
<6>ehci_hcd 0000:00:1a.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
<6>usb usb1: configuration #1 chosen from 1 choice
<6>hub 1-0:1.0: USB hub found
<6>hub 1-0:1.0: 4 ports detected
<5>sd 0:0:0:0: [sda] 234441648 512-byte hardware sectors: (120GB/111GiB)
<5>sd 0:0:0:0: [sda] Write Protect is off
<7>sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
<5>sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
<5>sd 0:0:0:0: [sda] 234441648 512-byte hardware sectors: (120GB/111GiB)
<5>sd 0:0:0:0: [sda] Write Protect is off
<7>sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
<5>sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
<6> sda: sda1 sda2 sda3
<5>sd 0:0:0:0: [sda] Attached SCSI disk
<6>usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
<6>usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb1: Product: EHCI Host Controller
<6>usb usb1: Manufacturer: Linux 2.6.27.2-16-default ehci_hcd
<6>usb usb1: SerialNumber: 0000:00:1a.7
<6>uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
<7>uhci_hcd 0000:00:1a.0: setting latency timer to 64
<6>uhci_hcd 0000:00:1a.0: UHCI Host Controller
<6>uhci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 2
<6>uhci_hcd 0000:00:1a.0: irq 16, io base 0x000050c0
<6>usb usb2: configuration #1 chosen from 1 choice
<6>hub 2-0:1.0: USB hub found
<6>hub 2-0:1.0: 2 ports detected
<4>Marking TSC unstable due to TSC halts in idle
<6>usb 1-2: new high speed USB device using ehci_hcd and address 2
<6>usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
<6>usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb2: Product: UHCI Host Controller
<6>usb usb2: Manufacturer: Linux 2.6.27.2-16-default uhci_hcd
<6>usb usb2: SerialNumber: 0000:00:1a.0
<6>uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
<7>uhci_hcd 0000:00:1a.1: setting latency timer to 64
<6>uhci_hcd 0000:00:1a.1: UHCI Host Controller
<6>uhci_hcd 0000:00:1a.1: new USB bus registered, assigned bus number 3
<6>uhci_hcd 0000:00:1a.1: irq 21, io base 0x000050a0
<6>usb 1-2: configuration #1 chosen from 1 choice
<6>usb usb3: configuration #1 chosen from 1 choice
<6>hub 3-0:1.0: USB hub found
<6>usb 1-2: New USB device found, idVendor=04f2, idProduct=b070
<6>usb 1-2: New USB device strings: Mfr=2, Product=1, SerialNumber=3
<6>usb 1-2: Product: CNF7051
<6>usb 1-2: Manufacturer: Chicony Electronics Co., Ltd.
<6>usb 1-2: SerialNumber: SN0001
<6>hub 3-0:1.0: 2 ports detected
<6>usb usb3: New USB device found, idVendor=1d6b, idProduct=0001
<6>usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<4>Clocksource tsc unstable (delta = -75445209 ns)
<6>usb usb3: Product: UHCI Host Controller
<6>usb usb3: Manufacturer: Linux 2.6.27.2-16-default uhci_hcd
<6>usb usb3: SerialNumber: 0000:00:1a.1
<6>ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
<7>ehci_hcd 0000:00:1d.7: setting latency timer to 64
<6>ehci_hcd 0000:00:1d.7: EHCI Host Controller
<6>ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 4
<6>ehci_hcd 0000:00:1d.7: debug port 1
<7>ehci_hcd 0000:00:1d.7: cache line size of 32 is not supported
<6>ehci_hcd 0000:00:1d.7: irq 23, io mem 0x54304800
<6>ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
<6>usb usb4: configuration #1 chosen from 1 choice
<6>hub 4-0:1.0: USB hub found
<6>hub 4-0:1.0: 6 ports detected
<6>usb usb4: New USB device found, idVendor=1d6b, idProduct=0002
<6>usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb4: Product: EHCI Host Controller
<6>usb usb4: Manufacturer: Linux 2.6.27.2-16-default ehci_hcd
<6>usb usb4: SerialNumber: 0000:00:1d.7
<6>uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
<7>uhci_hcd 0000:00:1d.0: setting latency timer to 64
<6>uhci_hcd 0000:00:1d.0: UHCI Host Controller
<6>uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 5
<6>uhci_hcd 0000:00:1d.0: irq 23, io base 0x00005080
<6>usb usb5: configuration #1 chosen from 1 choice
<6>hub 5-0:1.0: USB hub found
<6>hub 5-0:1.0: 2 ports detected
<6>usb 4-6: new high speed USB device using ehci_hcd and address 3
<6>usb usb5: New USB device found, idVendor=1d6b, idProduct=0001
<6>usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb5: Product: UHCI Host Controller
<6>usb usb5: Manufacturer: Linux 2.6.27.2-16-default uhci_hcd
<6>usb usb5: SerialNumber: 0000:00:1d.0
<6>uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 19 (level, low) -> IRQ 19
<7>uhci_hcd 0000:00:1d.1: setting latency timer to 64
<6>uhci_hcd 0000:00:1d.1: UHCI Host Controller
<6>uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 6
<6>uhci_hcd 0000:00:1d.1: irq 19, io base 0x00005060
<6>usb usb6: configuration #1 chosen from 1 choice
<6>hub 6-0:1.0: USB hub found
<6>hub 6-0:1.0: 2 ports detected
<6>usb 4-6: configuration #1 chosen from 1 choice
<6>usb 4-6: New USB device found, idVendor=0bda, idProduct=8198
<6>usb 4-6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
<6>usb 4-6: Product: RTL8187B_WLAN_Adapter 
<6>usb 4-6: Manufacturer: Manufacturer_Realtek
<6>usb 4-6: SerialNumber: 00e04c000001
<6>usb usb6: New USB device found, idVendor=1d6b, idProduct=0001
<6>usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb6: Product: UHCI Host Controller
<6>usb usb6: Manufacturer: Linux 2.6.27.2-16-default uhci_hcd
<6>usb usb6: SerialNumber: 0000:00:1d.1
<6>uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
<7>uhci_hcd 0000:00:1d.2: setting latency timer to 64
<6>uhci_hcd 0000:00:1d.2: UHCI Host Controller
<6>uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 7
<6>uhci_hcd 0000:00:1d.2: irq 18, io base 0x00005040
<6>usb usb7: configuration #1 chosen from 1 choice
<6>hub 7-0:1.0: USB hub found
<6>hub 7-0:1.0: 2 ports detected
<6>usb 5-1: new low speed USB device using uhci_hcd and address 2
<6>usb 5-1: configuration #1 chosen from 1 choice
<6>usb 5-1: New USB device found, idVendor=04f3, idProduct=0210
<6>usb 5-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0
<6>usb 5-1: Product: PS/2+USB Mouse
<6>usb usb7: New USB device found, idVendor=1d6b, idProduct=0001
<6>usb usb7: New USB device strings: Mfr=3, Product=2, SerialNumber=1
<6>usb usb7: Product: UHCI Host Controller
<6>usb usb7: Manufacturer: Linux 2.6.27.2-16-default uhci_hcd
<6>usb usb7: SerialNumber: 0000:00:1d.2
<6>usbcore: registered new interface driver hiddev
<6>input: PS/2+USB Mouse as /devices/pci0000:00/0000:00:1d.0/usb5/5-1/5-1:1.0/input/input2
<6>input,hidraw0: USB HID v1.11 Mouse [PS/2+USB Mouse] on usb-0000:00:1d.0-1
<6>usbcore: registered new interface driver usbhid
<6>usbhid: v2.6:USB HID core driver
<5>REISERFS (device sda3): found reiserfs format "3.6" with standard journal
<5>REISERFS (device sda3): using ordered data mode
<5>REISERFS (device sda3): journal params: device sda3, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
<5>REISERFS (device sda3): checking transaction log (sda3)
<5>REISERFS (device sda3): Using r5 hash to sort names
<5>REISERFS (device sda3): Removing [402964 155500 0x0 SD]..done
<5>REISERFS (device sda3): Removing [402964 154304 0x0 SD]..done
<5>REISERFS (device sda3): Removing [337520 106673 0x0 SD]..done
<5>REISERFS (device sda3): Removing [402964 99535 0x0 SD]..done
<5>REISERFS (device sda3): Removing [402964 99494 0x0 SD]..done
<5>REISERFS (device sda3): Removing [337520 89457 0x0 SD]..done
<5>REISERFS (device sda3): Removing [68141 67953 0x0 SD]..done
<5>REISERFS (device sda3): Removing [337520 67926 0x0 SD]..done
<5>REISERFS (device sda3): Removing [337520 44834 0x0 SD]..done
<5>REISERFS (device sda3): There were 9 uncompleted unlinks/truncates. Completed
<6>udevd version 128 started
<5>sd 0:0:0:0: Attached scsi generic sg0 type 0
<5>scsi 3:0:0:0: Attached scsi generic sg1 type 5
<6>iTCO_vendor_support: vendor-support=0
<6>iTCO_wdt: Intel TCO WatchDog Timer Driver v1.03 (30-Apr-2008)
<6>iTCO_wdt: Found a ICH8M TCO device (Version=2, TCOBASE=0x0460)
<6>iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
<6>input: PC Speaker as /devices/platform/pcspkr/input/input3
<4>sr0: scsi3-mmc drive: 24x/24x writer dvd-ram cd/rw xa/form2 cdda tray
<6>Uniform CD-ROM driver Revision: 3.20
<7>sr 3:0:0:0: Attached scsi CD-ROM sr0
<6>ACPI: AC Adapter [ADP0] (on-line)
<6>input: Power Button (FF) as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4
<6>ACPI: Power Button (FF) [PWRF]
<6>input: Power Button (CM) as /devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input5
<6>ACPI: Power Button (CM) [PWRB]
<6>input: Lid Switch as /devices/LNXSYSTM:00/device:00/PNP0C0D:00/input/input6
<6>ACPI: Lid Switch [LID]
<6>ACPI: Battery Slot [BAT0] (battery absent)
<6>rtc_cmos 00:03: rtc core: registered rtc_cmos as rtc0
<6>rtc0: alarms up to one month, hpet irqs
<6>r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
<6>vendor=8086 device=283f
<6>r8169 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
<7>r8169 0000:02:00.0: setting latency timer to 64
<6>r8169 0000:02:00.0: unknown MAC (37a00000)
<6>eth0: RTL8169 at 0xf90b8000, 00:1e:33:43:7d:fa, XID 34a00000 IRQ 220
<6>i801_smbus 0000:00:1f.3: PCI INT C -> GSI 19 (level, low) -> IRQ 19
<6>Linux video capture interface: v2.00
<6>Linux agpgart interface v0.103
<6>HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
<7>HDA Intel 0000:00:1b.0: setting latency timer to 64
<6>ALSA sound/pci/hda/hda_codec.c:2325: hda_codec: model 'toshiba' is selected
<6>agpgart-intel 0000:00:00.0: Intel 965GM Chipset
<6>agpgart-intel 0000:00:00.0: detected 7676K stolen memory
<6>agpgart-intel 0000:00:00.0: AGP aperture is 256M @ 0x40000000
<6>uvcvideo: Found UVC 1.00 device CNF7051 (04f2:b070)
<6>input: CNF7051 as /devices/pci0000:00/0000:00:1a.7/usb1/1-2/1-2:1.0/input/input7
<6>usbcore: registered new interface driver uvcvideo
<6>USB Video Class driver (v0.1.0)
<4>rtl8187: 8187B chip detected. Support is EXPERIMENTAL, and could damage your
<4>         hardware, use at your own risk
<7>phy0: Selected rate control algorithm 'pid'
<6>phy0: hwaddr 00:1b:9e:fc:23:bc, RTL8187BvE V0 + rtl8225z2
<6>usbcore: registered new interface driver rtl8187
<6>wlan0 renamed to wlan1
<6>udev: renamed network interface wlan0 to wlan1
<3>Unable to find swap-space signature
<6>device-mapper: uevent: version 1.0.3
<6>device-mapper: ioctl: 4.14.0-ioctl (2008-04-23) initialised: dm-devel@redhat.com
<6>loop: module loaded
Kernel logging (ksyslog) stopped.
Kernel log daemon terminating.

Boot logging started on /dev/tty1(/dev/console (deleted)) at Mon Oct 20 12:49:10 2008

done
Starting udevd: done
Loading drivers, configuring devices: done
Loading required kernel modules
doneActivating swap-devices in /etc/fstab...
failedmount: according to mtab, /dev/sda3 is already mounted on /

udevadm[1305]: the program '/bin/bash' called '/sbin/udevsettle', it should use 'udevadm settle <options>', this will stop working in a future release


Activating device mapper...
done
Starting MD Raid the program '/bin/bash' called '/sbin/udevsettle', it should use 'udevadm settle <options>', this will stop working in a future release
unused
Waiting for udev to settle...
Scanning for LVM volume groups...
  Reading all physical volumes.  This may take a while...
Activating LVM volume groups...
done
Checking file systems...
fsck 1.40.2 (12-Jul-2007)
/dev/sda2 was not cleanly unmounted, check forced.
^A/dev/sda2: |====                                                    |  7.8%   ^B^A/dev/sda2: |==============================                          / 54.4%   ^B^A/dev/sda2: |========================================================| 100.0%   ^B^A                                                                               ^B/dev/sda2: 51/18144 files (9.8% non-contiguous), 25720/72292 blocks
donedone
Mounting local file systems...
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
debugfs on /sys/kernel/debug type debugfs (rw)
udev on /dev type tmpfs (rw)
devpts on /dev/pts type devpts (rw,mode=0620,gid=5)
/dev/sda2 on /boot type ext2 (rw,acl,user_xattr)
doneSetting up the hardware clockdone
<notice>killproc: kill(609,29)
Creating /var/log/boot.msg
doneSetting up hostname 'toshi-lashk'done
Setting up loopback interface     lo        
    lo        IP address: 127.0.0.1/8   
Checking for network time protocol daemon (NTPD): unused
Can't determine current runlevel
done
Setting up swapspace version 1, size = 2056282 kB
no label, UUID=41da6981-996b-4627-953d-12496fcbafa8
Activating remaining swap-devices in /etc/fstab...
doneConfiguring serial ports...
Configured serial ports
doneSetting current sysctl status from /etc/sysctl.conf
net.ipv4.icmp_echo_ignore_broadcasts = 1
net.ipv4.conf.all.rp_filter = 1
fs.inotify.max_user_watches = 65536
done
Enabling syn flood protectiondone
Enabling IP forwardingdone
done
System Boot Control: The system has been set up
Skipped features: boot.md boot.cycle
System Boot Control: Running /etc/init.d/boot.local
FATAL: Module ieee80211_crypt_rtl not found.
FATAL: Module ieee80211_crypt_wep_rtl not found.
FATAL: Module ieee80211_crypt_tkip_rtl not found.
FATAL: Module ieee80211_crypt_ccmp_rtl not found.
FATAL: Module ieee80211_rtl not found.
FATAL: Module r8187 not found.
failed<notice>killproc: kill(609,3)

INIT: 
Boot logging started on /dev/tty1(/dev/console) at Mon Oct 20 12:49:26 2008

Master Resource Control: previous runlevel: N, switching to runlevel: 5
Master Resource Control: Running /etc/init.d/before.local
doneEntering runlevel: 5


Starting D-Bus daemondone
<notice>startproc: execve (/sbin/resmgrd) [ /sbin/resmgrd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/resmgrd ]
<notice>startproc: execve (/sbin/acpid) [ /sbin/acpid ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/acpid ]
acpid: starting up


Starting acpid done
acpid: 2 rules loaded


Starting resource managerdone
<notice>startproc: execve (/usr/sbin/console-kit-daemon) [ /usr/sbin/console-kit-daemon ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/console-kit-daemon ]
<notice>startproc: execve (/sbin/syslog-ng) [ /sbin/syslog-ng -a /var/lib/dhcp/dev/log -a /var/lib/named/dev/log -a /var/lib/ntp/dev/log ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs TERM=linux SHELL=/bin/sh ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 SPLASHCFG= PWD=/ PREVLEVEL=N LINES=48 SHLVL=2 HOME=/ SPLASH=no splash=verbose ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/syslog-ng ]
Starting ConsoleKitdone
<notice>startproc: execve (/sbin/klogd) [ /sbin/klogd -c 1 -x -x ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs TERM=linux SHELL=/bin/sh ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 SPLASHCFG= PWD=/ PREVLEVEL=N LINES=48 SHLVL=2 HOME=/ SPLASH=no splash=verbose ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/klogd ]
Starting syslog servicesdone
Starting Firewall Initialization (phase 1 of 2) <notice>startproc: execve (/usr/sbin/hald) [ /usr/sbin/hald --daemon=yes ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/hald ]
Initializing random number generatordone
Starting HAL daemondone
Loading CPUFreq modules (CPUFreq not supported)
SuSEfirewall2: Warning: ip6tables does not support state matching. Extended IPv6 support disabled.
done
Starting service kdm<notice>startproc: execve (/opt/kde3/bin/kdm) [ /opt/kde3/bin/kdm ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs TERM=linux SHELL=/bin/sh ROOTFS_FSCK=0 QTDIR=/usr/lib/qt3 INIT_VERSION=sysvinit-2.86 KDEROOTHOME=/root/.kdm REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 SPLASHCFG= PWD=/ LANG=en_US.UTF-8 PREVLEVEL=N LINES=48 QT_SYSTEM_DIR=/usr/share/desktop-data SHLVL=2 HOME=/ XCURSOR_THEME=crystalwhite WINDOWMANAGER=/usr/bin/kde LC_CTYPE=en_US.UTF-8 SPLASH=no splash=verbose ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/opt/kde3/bin/kdm ]
done
<notice>startproc: execve (/usr/sbin/dhcdbd) [ /usr/sbin/dhcdbd --system ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 OLDPWD=/etc/sysconfig/network LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/sbin:/usr/sbin:/bin:/usr/bin:/etc/sysconfig/network/scripts vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/dhcdbd ]
<notice>startproc: execve (/usr/sbin/NetworkManagerDispatcher) [ /usr/sbin/NetworkManagerDispatcher ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 OLDPWD=/etc/sysconfig/network LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/sbin:/usr/sbin:/bin:/usr/bin:/etc/sysconfig/network/scripts vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/NetworkManagerDispatcher ]
<notice>startproc: execve (/usr/sbin/NetworkManager) [ /usr/sbin/NetworkManager ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 OLDPWD=/etc/sysconfig/network LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/sbin:/usr/sbin:/bin:/usr/bin:/etc/sysconfig/network/scripts vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/NetworkManager ]
Starting the DHCP DBUS Daemondone
Starting the NetworkManagerDispatcherdone
Starting the NetworkManagerdone
Mount CIFS File Systems unused
Loading keymap i386/qwerty/us.map.gz
doneLoading compose table latin1.adddone
Start Unicode mode
doneLoading console font lat9w-16.psfu  -m trivial G0:loadable
done<notice>checkproc: /opt/kde3/bin/kdm 1951
<notice>startproc: execve (/sbin/auditd) [ /sbin/auditd -s disable ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/auditd ]
Starting auditd done
<notice>startproc: execve (/usr/sbin/avahi-daemon) [ /usr/sbin/avahi-daemon -D ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/avahi-daemon ]
Starting Avahi daemon.done
<notice>startproc: execve (/usr/sbin/avahi-dnsconfd) [ /usr/sbin/avahi-dnsconfd -D ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/avahi-dnsconfd ]
Starting Avahi DNS Configuration daemondone
<notice>startproc: execve (/usr/sbin/cannaserver) [ /usr/sbin/cannaserver -u wnn -r /var/lib/canna ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/cannaserver ]
Starting Canna Kanji Serverdone
Starting hotkey-setup done
Starting irqbalance unused
<notice>checkproc: /opt/kde3/bin/kdm 1951
Try to get initial date and time via NTP from 0.pool.ntp.org 1.pool.ntp.org 2.pool.ntp.orgStarting smart card terminalsdone
<notice>startproc: execve (/usr/sbin/pcscd) [ /usr/sbin/pcscd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/pcscd ]
Starting PC/SC smart card daemon done
<notice>startproc: execve (/sbin/portmap) [ /sbin/portmap ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/sbin/portmap ]
Starting RPC portmap daemondone
<notice>startproc: execve (/usr/sbin/powersaved) [ /usr/sbin/powersaved -d -f /var/run/acpid.socket -v 3 ], [ HOME=/ PATH=/bin:/sbin:/usr/bin:/usr/sbin SHELL=/bin/sh RUNLEVEL=5 PREVLEVEL=N DAEMON=/usr/sbin/powersaved ]
Starting powersaved: done
<notice>startproc: execve (/usr/sbin/automount) [ /usr/sbin/automount ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/sbin:/usr/sbin:/bin:/usr/bin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/automount ]
Starting automount done
<notice>startproc: execve (/usr/sbin/smpppd) [ /usr/sbin/smpppd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/smpppd ]
<notice>startproc: execve (/usr/sbin/cupsd) [ /usr/sbin/cupsd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/cupsd ]
Starting SMPPPDdone
Starting cupsddone
<notice>startproc: execve (/usr/sbin/sshd) [ /usr/sbin/sshd -o PidFile=/var/run/sshd.init.pid ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/sshd ]
<notice>startproc: execve (/usr/sbin/xinetd) [ /usr/sbin/xinetd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/xinetd ]
Starting SSH daemondone
Starting INET services. (xinetd)done
Error : Temporary failure in name resolution
Error : Temporary failure in name resolution
Error : Temporary failure in name resolution
failed
Starting network time protocol daemon (NTPD)<notice>startproc: execve (/usr/sbin/ntpd) [ /usr/sbin/ntpd -p /var/run/ntp/ntpd.pid -u ntp -i /var/lib/ntp ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/ntpd ]
done
<notice>startproc: execve (/usr/sbin/atd) [ /usr/sbin/atd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/atd ]
Starting service at daemondone
<notice>startproc: execve (/usr/sbin/famd) [ /usr/sbin/famd -t 4 -T 0 -L ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/famd ]
Starting File Access Monitoring Daemondone
<notice>startproc: execve (/usr/sbin/nscd) [ /usr/sbin/nscd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/nscd ]
Starting Name Service Cache Daemondone
Starting mail service (Postfix)done
<notice>startproc: execve (/usr/sbin/cron) [ /usr/sbin/cron ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/cron ]
Starting CRON daemondone
Starting smartd <notice>startproc: execve (/usr/sbin/smartd) [ /usr/sbin/smartd ], [ CONSOLE=/dev/console ROOTFS_FSTYPE=reiserfs SHELL=/bin/sh TERM=linux ROOTFS_FSCK=0 LC_ALL=POSIX INIT_VERSION=sysvinit-2.86 REDIRECT=/dev/tty1 COLUMNS=128 PATH=/bin:/sbin:/usr/bin:/usr/sbin vga=791 RUNLEVEL=5 PWD=/ SPLASHCFG= PREVLEVEL=N LINES=48 HOME=/ SHLVL=2 splash=verbose SPLASH=no ROOTFS_BLKDEV=/dev/sda3 _=/sbin/startproc DAEMON=/usr/sbin/smartd ]
done
Starting Firewall Initialization (phase 2 of 2) SuSEfirewall2: Warning: no default firewall zone defined, assuming 'ext'
done
done
Master Resource Control: runlevel 5 has been reached
Skipped services in runlevel 5: smbfs irq_balancer
<notice>killproc: kill(1616,3)
------------ End of the file -------------------
Comment 1 Rafael J. Wysocki 2008-10-20 04:27:17 UTC
OK

Any chance to try a kernel.org kernel earlier that 2.6.27?

What happens if you do 'echo disk > /sys/power/state' (as root) under 2.6.27-2 (it should hibernate, so are you able to resume)?

Also, in future please don't paste logs, they are completely unreadable in this form.  Please add them as attachments instead.
Comment 2 Michael Lashkevich 2008-10-20 05:21:00 UTC
May I try any binaries of earlier versions from the SuSE repositories?

The result of 'echo disk >/sys/power/state' is the same. The screen blackens, the computer powers off after some delay, then when I power it on it boots normally (with some replaying the filesystem journal).
Comment 3 Michael Lashkevich 2008-10-20 05:22:54 UTC
Created attachment 18375 [details]
/var/log/pm-suspend.log after failed resume
Comment 4 Michael Lashkevich 2008-10-20 05:23:34 UTC
Created attachment 18376 [details]
boot.msg after booting instead of resuming
Comment 5 Michael Lashkevich 2008-10-20 13:40:42 UTC
I tried the binaries "kernel-default-2.6.25.4-60.1.i586.rpm" from the repositary "http://download.opensuse.org/repositories/home:/hmacht/openSUSE_10.3/". The same problem.
Comment 6 Hin-Tak Leung 2008-10-21 22:37:51 UTC
What's your swap configuration, and did you have large-memory processes running prior to hiberation (e.g. a few hundred browser tabs)? If the sum total of your swap is not sufficient to save the total of your current processes, then hibernation does not work, and that's what you see.

i.e. in the "reboot", the last kernel is supposed to read saved memory-dump from
swap, and if swap was not configured properly or too small, then the saved memory-dump is not complete and the kernel proceeds to boot normal.
Comment 7 Michael Lashkevich 2008-10-22 00:48:16 UTC
First of all, hibernation works properly with 2.6.22 for much larger memory usage than that I tested with 2.6.27, 2.6.25 for. Namely, I tested it with one kde session, one xterm (with mc) and one thunderbird. Nothing more.

For example, just now I have one kde-session, three xterm's, one thunderbird and one firefox. It takes 256788k + 40528k buffers + 230648 cache + 16k swap according to output of "free".

My RAM is 1026217k total, my swap space (/dev/sda1) is 2008084k total, my usual memory image size calculated by the s2disk utility and saved to /var/lib/s2disk.conf is about 500M.
Comment 8 Rafael J. Wysocki 2008-10-22 14:10:41 UTC
What's the result of 'cat /sys/power/disk' on your box?
Comment 9 Michael Lashkevich 2008-10-22 14:32:11 UTC
lashkevi@toshi-lashk:~> cat /sys/power/disk
[platform] test testproc shutdown reboot 
Comment 10 Hin-Tak Leung 2008-10-22 14:39:06 UTC
You have an fsck on boot, which means your system did not go into hibernation
properly. 

You need to find the bits of the log just *before* hibernation, rather than after waking up. (e.g. a driver might have refused to go into sleep, etc).
Comment 11 Rafael J. Wysocki 2008-10-22 14:46:13 UTC
Michael, please check if the system resumes correctly after

# echo shutdown > /sys/power/disk
# echo disk > /sys/power/state

If not, please send the output of 'cat /proc/cmdline' and 'cat /proc/swaps'.

It is possible that the kernel can't find the image during the resume for some reason.
Comment 12 Michael Lashkevich 2008-10-22 15:17:54 UTC
(In reply to comment #11)
> If not, please send the output of 'cat /proc/cmdline' and 'cat /proc/swaps'.
toshi-lashk:~ # cat /proc/cmdline
root=/dev/sda3 vga=791 resume=/dev/sda1 splash=verbose acpi_osi=!Linux  showopts
toshi-lashk:~ # cat /proc/swaps
Filename                                Type            Size    Used    Priority
/dev/sda1                               partition       2008084 0       42

You see, the 'resume=' parameter points to the correct swap partition.

A comment: The parameter 'acpi_osi=!Linux' is added since the FN/Fx keys do not work at all without it.
Comment 13 Michael Lashkevich 2008-10-22 15:23:40 UTC
(In reply to comment #11)
> Michael, please check if the system resumes correctly after
> 
> # echo shutdown > /sys/power/disk
> # echo disk > /sys/power/state
Sorry, I forgot to say: the system does NOT resume correctly with these commands.
Comment 14 Rafael J. Wysocki 2008-10-22 15:30:32 UTC
Can you please attach dmesg output from right after a failing resume?
Comment 15 Michael Lashkevich 2008-10-22 22:31:50 UTC
Created attachment 18408 [details]
dmesg output just after failed resume
Comment 16 Michael Lashkevich 2008-10-22 22:46:54 UTC
Created attachment 18409 [details]
the "/var/log/pm-suspend.log" file after a suspend INTERRUPTED by pressing the backspace key

(In reply to comment #10)
> You have an fsck on boot, which means your system did not go into hibernation
> properly. 
> 
> You need to find the bits of the log just *before* hibernation, rather than
> after waking up. (e.g. a driver might have refused to go into sleep, etc).
To satisfy your request I attach the "/var/log/pm-suspend.log" file after an attempted to suspend interrupted by backspace to resume without complete creating the image. But I am afraid it sais nothing new...
Comment 17 Rafael J. Wysocki 2008-10-22 23:02:36 UTC
(In reply to comment #15)
> Created an attachment (id=18408) [details]
> dmesg output just after failed resume

The image seems to be there, but also it seems to have been damaged.

Is the sequence of events such that after hibernating the box is powered off and then you power it on and it reboots while trying to resume, or does it boot "normally" instead of resuming?
Comment 18 Rafael J. Wysocki 2008-10-22 23:11:02 UTC
Can you also attach dmesg from after a clean boot, please?
Comment 19 Michael Lashkevich 2008-10-23 00:13:35 UTC
Created attachment 18410 [details]
Output of "dmesg" after a clean boot

(In reply to comment #17)
> Is the sequence of events such that after hibernating the box is powered off
> and then you power it on and it reboots while trying to resume, or does it
> boot
> "normally" instead of resuming?
> 
It just boots normally. I mean, thire is no reboot after starting grub. It starts like it usually does while resuming (without the start menu) but proceeds with a normal boot.
Comment 20 Hin-Tak Leung 2008-10-23 02:37:02 UTC
(In reply to comment #16)
> To satisfy your request I attach the "/var/log/pm-suspend.log" file after an
> attempted to suspend interrupted by backspace to resume without complete
> creating the image. But I am afraid it sais nothing new...

Wrong log, and wrong way to do it. I wrote the log just before a failed resume, and I meant it - not an "interrupted suspend", and wrong file. I meant *the log*, i.e. /var/log/messages, the hundred lines just before the new 
<date> <hostname> kernel: Linux version 2.6.xxx... gcc..
<date> <hostname> kernel: Command line: ro root=...
Comment 21 Michael Lashkevich 2008-10-23 05:37:49 UTC
(In reply to comment #20)
> and I meant it - not an "interrupted suspend", and wrong file. I meant *the
> log*, i.e. /var/log/messages, the hundred lines just before the new 
> <date> <hostname> kernel: Linux version 2.6.xxx... gcc..
> <date> <hostname> kernel: Command line: ro root=...
Ok, but how to save the "/var/log/messages" file after hibernation but before powering off? I tried to hibernate in the "reboot" mode and then save the file from the rescue disc mounting the filesystem in the readonly mode, but it did not help. The last line was earlier than the actual hibernation process. Probably, the system checked and repaired the filesystem silently while mounting the filesystem.
Comment 22 Hin-Tak Leung 2008-10-23 06:51:26 UTC
Hmm, your problem is clearly not about resume, but that your system did not hibernate properly (so there is no good state to resume from). Basically your system crashed while trying to hibernate, I think, so you just get a normal boot/repair after crash.

I think a serial console and a 2nd machine (and the know-how to use a serial console) is needed to debug this sort of problem.
Comment 23 Rafael J. Wysocki 2008-10-23 15:29:10 UTC
Michael, I also think that the system crashes while saving the hibernation image and this kind of failure is unfortunately very difficult to debug.

Frankly, the only practical method I can suggest you at the moment is to carry out git bisection and see which commit broke things for you.
Comment 24 Michael Lashkevich 2008-10-24 03:44:57 UTC
Rafael, please, explain, what is "git bisection" and give me practical instructions how to do it.
Comment 25 Rafael J. Wysocki 2008-10-24 04:38:09 UTC
Well, that unfortunately requires you to compile the kernel from sources and install it (multiple times).  On openSUSE it's not very difficult, though.

Have you ever done it?
Comment 26 Michael Lashkevich 2008-10-24 04:50:12 UTC
Once, long ago. Recently, I only compiled modules. I think I'll manage it.
Comment 27 Rafael J. Wysocki 2008-10-26 15:56:23 UTC
Created attachment 18454 [details]
Kernel compilation and git bisection instructions

Please follow the instructions in this attachment.  If you have any problems, please ask.
Comment 28 Michael Lashkevich 2008-10-27 14:18:44 UTC
I tried to make the git bisection but encountered a problem even at its first step. To be sure I began with trying 2.6.28-rc2 generated initially from the git tree, but the resume problem remains for this version.

Then I tried a bisection between versions 2.6.22 (definitely good) and 2.6.25 (already bad), which was proposed to be 2.6.24-rc2-default, but it has a problem with modprobe as early as at the boot process. Suspend to disk fails and resumes at some early stage without creating image (ERR=255). Even when I halt the system normally it fails to unmount correctly my root filesystem.

Probably, I used a wrong .config file (I took it from my old 2.6.22. I also tried that from 2.6.27 but with this last the kernel ide modules were not generated at all so it could not correctly make initrd.)
Comment 29 Rafael J. Wysocki 2008-10-27 14:34:32 UTC
That isn't good at all.

Do you normally use IDE drivers or libata/PATA drivers?
Comment 30 Michael Lashkevich 2008-10-27 14:46:29 UTC
Created attachment 18476 [details]
lsmod output for 2.6.22

Yes, the kernel uses them (ide_core, piix, ata_piix, libata, ahci). See this attachment for 2.6.22. For 2.6.27 see the pm-suspend.log attached earlier.
Comment 31 Rafael J. Wysocki 2008-10-27 14:59:39 UTC
The IDE driver seems to be not used, though.

Anyway, please run 'git bisect reset' in your repository directory, run 'git pull' from there to update the kernel source to the latest version (that will be 2.6.28-rc2-something), run 'make xconfig' and set CONFIG_PM_DEBUG.  Compile and install the kernel and run:

# echo core > /sys/power/pm_test
# echo disk > /sys/power/state

(that will test the hibernation code without creating the image) and see if the system remains stable after that.
Comment 32 Michael Lashkevich 2008-10-28 00:34:11 UTC
Created attachment 18478 [details]
Dmesg output after 'echo core >/sys/power/pm_test; echo disk >/sys/power/state'

This is the dmesg output after

# modprobe -r rtl8187
# echo core > /sys/power/pm_test
# echo disk > /sys/power/state

(The fist line is necessary since the computer freezes while suspending with this module.)
Comment 33 Michael Lashkevich 2008-10-28 01:13:49 UTC
I tried to hibernate the computer with 'echo 1 >/sys/power/pm_trace'. After booting, I got the following dmesg lines:

  Magic number: 0:77:376
  hash matches drivers/base/power/main.c:390
Comment 34 Hin-Tak Leung 2008-10-28 10:09:29 UTC
I wonder why you need to modprobe -r rtl8187 - the driver emits a warning on suspend/hibernate: "rtl8187 1-6:1.0: no suspend for driver rtl8187?", but
the kernel unloads the whole of the usb stack on suspend/hibernate so the warning is just a warning.
Comment 35 Michael Lashkevich 2008-10-28 12:01:25 UTC
(In reply to comment #34)
Because with this driver loaded the computer freezes forever at some early stage of hibernation(freezing tasks, I believe). This is an experimental fact.
Comment 36 Rafael J. Wysocki 2008-10-28 14:31:34 UTC
First, I'm changing the severity of this bug to "normal", as it seems to be related to your hardware in a non-trivial way.

Second, your dmesg attached to comment #32 (btw, please set the 'plain text' type for your text attachments, that makes browsing them _much_ easier) looks pretty normal.  Did the system work correctly after that?

Finally, please file a separate bug for the rtl8187 issue.
Comment 37 Michael Lashkevich 2008-10-28 15:02:08 UTC
The system worked correctly after 'echo core...'.

When the kernel fails to resume there is a message in the boot.msg:

<3>Unable to find swap-space signature

Is it relevant to the problem?
Comment 38 Rafael J. Wysocki 2008-10-28 15:08:39 UTC
Yes, it is.  This means that the hibernation code managed to change the swap signature of your resume device.

BTW, are there any swap devices right after a failing resume in /proc/swaps?
Comment 39 Michael Lashkevich 2008-10-28 15:16:30 UTC
Yes, swapon succeeds after that.
Comment 40 Hin-Tak Leung 2008-10-28 15:23:57 UTC
If you do file a bug against rtl8187 hibernation, please add me to the CC: (I was
one of the people who made rtl8187B support possible - i.e. the bulk of the wireless driver code you are using).
Comment 41 Rafael J. Wysocki 2008-10-28 15:28:03 UTC
(In reply to comment #39)
> Yes, swapon succeeds after that.

Can you please try to run 'mkswap' on your swap space and retest hibernation with 'echo disk > /sys/power/state'?
Comment 42 Michael Lashkevich 2008-10-28 16:01:00 UTC
(In reply to comment #40)
> If you do file a bug against rtl8187 hibernation, please add me to the CC: (I
> was
> one of the people who made rtl8187B support possible - i.e. the bulk of the
> wireless driver code you are using).
Ok. I'll do it.
Comment 43 Michael Lashkevich 2008-10-28 16:10:20 UTC
(In reply to comment #41)
> Can you please try to run 'mkswap' on your swap space and retest hibernation
> with 'echo disk > /sys/power/state'?
> 
It does not help.

Moreover, today I failed to resume with 2.6.22. I thought that it was something wrong with the installation of the kernel after so many fsck's, and updated by the use of OpenSUSE update utility from 2.6.22.18 to 2.6.22.19 (and rebooted after that), but it did not help. Maybe something wrong with the disk? Maybe better to make full fsck from the rescue disk?
Comment 44 Rafael J. Wysocki 2008-10-28 16:45:38 UTC
If you have a spare disk, you can try to set up a swap partition in there and try to hibernate.

Alternatively, you can try to use a swap file for hibernation.

If this is a disk problem, fsck won't help fix it (swap partitions don't contain filesystems anyway, so fsck doesn't work on them).
Comment 45 Hin-Tak Leung 2008-10-28 18:53:48 UTC
Hmm, I normally do suspend, so I just put my toshiba laptop  into hibernate and it resumes alright as it should. It is a satellite A210, not the same model - I know for a fact that the rtl8187 driver code path on this and yours is identical. This is with fedora 9 2.6.26.7-86.fc9.x86_64 .

How are you configuring your networking? NetworkManager should automatically disconnect on hibernate and ifconfig down the device, then the kernel unloads the whole USB core stack plus drivers, there shouldn't need to be a manual "modprobe -r".
Comment 46 Michael Lashkevich 2008-10-29 05:42:27 UTC
(In reply to comment #45)
> Hmm, I normally do suspend, so I just put my toshiba laptop  into hibernate
> and
> it resumes alright as it should. It is a satellite A210, not the same model -
> I
> know for a fact that the rtl8187 driver code path on this and yours is
> identical. This is with fedora 9 2.6.26.7-86.fc9.x86_64 .
> 
> How are you configuring your networking? NetworkManager should automatically
> disconnect on hibernate and ifconfig down the device, then the kernel unloads
> the whole USB core stack plus drivers, there shouldn't need to be a manual
> "modprobe -r".
> 
Yes, I use NetwrokManager. Maybe that is because of the non-standard identifier of this card (0bda:8198) on Toshiba Satellite L300? For former releases and drivers I needed to add this idenitifier manually into the source code.
Comment 47 Michael Lashkevich 2008-10-29 05:46:56 UTC
(In reply to comment #44)
> If you have a spare disk, you can try to set up a swap partition in there and
> try to hibernate.
> 
> Alternatively, you can try to use a swap file for hibernation.
> 
> If this is a disk problem, fsck won't help fix it (swap partitions don't
> contain filesystems anyway, so fsck doesn't work on them).
> 
I remade the swap partition with the flag '-c', which forces to check the space for bad blocks. No bad blocks found. The use of a swap file does not help either.
Comment 48 Rafael J. Wysocki 2008-10-29 13:29:54 UTC
Can you compile the current mainline kernel from sources with CONFIG_PM_DEBUG enabled and install it?
Comment 49 Michael Lashkevich 2008-10-29 15:03:28 UTC
(In reply to comment #48)
> Can you compile the current mainline kernel from sources with CONFIG_PM_DEBUG
> enabled and install it?
> 
Done.
Comment 50 Rafael J. Wysocki 2008-10-29 15:16:01 UTC
Please attach dmesg from this kernel taken right after a failing resume (as a text attachment).
Comment 51 Michael Lashkevich 2008-10-29 15:32:18 UTC
Created attachment 18502 [details]
dmesg output just after failed resume (2.6.28-rc2-17-default, CONFIG_PM_DEBUG=y)

Here you are.
Comment 52 Rafael J. Wysocki 2008-10-29 15:44:16 UTC
Unfortunately, the log doesn't reveal _anything_.

I'm getting a bit frustrated with that.  Is there a possibility to set up a serial console on this box?
Comment 53 Hin-Tak Leung 2008-10-29 15:54:40 UTC
Yes, since the problem I believe is about crash during hibernation (not resume), log after resume does not help; unless you can somehow override the disk-recovery/fsck right after the crash, *before* the resume. Actually I wonder if mounting the disk by a 2nd machine read-only will work. (read-write certainly won't, since the first thing is "recover-journal" or "fsck"). 

Oh, there is one other option - configure syslog to send the log over the network to a 2nd machine (in addition to logging locally). But one only gets logs as far as the networking facility is up, so one probably does get very close to the moment of crash.

Honestly, I think the most informative/useful route is debugging with a serial console - this would get at the logs as close to the moment of crash as possible. 
Comment 54 Michael Lashkevich 2008-10-29 16:06:39 UTC
What means a serial console?

I could try again to boot my computer from a rescue disc just after suspend and mount the filesystems readonly. To do it, maybe it is better first to redirect syslog to the ext2 boot partition instead of /var/log on the reiserfs root partition?
Comment 55 Rafael J. Wysocki 2008-10-29 16:12:58 UTC
Serial console is a second machine with 'minicom' or equivalent program attached to your box with a serial null-modem cable and capable of reading the kernel messages on the fly.

Another possibility to debug it a bit further would be to use the latest version of user space hibernation utilities (the CVS version from suspend.sf.net) and enable the image verification option.  That might give us access to kernel logs generated during failing hibernation.
Comment 56 Michael Lashkevich 2008-10-30 06:12:19 UTC
(In reply to comment #55)
> Serial console is a second machine with 'minicom' or equivalent program
> attached to your box with a serial null-modem cable and capable of reading
> the
> kernel messages on the fly.
>
My notebook has no serial port, only USB ones.

> Another possibility to debug it a bit further would be to use the latest
> version of user space hibernation utilities (the CVS version from
> suspend.sf.net) and enable the image verification option.  That might give us
> access to kernel logs generated during failing hibernation.
> 
I installed it and suspended with 'debug verify image = y'. It successfully verified the image, but again failed to resume. Then I found no new log messages.
Comment 57 Michael Lashkevich 2008-11-01 02:13:21 UTC
Created attachment 18564 [details]
A comment of Alexander Prokofiev, the sysadmin of Landau Institute

I consulted the system administrator at my work, Alexander Prokofiev, on this problem, and he is wonders why dmesg after failed resume does not contain any lines about attempt to resume and the reason of failure. I attach here his comment translated into English.
Comment 58 Rafael J. Wysocki 2008-11-01 14:26:52 UTC
Actually, the advice to replace pr_debug with printk in this fragment of code is a good one.

You can also compile the kernel (2.6.28-rc2 or newer) with CONFIG_DYNAMIC_PRINTK_DEBUG set and add 'dynamic_printk' to the kernel command line.

There is a change in 2.6.28-rc that makes pr_debug messages only be printed if there's 'dynamic_printk' in the kernel command line (however, it makes _all_ of the pr_debug messages appear in the log, which may not be what you want).
Comment 59 Michael Lashkevich 2008-11-01 16:08:22 UTC
Created attachment 18588 [details]
Output of "dmesg |grep 'PM:'" after failed resume

(In reply to comment #58)
The parameter CONFIG_DYNAMIC_PRINTK_DEBUG does not seem to work even together with the kernel command line parameter 'dynamic_printk'. That is why I replaced all the functions pr_debug(...) to printk(...) in all files in the files in the directory "kernel/power". This gave several additional log messages (see the attachment), which are the same for both clear boot and boot after failed resume.

Is it possible include some other printk lines to debug it further?
Comment 60 Rafael J. Wysocki 2008-11-02 04:02:37 UTC
Well, I'll have to see why the debug messages are busted.

The information you obtained is really useful, because:

PM: Resume from partition /dev/sda1
PM: Checking hibernation image.
PM: Error -6 checking image file

means "No such device or address", so it looks like your resume kernel can't handle the resume device.  It can be a missing driver or something wrong with the initrd image.
Comment 61 Michael Lashkevich 2008-11-02 15:06:45 UTC
Created attachment 18598 [details]
Output of mkinitrd

Here is the output of the mkinitrd command. What could be wrong with it? It seems to contain all necessary drivers.

By the way, it seems from dmesg that the ahci and libata modules are loaded _after_ the attempt of resume. Is it a correct behaviour?
Comment 62 Rafael J. Wysocki 2008-11-02 15:55:42 UTC
(In reply to comment #61)
> Created an attachment (id=18598) [details]
> Output of mkinitrd
> 
> Here is the output of the mkinitrd command. What could be wrong with it? It
> seems to contain all necessary drivers.

Yes, it appears so.

> By the way, it seems from dmesg that the ahci and libata modules are loaded
> _after_ the attempt of resume. Is it a correct behaviour?

No, it isn't if you try to resume after hibernating with 'echo disk > /sys/power/state'.  Please try to compile these drivers directly into the kernel and retest.
Comment 63 Michael Lashkevich 2008-11-03 04:06:59 UTC
The same error -6 when I try to suspend and resume for the kernel compiled with

CONFIG_PM_STD_PARTITION="/dev/sda1"
CONFIG_SCSI=y
CONFIG_ATA=y
CONFIG_SATA_AHCI=y
CONFIG_ATA_GENERIC=y
Comment 64 Rafael J. Wysocki 2008-11-03 05:23:57 UTC
Well, this probably means that /dev/sda1 is not present in your initrd image, so the kernel cannot find the device.  I don't know why this happens, though.
Comment 65 Michael Lashkevich 2008-11-03 05:38:03 UTC
# mkinitrd -k vmlinuz-2.6.28-rc2-17-default -i initrd-2.6.28-rc2-17-default

Kernel image:   /boot/vmlinuz-2.6.28-rc2-17-default
Initrd image:   /boot/initrd-2.6.28-rc2-17-default
Root device:    /dev/sda3 (mounted on / as reiserfs)
Resume device:  /dev/sda1
Kernel Modules: ata_piix hwmon thermal_sys processor thermal fan reiserfs edd ide-core piix crc-t10dif sd_mod usbcore ohci-hcd uhci-hcd ehci-hcd hid usbhid 
Features:       block usb
17685 blocks
Comment 66 Michael Lashkevich 2008-11-03 06:33:43 UTC
Rafael, the problem is indeed in the initrd file!

When I upgraded to 2.6.27 from the SuSE repositories, I needed to upgrade mkinitrd from 2.1 to 2.4 due to failed dependencies. Now, since I use a compiled kernel, I falled back to mkinitrd-2.1 and rebuilt the initrd files. And now HIBERNATION AND RESUME WORKS!

The problem with 2.6.22 that occured while debugging was because I occasionally rebuilt it initrd with mkinitrd 2.4.

Hence, I must address the problem to the SuSE team rather than to the kernel team. Sorry for taking so much of your time and thank you for help.

Best regards,

Michael
Comment 67 Rafael J. Wysocki 2008-11-03 12:33:42 UTC
I'm glad you found the source of the trouble. :-)