After suspend/resume, screen not switched on, which culprit?
I've had the following problem for several weeks (I don't know when
exactly) with my Debian/sid laptop (DELL Latitude E6400, NVIDIA NV98
chipset): I can suspend the machine with Fn-F1, but when I want to
resume, the screen remains off. The machine isn't frozen as there
are disk accesses and after a reboot, I can see log messages.
I initially thought that it was due to the kernel, but I have the
same problem with old kernels (which were fine). I now think it can
be due to xserver-xorg-video-nouveau (I haven't tried a downgrade
yet). I couldn't find any existing bug report about this problem yet.
Here how I can reproduce the problem:
1. Switch on the machine.
2. Suspend with Fn-F1 once the boot process is complete.
3. Resume by pressing the power button. But the screen remains off.
4. Press the power button again. This switches the screen on, but with
only the following message (not always present):
[ 127.629522] [drm] nouveau 0000:01:00.0: 0xD7E0: i2c wr fail: -6
I give syslog messages below. Any idea or suggestion?
Thanks in advance.
Jan 3 16:44:41 xvii kernel: [862557.266993] PM: Syncing filesystems ... done.
Jan 3 16:44:41 xvii kernel: [862557.332748] PM: Preparing system for mem sleep
Jan 3 18:46:42 xvii kernel: [862559.000566] detected fb_set_par error, error code: -16
Jan 3 18:46:42 xvii kernel: [862559.000648] Freezing user space processes ... (elapsed 0.03 seconds) done.
Jan 3 18:46:42 xvii kernel: [862559.032231] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Jan 3 18:46:42 xvii kernel: [862559.048266] PM: Entering mem sleep
Jan 3 18:46:42 xvii kernel: [862559.048280] Suspending console(s) (use no_console_suspend to debug)
Jan 3 18:46:42 xvii kernel: [862559.048725] sd 0:0:0:0: [sda] Synchronizing SCSI cache
Jan 3 18:46:42 xvii kernel: [862559.048893] sd 0:0:0:0: [sda] Stopping disk
Jan 3 18:46:42 xvii kernel: [862559.066165] serial 00:09: disabled
Jan 3 18:46:42 xvii kernel: [862559.067278] ACPI handle has no context!
Jan 3 18:46:42 xvii kernel: [862559.067286] sdhci-pci 0000:03:01.2: PCI INT C disabled
Jan 3 18:46:42 xvii kernel: [862559.067291] ACPI handle has no context!
Jan 3 18:46:42 xvii kernel: [862559.067374] [drm] nouveau 0000:01:00.0: Disabling fbcon acceleration...
Jan 3 18:46:42 xvii kernel: [862559.067376] [drm] nouveau 0000:01:00.0: Unpinning framebuffer(s)...
Jan 3 18:46:42 xvii kernel: [862559.067443] [drm] nouveau 0000:01:00.0: Evicting buffers...
Jan 3 18:46:42 xvii kernel: [862559.067524] ehci_hcd 0000:00:1d.7: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862559.067544] uhci_hcd 0000:00:1d.2: PCI INT C disabled
Jan 3 18:46:42 xvii kernel: [862559.067558] uhci_hcd 0000:00:1d.1: PCI INT B disabled
Jan 3 18:46:42 xvii kernel: [862559.067577] uhci_hcd 0000:00:1d.0: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862559.067710] ehci_hcd 0000:00:1a.7: PCI INT C disabled
Jan 3 18:46:42 xvii kernel: [862559.067729] uhci_hcd 0000:00:1a.2: PCI INT C disabled
Jan 3 18:46:42 xvii kernel: [862559.067753] uhci_hcd 0000:00:1a.1: PCI INT B disabled
Jan 3 18:46:42 xvii kernel: [862559.067772] uhci_hcd 0000:00:1a.0: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862559.072055] ACPI handle has no context!
Jan 3 18:46:42 xvii kernel: [862559.093162] [drm] nouveau 0000:01:00.0: Idling channels...
Jan 3 18:46:42 xvii kernel: [862559.093452] [drm] nouveau 0000:01:00.0: Suspending GPU objects...
Jan 3 18:46:42 xvii kernel: [862559.164960] e1000e 0000:00:19.0: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862559.164972] e1000e 0000:00:19.0: PME# enabled
Jan 3 18:46:42 xvii kernel: [862559.164982] pci0000:00: wake-up capability enabled by ACPI
Jan 3 18:46:42 xvii kernel: [862559.272171] snd_hda_intel 0000:00:1b.0: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862561.647386] [drm] nouveau 0000:01:00.0: And we're gone!
Jan 3 18:46:42 xvii kernel: [862561.647457] nouveau 0000:01:00.0: PCI INT A disabled
Jan 3 18:46:42 xvii kernel: [862561.660076] PM: suspend of devices complete after 2611.515 msecs
Jan 3 18:46:42 xvii kernel: [862561.708156] PM: late suspend of devices complete after 48.075 msecs
Jan 3 18:46:42 xvii kernel: [862561.708681] ACPI: Preparing to enter system sleep state S3
Jan 3 18:46:42 xvii kernel: [862561.728463] PM: Saving platform NVS memory
Jan 3 18:46:42 xvii kernel: [862561.728465] Disabling non-boot CPUs ...
Jan 3 18:46:42 xvii kernel: [862561.832038] CPU 1 is now offline
Jan 3 18:46:42 xvii kernel: [862561.832646] Extended CMOS year: 2000
Jan 3 18:46:42 xvii kernel: [862561.832646] ACPI: Low-level resume complete
Jan 3 18:46:42 xvii kernel: [862561.832646] PM: Restoring platform NVS memory
Jan 3 18:46:42 xvii rtkit-daemon[1864]: The canary thread is apparently starving. Taking action.
Jan 3 18:46:42 xvii rtkit-daemon[1864]: Demoting known real-time threads.
Jan 3 18:46:42 xvii rtkit-daemon[1864]: Successfully demoted thread 15453 of process 15451 (/usr/bin/pulseaudio).
Jan 3 18:46:42 xvii rtkit-daemon[1864]: Successfully demoted thread 15452 of process 15451 (/usr/bin/pulseaudio).
Jan 3 18:46:42 xvii rtkit-daemon[1864]: Successfully demoted thread 15451 of process 15451 (/usr/bin/pulseaudio).
Jan 3 18:46:42 xvii rtkit-daemon[1864]: Demoted 3 threads.
Jan 3 18:46:42 xvii acpid: input device has been disconnected, fd 4
Jan 3 18:46:42 xvii kernel: [862561.832646] Extended CMOS year: 2000
Jan 3 18:46:42 xvii kernel: [862561.832646] Enabling non-boot CPUs ...
Jan 3 18:46:42 xvii kernel: [862561.832646] Booting Node 0 Processor 1 APIC 0x1
Jan 3 18:46:42 xvii kernel: [862561.832646] smpboot cpu 1: start_ip = 96000
Jan 3 18:46:42 xvii kernel: [862561.729760] Calibrating delay loop (skipped) already calibrated this CPU
Jan 3 18:46:42 xvii kernel: [862561.844677] NMI watchdog enabled, takes one hw-pmu counter.
Jan 3 18:46:42 xvii kernel: [862561.848021] Switched to NOHz mode on CPU #1
Jan 3 18:46:42 xvii kernel: [862561.848064] CPU1 is up
Jan 3 18:46:42 xvii kernel: [862561.849219] ACPI: Waking up from system sleep state S3
Jan 3 18:46:42 xvii kernel: [862561.932380] pcieport 0000:00:01.0: restoring config space at offset 0xf (was 0x80100, writing 0x1a0100)
Jan 3 18:46:42 xvii kernel: [862561.932388] pcieport 0000:00:01.0: restoring config space at offset 0xa (was 0xf, writing 0x0)
Jan 3 18:46:42 xvii kernel: [862561.932392] pcieport 0000:00:01.0: restoring config space at offset 0x9 (was 0x1fff1, writing 0xeff1e001)
Jan 3 18:46:42 xvii kernel: [862561.932397] pcieport 0000:00:01.0: restoring config space at offset 0x8 (was 0xfff0, writing 0xf6e0f200)
Jan 3 18:46:42 xvii kernel: [862561.932402] pcieport 0000:00:01.0: restoring config space at offset 0x7 (was 0x200000f0, writing 0xd0d0)
Jan 3 18:46:43 xvii kernel: [862561.932406] pcieport 0000:00:01.0: restoring config space at offset 0x6 (was 0x0, writing 0x10100)
Jan 3 18:46:43 xvii kernel: [862561.932412] pcieport 0000:00:01.0: restoring config space at offset 0x3 (was 0x10000, writing 0x10010)
Jan 3 18:46:43 xvii kernel: [862561.932417] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100507)
Jan 3 18:46:43 xvii kernel: [862561.932455] e1000e 0000:00:19.0: restoring config space at offset 0xf (was 0x100, writing 0x10b)
Jan 3 18:46:43 xvii kernel: [862561.932476] e1000e 0000:00:19.0: restoring config space at offset 0x6 (was 0x1, writing 0xefe1)
Jan 3 18:46:43 xvii kernel: [862561.932483] e1000e 0000:00:19.0: restoring config space at offset 0x5 (was 0x0, writing 0xf6fdb000)
Jan 3 18:46:43 xvii kernel: [862561.932490] e1000e 0000:00:19.0: restoring config space at offset 0x4 (was 0x0, writing 0xf6fe0000)
Jan 3 18:46:43 xvii kernel: [862561.932500] e1000e 0000:00:19.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100107)
Jan 3 18:46:43 xvii kernel: [862561.932532] uhci_hcd 0000:00:1a.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
Jan 3 18:46:43 xvii kernel: [862561.932549] uhci_hcd 0000:00:1a.0: restoring config space at offset 0x8 (was 0x1, writing 0x6f61)
Jan 3 18:46:43 xvii kernel: [862561.932567] uhci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.932591] uhci_hcd 0000:00:1a.1: restoring config space at offset 0xf (was 0x200, writing 0x203)
Jan 3 18:46:43 xvii kernel: [862561.932609] uhci_hcd 0000:00:1a.1: restoring config space at offset 0x8 (was 0x1, writing 0x6f81)
Jan 3 18:46:43 xvii kernel: [862561.932626] uhci_hcd 0000:00:1a.1: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.932651] uhci_hcd 0000:00:1a.2: restoring config space at offset 0xf (was 0x300, writing 0x30b)
Jan 3 18:46:43 xvii kernel: [862561.932668] uhci_hcd 0000:00:1a.2: restoring config space at offset 0x8 (was 0x1, writing 0x6fa1)
Jan 3 18:46:43 xvii kernel: [862561.932685] uhci_hcd 0000:00:1a.2: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.932743] ehci_hcd 0000:00:1a.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
Jan 3 18:46:43 xvii kernel: [862561.932785] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0xf (was 0x100, writing 0x103)
Jan 3 18:46:43 xvii kernel: [862561.932810] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x4 (was 0xfebfc004, writing 0xf6fdc004)
Jan 3 18:46:43 xvii kernel: [862561.932817] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
Jan 3 18:46:43 xvii kernel: [862561.932825] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100102)
Jan 3 18:46:43 xvii kernel: [862561.932864] pcieport 0000:00:1c.0: restoring config space at offset 0xf (was 0x100, writing 0x20100)
Jan 3 18:46:43 xvii kernel: [862561.932880] pcieport 0000:00:1c.0: restoring config space at offset 0x9 (was 0x10001, writing 0xf091f081)
Jan 3 18:46:43 xvii kernel: [862561.932887] pcieport 0000:00:1c.0: restoring config space at offset 0x8 (was 0x0, writing 0xf070f060)
Jan 3 18:46:43 xvii kernel: [862561.932894] pcieport 0000:00:1c.0: restoring config space at offset 0x7 (was 0x20000000, writing 0x5050)
Jan 3 18:46:43 xvii kernel: [862561.932900] pcieport 0000:00:1c.0: restoring config space at offset 0x6 (was 0x0, writing 0xb0b00)
Jan 3 18:46:43 xvii kernel: [862561.932910] pcieport 0000:00:1c.0: restoring config space at offset 0x3 (was 0x810000, writing 0x810010)
Jan 3 18:46:43 xvii kernel: [862561.932919] pcieport 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100507)
Jan 3 18:46:43 xvii kernel: [862561.932982] pcieport 0000:00:1c.1: restoring config space at offset 0xf (was 0x200, writing 0x20200)
Jan 3 18:46:43 xvii kernel: [862561.932998] pcieport 0000:00:1c.1: restoring config space at offset 0x9 (was 0x10001, writing 0xf051f041)
Jan 3 18:46:43 xvii kernel: [862561.933004] pcieport 0000:00:1c.1: restoring config space at offset 0x8 (was 0x0, writing 0xf1f0f1f0)
Jan 3 18:46:43 xvii kernel: [862561.933010] pcieport 0000:00:1c.1: restoring config space at offset 0x7 (was 0x20000000, writing 0x4040)
Jan 3 18:46:43 xvii kernel: [862561.933018] pcieport 0000:00:1c.1: restoring config space at offset 0x6 (was 0x0, writing 0xc0c00)
Jan 3 18:46:43 xvii kernel: [862561.933028] pcieport 0000:00:1c.1: restoring config space at offset 0x3 (was 0x810000, writing 0x810010)
Jan 3 18:46:43 xvii kernel: [862561.933036] pcieport 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100000, writing 0x100507)
Jan 3 18:46:43 xvii kernel: [862561.933098] pcieport 0000:00:1c.2: restoring config space at offset 0xf (was 0x300, writing 0x20300)
Jan 3 18:46:43 xvii kernel: [862561.933114] pcieport 0000:00:1c.2: restoring config space at offset 0x9 (was 0x10001, writing 0xf031f021)
Jan 3 18:46:43 xvii kernel: [862561.933120] pcieport 0000:00:1c.2: restoring config space at offset 0x8 (was 0x0, writing 0xf010f000)
Jan 3 18:46:43 xvii kernel: [862561.933128] pcieport 0000:00:1c.2: restoring config space at offset 0x7 (was 0x20000000, writing 0x3030)
Jan 3 18:46:43 xvii kernel: [862561.933134] pcieport 0000:00:1c.2: restoring config space at offset 0x6 (was 0x0, writing 0xd0d00)
Jan 3 18:46:43 xvii kernel: [862561.933144] pcieport 0000:00:1c.2: restoring config space at offset 0x3 (was 0x810000, writing 0x810010)
Jan 3 18:46:43 xvii kernel: [862561.933153] pcieport 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100000, writing 0x100507)
Jan 3 18:46:43 xvii kernel: [862561.933232] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900005, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.933256] uhci_hcd 0000:00:1d.1: restoring config space at offset 0xf (was 0x200, writing 0x203)
Jan 3 18:46:43 xvii kernel: [862561.933274] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x8 (was 0x1, writing 0x6f21)
Jan 3 18:46:43 xvii kernel: [862561.933291] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.933316] uhci_hcd 0000:00:1d.2: restoring config space at offset 0xf (was 0x300, writing 0x30b)
Jan 3 18:46:43 xvii kernel: [862561.933332] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x8 (was 0x1, writing 0x6f41)
Jan 3 18:46:43 xvii kernel: [862561.933349] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900001)
Jan 3 18:46:43 xvii kernel: [862561.933407] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
Jan 3 18:46:43 xvii kernel: [862561.933453] pci 0000:00:1e.0: restoring config space at offset 0x7 (was 0x2280e0f0, writing 0x22802020)
Jan 3 18:46:43 xvii kernel: [862561.933459] pci 0000:00:1e.0: restoring config space at offset 0x6 (was 0x20030300, writing 0x20070300)
Jan 3 18:46:43 xvii kernel: [862561.933528] pci 0000:00:1f.0: restoring config space at offset 0x1 (was 0x2100007, writing 0x2100107)
Jan 3 18:46:43 xvii kernel: [862561.933569] ahci 0000:00:1f.2: restoring config space at offset 0xf (was 0x400, writing 0x40a)
Jan 3 18:46:43 xvii kernel: [862561.933598] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
Jan 3 18:46:43 xvii kernel: [862561.933644] i801_smbus 0000:00:1f.3: restoring config space at offset 0xf (was 0x200, writing 0x20a)
Jan 3 18:46:43 xvii kernel: [862561.933669] i801_smbus 0000:00:1f.3: restoring config space at offset 0x4 (was 0x4, writing 0xf6fdaf04)
Jan 3 18:46:43 xvii kernel: [862561.933679] i801_smbus 0000:00:1f.3: restoring config space at offset 0x1 (was 0x2800001, writing 0x2800103)
Jan 3 18:46:43 xvii kernel: [862561.933833] nouveau 0000:01:00.0: restoring config space at offset 0xf (was 0x100, writing 0x103)
Jan 3 18:46:43 xvii kernel: [862561.933895] nouveau 0000:01:00.0: restoring config space at offset 0x9 (was 0x1, writing 0xdf01)
Jan 3 18:46:43 xvii kernel: [862561.933923] nouveau 0000:01:00.0: restoring config space at offset 0x7 (was 0x4, writing 0xf2000004)
Jan 3 18:46:43 xvii kernel: [862561.933951] nouveau 0000:01:00.0: restoring config space at offset 0x5 (was 0xc, writing 0xe000000c)
Jan 3 18:46:43 xvii kernel: [862561.933971] nouveau 0000:01:00.0: restoring config space at offset 0x4 (was 0x0, writing 0xf5000000)
Jan 3 18:46:43 xvii kernel: [862561.933990] nouveau 0000:01:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
Jan 3 18:46:43 xvii kernel: [862561.934018] nouveau 0000:01:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100007)
Jan 3 18:46:43 xvii kernel: [862561.934219] iwlagn 0000:0c:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
Jan 3 18:46:43 xvii kernel: [862561.934262] iwlagn 0000:0c:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xf1ffe004)
Jan 3 18:46:43 xvii kernel: [862561.934273] iwlagn 0000:0c:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
Jan 3 18:46:43 xvii kernel: [862561.934286] iwlagn 0000:0c:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100106)
Jan 3 18:46:43 xvii kernel: [862561.934375] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xf (was 0x7000100, writing 0x580010a)
Jan 3 18:46:43 xvii kernel: [862561.934382] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xe (was 0x0, writing 0x20fc)
Jan 3 18:46:43 xvii kernel: [862561.934388] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xd (was 0x0, writing 0x2000)
Jan 3 18:46:43 xvii kernel: [862561.934396] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xc (was 0x0, writing 0x24fc)
Jan 3 18:46:43 xvii kernel: [862561.934402] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xb (was 0x0, writing 0x2400)
Jan 3 18:46:43 xvii kernel: [862561.934410] yenta_cardbus 0000:03:01.0: restoring config space at offset 0xa (was 0x0, writing 0xf13ff000)
Jan 3 18:46:43 xvii kernel: [862561.934416] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x9 (was 0x0, writing 0xf1000000)
Jan 3 18:46:43 xvii kernel: [862561.934423] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x8 (was 0x0, writing 0xf0fff000)
Jan 3 18:46:43 xvii kernel: [862561.934430] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x7 (was 0x0, writing 0xf0c00000)
Jan 3 18:46:43 xvii kernel: [862561.934437] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x6 (was 0x0, writing 0xb0070403)
Jan 3 18:46:43 xvii kernel: [862561.934446] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x4 (was 0x0, writing 0xfc000000)
Jan 3 18:46:43 xvii kernel: [862561.934452] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x3 (was 0x820000, writing 0x82a800)
Jan 3 18:46:43 xvii kernel: [862561.934462] yenta_cardbus 0000:03:01.0: restoring config space at offset 0x1 (was 0x2100000, writing 0x2100007)
Jan 3 18:46:43 xvii kernel: [862561.934490] yenta_cardbus 0000:03:01.0: proprietary Ricoh MMC controller disabled (via cardbus function)
Jan 3 18:46:43 xvii kernel: [862561.934492] yenta_cardbus 0000:03:01.0: MMC cards are now supported by standard SDHCI controller
Jan 3 18:46:43 xvii kernel: [862561.934529] firewire_ohci 0000:03:01.1: restoring config space at offset 0xf (was 0x4020200, writing 0x402020a)
Jan 3 18:46:43 xvii kernel: [862561.934556] firewire_ohci 0000:03:01.1: restoring config space at offset 0x3 (was 0x800000, writing 0x804010)
Jan 3 18:46:43 xvii kernel: [862561.934565] firewire_ohci 0000:03:01.1: restoring config space at offset 0x1 (was 0x2100000, writing 0x2100106)
Jan 3 18:46:43 xvii kernel: [862561.934593] sdhci-pci 0000:03:01.2: restoring config space at offset 0xf (was 0x300, writing 0x30b)
Jan 3 18:46:43 xvii kernel: [862561.934619] sdhci-pci 0000:03:01.2: restoring config space at offset 0x4 (was 0x0, writing 0xf1eff700)
Jan 3 18:46:43 xvii kernel: [862561.934626] sdhci-pci 0000:03:01.2: restoring config space at offset 0x3 (was 0x800000, writing 0x804010)
Jan 3 18:46:43 xvii kernel: [862561.934636] sdhci-pci 0000:03:01.2: restoring config space at offset 0x1 (was 0x2100000, writing 0x2100106)
Jan 3 18:46:43 xvii kernel: [862561.934989] PM: early resume of devices complete after 2.709 msecs
Jan 3 18:46:43 xvii kernel: [862561.935081] pci0000:00: wake-up capability disabled by ACPI
Jan 3 18:46:43 xvii kernel: [862561.935089] e1000e 0000:00:19.0: PME# disabled
Jan 3 18:46:43 xvii kernel: [862561.935153] uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
Jan 3 18:46:43 xvii kernel: [862561.935166] uhci_hcd 0000:00:1a.0: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935209] usb usb3: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935217] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X
Jan 3 18:46:43 xvii kernel: [862561.935226] uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
Jan 3 18:46:43 xvii kernel: [862561.935239] uhci_hcd 0000:00:1a.1: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935285] usb usb4: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935301] uhci_hcd 0000:00:1a.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
Jan 3 18:46:43 xvii kernel: [862561.935308] uhci_hcd 0000:00:1a.2: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935338] usb usb5: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935357] ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
Jan 3 18:46:43 xvii kernel: [862561.935364] ehci_hcd 0000:00:1a.7: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935424] snd_hda_intel 0000:00:1b.0: PCI INT A -> GSI 21 (level, low) -> IRQ 21
Jan 3 18:46:43 xvii kernel: [862561.935432] snd_hda_intel 0000:00:1b.0: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935500] snd_hda_intel 0000:00:1b.0: irq 47 for MSI/MSI-X
Jan 3 18:46:43 xvii kernel: [862561.935550] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
Jan 3 18:46:43 xvii kernel: [862561.935557] uhci_hcd 0000:00:1d.0: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935593] usb usb6: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935609] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
Jan 3 18:46:43 xvii kernel: [862561.935616] uhci_hcd 0000:00:1d.1: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935646] usb usb7: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935659] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
Jan 3 18:46:43 xvii kernel: [862561.935668] uhci_hcd 0000:00:1d.2: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935700] usb usb8: root hub lost power or was reset
Jan 3 18:46:43 xvii kernel: [862561.935717] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 20 (level, low) -> IRQ 20
Jan 3 18:46:43 xvii kernel: [862561.935724] ehci_hcd 0000:00:1d.7: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935782] pci 0000:00:1e.0: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935799] ahci 0000:00:1f.2: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935867] [drm] nouveau 0000:01:00.0: We're back, enabling device...
Jan 3 18:46:43 xvii kernel: [862561.935889] nouveau 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
Jan 3 18:46:43 xvii kernel: [862561.935908] nouveau 0000:01:00.0: setting latency timer to 64
Jan 3 18:46:43 xvii kernel: [862561.935918] [drm] nouveau 0000:01:00.0: POSTing device...
Jan 3 18:46:43 xvii kernel: [862561.935921] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table 0 at offset 0xD601
Jan 3 18:46:43 xvii kernel: [862561.937634] iwlagn 0000:0c:00.0: RF_KILL bit toggled to disable radio.
Jan 3 18:46:43 xvii kernel: [862561.937708] sdhci-pci 0000:03:01.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
Jan 3 18:46:43 xvii kernel: [862561.939565] sd 0:0:0:0: [sda] Starting disk
Jan 3 18:46:43 xvii kernel: [862561.963319] [drm] nouveau 0000:01:00.0: 0xD7E0: i2c wr fail: -6
Jan 3 18:46:43 xvii kernel: [862561.968744] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table 1 at offset 0xD9B3
Jan 3 18:46:43 xvii kernel: [862561.975176] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table 2 at offset 0xE259
Jan 3 18:46:43 xvii kernel: [862561.975257] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table 3 at offset 0xE34B
Jan 3 18:46:43 xvii kernel: [862561.976458] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table 4 at offset 0xE557
Jan 3 18:46:43 xvii kernel: [862561.976479] [drm] nouveau 0000:01:00.0: Parsing VBIOS init table at offset 0xE5BC
Jan 3 18:46:43 xvii kernel: [862561.996533] [drm] nouveau 0000:01:00.0: Restoring GPU objects...
Jan 3 18:46:43 xvii kernel: [862562.000211] firewire_core: skipped bus generations, destroying all nodes
Jan 3 18:46:43 xvii kernel: [862562.141087] serial 00:09: activated
Jan 3 18:46:43 xvii kernel: [862562.256217] ata5: SATA link down (SStatus 0 SControl 300)
Jan 3 18:46:43 xvii kernel: [862562.264103] ata6: SATA link down (SStatus 0 SControl 300)
Jan 3 18:46:43 xvii kernel: [862562.300087] usb 1-6: reset high speed USB device number 4 using ehci_hcd
Jan 3 18:46:43 xvii kernel: [862562.428094] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Jan 3 18:46:43 xvii kernel: [862562.444210] [drm] nouveau 0000:01:00.0: Reinitialising engines...
Jan 3 18:46:43 xvii kernel: [862562.444317] [drm] nouveau 0000:01:00.0: Restoring mode...
Jan 3 18:46:43 xvii kernel: [862562.444328] [drm] nouveau 0000:01:00.0: bo ffff8800d4939c00 pinned elsewhere: 0x00000002 vs 0x00000004
Jan 3 18:46:43 xvii kernel: [862562.445656] [drm] nouveau 0000:01:00.0: EvoCh 0 Mthd 0x0080 Data 0x00000000 (0x0005 0x05)
Jan 3 18:46:43 xvii kernel: [862562.500182] firewire_core: rediscovered device fw0
Jan 3 18:46:43 xvii kernel: [862562.502087] ata2.00: configured for UDMA/100
Jan 3 18:46:43 xvii kernel: [862564.087709] [drm] nouveau 0000:01:00.0: bo ffff8800d4939c00 pinned elsewhere: 0x00000002 vs 0x00000004
Jan 3 18:46:43 xvii kernel: [862564.087722] [drm:drm_helper_resume_force_mode] *ERROR* failed to set mode on crtc ffff88011a36d000
Jan 3 18:46:43 xvii kernel: [862564.302953] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input18
Jan 3 18:46:43 xvii kernel: [862565.468313] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Jan 3 18:46:43 xvii kernel: [862565.482157] ata1.00: configured for UDMA/133
Jan 3 18:46:43 xvii kernel: [862565.650414] PM: resume of devices complete after 3715.365 msecs
Jan 3 18:46:43 xvii kernel: [862565.691472] PM: Finishing wakeup.
Jan 3 18:46:43 xvii kernel: [862565.691480] Restarting tasks ... done.
Jan 3 18:46:43 xvii kernel: [862565.732448] video LNXVIDEO:00: Restoring backlight state
Jan 3 18:46:43 xvii kernel: [862565.932073] usb 3-1: new full speed USB device number 6 using uhci_hcd
Jan 3 18:46:43 xvii kernel: [862565.996103] hub 3-0:1.0: unable to enumerate USB device on port 1
Jan 3 18:46:43 xvii kernel: [862565.996161] usb 5-1: USB disconnect, device number 2
Jan 3 18:46:43 xvii kernel: [862566.025815] [drm] nouveau 0000:01:00.0: EvoCh 0 Mthd 0x0080 Data 0x00000000 (0x1005 0x05)
Jan 3 18:46:43 xvii acpid: client 15390[0:0] has disconnected
Jan 3 18:46:43 xvii kernel: [862566.480083] usb 5-1: new full speed USB device number 3 using uhci_hcd
Jan 3 18:46:43 xvii acpid: client connected from 15390[0:0]
Jan 3 18:46:43 xvii acpid: 1 client rule loaded
Jan 3 18:46:43 xvii kernel: [862566.666354] usb 5-1: New USB device found, idVendor=0a5c, idProduct=5800
Jan 3 18:46:43 xvii kernel: [862566.666366] usb 5-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jan 3 18:46:43 xvii kernel: [862566.666373] usb 5-1: Product: 5880
Jan 3 18:46:43 xvii kernel: [862566.666378] usb 5-1: Manufacturer: Broadcom Corp
Jan 3 18:46:43 xvii kernel: [862566.666383] usb 5-1: SerialNumber: 0123456789ABCD
Jan 3 18:46:43 xvii kernel: [862566.666650] usb 5-1: config 0 descriptor??
Jan 3 18:46:44 xvii mtp-probe: checking bus 5, device 3: "/sys/devices/pci0000:00/0000:00:1a.2/usb5/5-1"
Jan 3 18:46:44 xvii mtp-probe: bus: 5, device: 3 was not an MTP device
Jan 3 18:46:44 xvii pcscd: ifdhandler.c:102:IFDHCreateChannelByName() failed
Jan 3 18:46:44 xvii pcscd: readerfactory.c:965:RFInitializeReader() Open Port 0x200000 Failed (usb:0a5c/5800:libudev:0:/dev/bus/usb/005/003)
Jan 3 18:46:44 xvii pcscd: readerfactory.c:276:RFAddReader() Broadcom 5880 [Broadcom USH] (0123456789ABCD) init failed.
Jan 3 18:46:46 xvii pcscd: ccid_usb.c:1026:ControlUSB() control failed (5/3): -7 Success
Jan 3 18:46:46 xvii pcscd: commands.c:1055:CmdGetSlotStatus Hardware error
Jan 3 18:46:46 xvii pcscd: commands.c:1055:CmdGetSlotStatus Hardware error
Jan 3 18:46:46 xvii pcscd: commands.c:1055:CmdGetSlotStatus Hardware error
Jan 3 18:46:46 xvii pcscd: ifdhandler.c:135:IFDHCreateChannelByName() failed
Jan 3 18:46:46 xvii pcscd: readerfactory.c:965:RFInitializeReader() Open Port 0x200001 Failed (usb:0a5c/5800:libudev:1:/dev/bus/usb/005/003)
Jan 3 18:46:46 xvii pcscd: readerfactory.c:276:RFAddReader() Broadcom 5880 [Contacted SmartCard] (0123456789ABCD) init failed.
Jan 3 18:46:46 xvii pcscd: hotplug_libudev.c:380:HPAddDevice() Failed adding USB device: Broadcom 5880
Jan 3 18:47:01 xvii kernel: [862584.540550] iwlagn 0000:0c:00.0: RF_KILL bit toggled to enable radio.
Jan 3 18:47:01 xvii kernel: [862584.540666] keyboard: can't emulate rawmode for keycode 240
Jan 3 18:47:01 xvii kernel: [862584.540692] keyboard: can't emulate rawmode for keycode 240
Jan 3 18:47:02 xvii kernel: [862585.024322] usb 3-1: new full speed USB device number 7 using uhci_hcd
Jan 3 18:47:02 xvii kernel: [862585.257578] usb 3-1: New USB device found, idVendor=0a5c, idProduct=4500
Jan 3 18:47:02 xvii kernel: [862585.257590] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jan 3 18:47:02 xvii kernel: [862585.257597] usb 3-1: Product: BCM2046B1
Jan 3 18:47:02 xvii kernel: [862585.257601] usb 3-1: Manufacturer: Broadcom
Jan 3 18:47:02 xvii kernel: [862585.259493] hub 3-1:1.0: USB hub found
Jan 3 18:47:02 xvii kernel: [862585.261380] hub 3-1:1.0: 3 ports detected
Jan 3 18:47:02 xvii kernel: [862585.541574] usb 3-1.1: new full speed USB device number 8 using uhci_hcd
Jan 3 18:47:02 xvii kernel: [862585.660358] usb 3-1.1: New USB device found, idVendor=413c, idProduct=8157
Jan 3 18:47:02 xvii kernel: [862585.660370] usb 3-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Jan 3 18:47:02 xvii kernel: [862585.666959] input: HID 413c:8157 as /devices/pci0000:00/0000:00:1a.0/usb3/3-1/3-1.1/3-1.1:1.0/input/input19
Jan 3 18:47:02 xvii kernel: [862585.667343] generic-usb 0003:413C:8157.0003: input,hidraw0: USB HID v1.11 Keyboard [HID 413c:8157] on usb-0000:00:1a.0-1.1/input0
Jan 3 18:47:02 xvii kernel: [862585.741343] usb 3-1.2: new full speed USB device number 9 using uhci_hcd
Jan 3 18:47:03 xvii kernel: [862585.867339] usb 3-1.2: New USB device found, idVendor=413c, idProduct=8158
Jan 3 18:47:03 xvii kernel: [862585.867345] usb 3-1.2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Jan 3 18:47:03 xvii kernel: [862585.875609] input: HID 413c:8158 as /devices/pci0000:00/0000:00:1a.0/usb3/3-1/3-1.2/3-1.2:1.0/input/input20
Jan 3 18:47:03 xvii kernel: [862585.875800] generic-usb 0003:413C:8158.0004: input,hidraw1: USB HID v1.11 Mouse [HID 413c:8158] on usb-0000:00:1a.0-1.2/input0
Jan 3 18:47:03 xvii mtp-probe: checking bus 3, device 9: "/sys/devices/pci0000:00/0000:00:1a.0/usb3/3-1/3-1.2"
Jan 3 18:47:03 xvii mtp-probe: checking bus 3, device 8: "/sys/devices/pci0000:00/0000:00:1a.0/usb3/3-1/3-1.1"
Jan 3 18:47:03 xvii kernel: [862586.038357] iwlagn 0000:0c:00.0: L1 Enabled; Disabling L0S
Jan 3 18:47:03 xvii kernel: [862586.041430] iwlagn 0000:0c:00.0: Radio type=0x0-0x2-0x0
Jan 3 18:47:03 xvii kernel: [862586.098773] ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jan 3 18:47:03 xvii mtp-probe: bus: 3, device: 9 was not an MTP device
Jan 3 18:47:03 xvii mtp-probe: bus: 3, device: 8 was not an MTP device
Jan 3 18:47:03 xvii kernel: [862586.609563] usb 3-1.3: new full speed USB device number 10 using uhci_hcd
Jan 3 18:47:03 xvii bluetoothd[1657]: HCI dev 0 registered
Jan 3 18:47:03 xvii bluetoothd[1657]: Listening for HCI events on hci0
Jan 3 18:47:03 xvii kernel: [862586.736558] usb 3-1.3: New USB device found, idVendor=413c, idProduct=8156
Jan 3 18:47:03 xvii kernel: [862586.736570] usb 3-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jan 3 18:47:03 xvii kernel: [862586.736578] usb 3-1.3: Product: Dell Wireless 370 Bluetooth Mini-card
Jan 3 18:47:03 xvii kernel: [862586.736583] usb 3-1.3: Manufacturer: Dell Computer Corp
Jan 3 18:47:03 xvii bluetoothd[1657]: HCI dev 0 up
Jan 3 18:47:04 xvii bluetoothd[1657]: sap-dummy interface org.bluez.SimAccessTest init failed on path /org/bluez/test
Jan 3 18:47:04 xvii bluetoothd[1657]: Sap driver initialization failed.
Jan 3 18:47:04 xvii bluetoothd[1657]: sap-server: Operation not permitted (1)
Jan 3 18:47:04 xvii bluetoothd[1657]: Adapter /org/bluez/1657/hci0 has been enabled
--
Vincent Lefèvre <vincent@vinc17.net> - Web: <http://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <http://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / Arénaire project (LIP, ENS-Lyon)
Reply to: