Bug 36048 - [965GM] Resume ends with plasma effect
Summary: [965GM] Resume ends with plasma effect
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: unspecified
Hardware: x86-64 (AMD64) Linux (All)
: medium normal
Assignee: Daniel Vetter
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-04-07 04:29 UTC by Zdenek Kabelac
Modified: 2017-07-24 23:05 UTC (History)
4 users (show)

See Also:
i915 platform:
i915 features:


Attachments
Plasma effect on Intel display during resume (566.78 KB, video/avi)
2011-04-07 04:37 UTC, Zdenek Kabelac
no flags Details
dmesg from undock (122.15 KB, text/plain)
2011-04-11 01:23 UTC, Zdenek Kabelac
no flags Details
intel_gpu_dump (1.01 KB, text/plain)
2011-04-13 01:16 UTC, Zdenek Kabelac
no flags Details
Intel gtt (1.12 KB, text/plain)
2011-04-13 01:17 UTC, Zdenek Kabelac
no flags Details
i915_error_state (190.64 KB, text/plain)
2011-04-13 01:19 UTC, Zdenek Kabelac
no flags Details
i915_gem_pinned (387 bytes, text/plain)
2011-04-13 01:22 UTC, Zdenek Kabelac
no flags Details
pipe assert (28.20 KB, text/plain)
2011-04-21 10:26 UTC, Zdenek Kabelac
no flags Details
trace of intel lock (13.27 KB, text/plain)
2011-06-21 06:44 UTC, Zdenek Kabelac
no flags Details

Description Zdenek Kabelac 2011-04-07 04:29:16 UTC
It's now a big lottery to 'suspend/resume' my Lenovo T61 GMA965 - this problem is quite longterm - it happened from time to time in the past, but disabling drm_kms_helper thread seemed to minimize it.

However now with kernel 2.6.39-rcX - it strikes back with full power - nothing seems to help - and it's like 1 from 3-4 resumes ends with plasma effect on resume -  when this happens - the only way to have the laptop usable is to make a full reboot - machine seems to work OK - but without display it's not really useful.

I'm attaching phone video grab of such plasma effect.

Recently there are some extra warnings in the message log - but they are probably unrelated to real cause - they are just side effect - when I tried after such broken resume to suspend machine again.

So here is the log from 'resume -> (plasma) -> suspend -> resume...'

 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 hci_cmd_timer: hci0 command tx timeout
 e1000e 0000:00:19.0: PCI INT A disabled
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 451.401 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
QUEST on wlan0 to 192.168.192.1 port 67
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.886 msecs
 ACPI: Preparing to enter system sleep state S3
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.461 msecs
 i915 0000:00:02.0: power state changed by ACPI to D0
 i915 0000:00:02.0: power state changed by ACPI to D0
 e1000e 0000:00:19.0: wake-up capability disabled by ACPI
 uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
 usb usb2: root hub lost power or was reset
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
 usb usb3: root hub lost power or was reset
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
 HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 usb usb4: root hub lost power or was reset
 uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 usb usb6: root hub lost power or was reset
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 usb usb7: root hub lost power or was reset
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
 sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
 sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sd 0:0:0:0: [sda] Starting disk
 ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: configured for UDMA/33
 ata3: SATA link down (SStatus 0 SControl 300)
 usb 2-2: reset full speed USB device number 3 using uhci_hcd
 ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: configured for UDMA/100
 thinkpad_acpi: ACPI backlight control delay disabled
 PM: resume of devices complete after 3425.635 msecs
 Restarting tasks ... 
 done.
 video LNXVIDEO:00: Restoring backlight state
 cfg80211: Calling CRDA to update world regulatory domain
info> (wlan0): supplicant interface state: completed -> disconnected
 cfg80211: World regulatory domain updated:
 cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
 cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211: Calling CRDA for country: CZ
 cfg80211: Regulatory domain changed to country: CZ
 cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
 cfg80211:     (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm)
 cfg80211:     (5150000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2301 mBm)
 cfg80211:     (5250000 KHz - 5350000 KHz @ 40000 KHz), (N/A, 2000 mBm)
 cfg80211:     (5470000 KHz - 5725000 KHz @ 40000 KHz), (N/A, 2698 mBm)
Activating service name='org.freedesktop.PackageKit' argv0='/lib64/dbus-1/dbus-daemon-launch-helper'
info> (wlan0): supplicant interface state: disconnected -> scanning
Service 'org.freedesktop.PolicyKit1' is already active
Successfully activated service 'org.freedesktop.PackageKit'
 usb 2-1: new full speed USB device number 4 using uhci_hcd
 usb 2-1: New USB device found, idVendor=0a5c, idProduct=2110
 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
 usb 2-1: Product: BCM2045B
 usb 2-1: Manufacturer: Broadcom Corp
info> (wlan0): supplicant interface state: scanning -> authenticating
info> (wlan0): supplicant interface state: authenticating -> associating
info> (wlan0): supplicant interface state: associating -> 4-way handshake
info> (wlan0): supplicant interface state: 4-way handshake -> completed
QUEST on wlan0 to 192.168.192.1 port 67
K from 192.168.192.1
to 192.168.192.99 -- renewal in 32195 seconds.
info> (wlan0): DHCPv4 state changed reboot -> renew
info>   address 192.168.192.99
info>   prefix 24 (255.255.255.0)
info>   gateway 192.168.192.1
info>   hostname 'kabi'
info>   nameserver '192.168.192.1'
Activating service name='org.freedesktop.nm_dispatcher' argv0='/lib64/dbus-1/dbus-daemon-launch-helper'
Successfully activated service 'org.freedesktop.nm_dispatcher'
 ACPI: \_SB_.GDCK - undocking
 usb 2-1: USB disconnect, device number 4
 systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
 PM: Syncing filesystems ... done.
 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 447.927 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.880 msecs
 ACPI: Preparing to enter system sleep state S3
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.399 msecs
 i915 0000:00:02.0: power state changed by ACPI to D0
 i915 0000:00:02.0: power state changed by ACPI to D0
 e1000e 0000:00:19.0: wake-up capability disabled by ACPI
 uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
 usb usb2: root hub lost power or was reset
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
 usb usb3: root hub lost power or was reset
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
 HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 usb usb4: root hub lost power or was reset
 uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 usb usb6: root hub lost power or was reset
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 usb usb7: root hub lost power or was reset
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
 sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
 sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sd 0:0:0:0: [sda] Starting disk
 ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: configured for UDMA/33
 ata3: SATA link down (SStatus 0 SControl 300)
 usb 2-2: reset full speed USB device number 3 using uhci_hcd
 ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: configured for UDMA/100
 thinkpad_acpi: ACPI backlight control delay disabled
 PM: resume of devices complete after 3319.876 msecs
 Restarting tasks ... 
 done.
 video LNXVIDEO:00: Restoring backlight state
 usb 2-1: new full speed USB device number 5 using uhci_hcd
 usb 2-1: New USB device found, idVendor=0a5c, idProduct=2110
 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
 usb 2-1: Product: BCM2045B
 usb 2-1: Manufacturer: Broadcom Corp
 cfg80211: Calling CRDA to update world regulatory domain
info> (wlan0): supplicant interface state: completed -> disconnected
 cfg80211: World regulatory domain updated:
 cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
 cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
 cfg80211: Calling CRDA for country: CZ
 cfg80211: Regulatory domain changed to country: CZ
 cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
 cfg80211:     (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm)
 cfg80211:     (5150000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2301 mBm)
 cfg80211:     (5250000 KHz - 5350000 KHz @ 40000 KHz), (N/A, 2000 mBm)
 cfg80211:     (5470000 KHz - 5725000 KHz @ 40000 KHz), (N/A, 2698 mBm)
info> (wlan0): supplicant interface state: disconnected -> scanning
 thinkpad_acpi: fan watchdog: enabling fan
 ACPI: \_SB_.GDCK - undocking
 usb 2-1: USB disconnect, device number 5
 systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
 PM: Syncing filesystems ... done.
 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 444.625 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.879 msecs
 ACPI: Preparing to enter system sleep state S3
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.857 msecs
 uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
 usb usb2: root hub lost power or was reset
 e1000e 0000:00:19.0: wake-up capability disabled by ACPI
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 usb usb6: root hub lost power or was reset
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
 usb usb3: root hub lost power or was reset
 ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
 sd 0:0:0:0: [sda] Starting disk
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 usb usb4: root hub lost power or was reset
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 usb usb7: root hub lost power or was reset
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 i915 0000:00:02.0: power state changed by ACPI to D0
 i915 0000:00:02.0: power state changed by ACPI to D0
 ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: configured for UDMA/33
 ata3: SATA link down (SStatus 0 SControl 300)
 usb 2-2: reset full speed USB device number 3 using uhci_hcd
 ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: configured for UDMA/100
 thinkpad_acpi: ACPI backlight control delay disabled
 PM: resume of devices complete after 3434.468 msecs
 Restarting tasks ... 
 done.
 video LNXVIDEO:00: Restoring backlight state
 usb 2-1: new full speed USB device number 6 using uhci_hcd
 usb 2-1: New USB device found, idVendor=0a5c, idProduct=2110
 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
 usb 2-1: Product: BCM2045B
 usb 2-1: Manufacturer: Broadcom Corp
info> (wlan0): device state change: 100 -> 30 (reason 11)
info> (wlan0): deactivating device (reason: 11).
info> (wlan0): canceled DHCP transaction, DHCP client pid 1394
hdrawing address record for 192.168.192.99 on wlan0.
ving mDNS multicast group on interface wlan0.IPv4 with address 192.168.192.99.
erface wlan0.IPv4 no longer relevant for mDNS.
info> Setting system hostname to 'linux' (no default device)
Activating service name='org.freedesktop.nm_dispatcher' argv0='/lib64/dbus-1/dbus-daemon-launch-helper'
nterrupted system call
d by signal: 15
Successfully activated service 'org.freedesktop.nm_dispatcher'
hdrawing workstation service for tun0.
info> (wlan0): supplicant interface state: scanning -> disconnected
warn> Couldn't disconnect supplicant interface: This interface is not connected.
info> (wlan0): supplicant interface state: disconnected -> inactive
terface #6 tun0, 10.36.10.243#123, interface stats: received=0, sent=0, dropped=0, active_time=937 secs
terface #3 wlan0, 192.168.192.99#123, interface stats: received=268, sent=269, dropped=0, active_time=26811 secs
4 interface 192.168.192.99 -> (none)
.182 interface 192.168.192.99 -> (none)
.12 interface 192.168.192.99 -> (none)
1 interface 192.168.192.99 -> (none)
shed
 ACPI: \_SB_.GDCK - undocking
 usb 2-1: USB disconnect, device number 6
 systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
rs found in /etc/resolv.conf, will retry
e canary thread is apparently starving. Taking action.
moting known real-time threads.
ccessfully demoted thread 6377 of process 6365 (/usr/bin/pulseaudio).
ccessfully demoted thread 6376 of process 6365 (/usr/bin/pulseaudio).
ccessfully demoted thread 6365 of process 6365 (/usr/bin/pulseaudio).
ccessfully demoted thread 6191 of process 6181 (/usr/bin/pulseaudio).
ccessfully demoted thread 6190 of process 6181 (/usr/bin/pulseaudio).
moted 5 threads.
 PM: Syncing filesystems ... done.
 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 441.254 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.880 msecs
 ACPI: Preparing to enter system sleep state S3
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
info> VPN service 'vpnc' disappeared
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.393 msecs
 i915 0000:00:02.0: power state changed by ACPI to D0
 i915 0000:00:02.0: power state changed by ACPI to D0
 e1000e 0000:00:19.0: wake-up capability disabled by ACPI
 uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
 usb usb2: root hub lost power or was reset
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
 usb usb3: root hub lost power or was reset
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
 HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 usb usb4: root hub lost power or was reset
 uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 usb usb6: root hub lost power or was reset
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 usb usb7: root hub lost power or was reset
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
 sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
 sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sd 0:0:0:0: [sda] Starting disk
 ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: configured for UDMA/33
 ata3: SATA link down (SStatus 0 SControl 300)
 usb 2-2: reset full speed USB device number 3 using uhci_hcd
 ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: configured for UDMA/100
 thinkpad_acpi: ACPI backlight control delay disabled
 PM: resume of devices complete after 3371.694 msecs
 Restarting tasks ... 
 done.
 video LNXVIDEO:00: Restoring backlight state
 usb 2-1: new full speed USB device number 7 using uhci_hcd
 usb 2-1: New USB device found, idVendor=0a5c, idProduct=2110
 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
 usb 2-1: Product: BCM2045B
 usb 2-1: Manufacturer: Broadcom Corp
 ACPI: \_SB_.GDCK - undocking
 thinkpad_acpi: fan watchdog: enabling fan
 usb 2-1: USB disconnect, device number 7
 systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
 PM: Syncing filesystems ... done.
 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 464.620 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.873 msecs
 ACPI: Preparing to enter system sleep state S3
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 [drm] Changing LVDS panel from (+hsync, +vsync) to (-hsync, -vsync)
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.388 msecs
 i915 0000:00:02.0: power state changed by ACPI to D0
 e1000e 0000:00:19.0: wake-up capability disabled by ACPI
 i915 0000:00:02.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
 usb usb2: root hub lost power or was reset
 uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 usb usb6: root hub lost power or was reset
 sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
 sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
 ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
 sd 0:0:0:0: [sda] Starting disk
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
 usb usb3: root hub lost power or was reset
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
 usb usb4: root hub lost power or was reset
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
 usb usb7: root hub lost power or was reset
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
 ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
 ata4.00: configured for UDMA/33
 ata3: SATA link down (SStatus 0 SControl 300)
 usb 2-2: reset full speed USB device number 3 using uhci_hcd
 ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
 ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
 ata1.00: configured for UDMA/100
 thinkpad_acpi: ACPI backlight control delay disabled
 PM: resume of devices complete after 3307.693 msecs
 Restarting tasks ... 
 done.
 video LNXVIDEO:00: Restoring backlight state
 usb 2-1: new full speed USB device number 8 using uhci_hcd
 usb 2-1: New USB device found, idVendor=0a5c, idProduct=2110
 usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
 usb 2-1: Product: BCM2045B
 usb 2-1: Manufacturer: Broadcom Corp
 ACPI: \_SB_.GDCK - undocking
 usb 2-1: USB disconnect, device number 8
 systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
 PM: Syncing filesystems ... done.
 Freezing user space processes ... (elapsed 0.01 seconds) done.
 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
 sd 0:0:0:0: [sda] Synchronizing SCSI cache
 sd 0:0:0:0: [sda] Stopping disk
 sdhci-pci 0000:15:00.3: PCI INT C disabled
 sdhci-pci 0000:15:00.2: PCI INT C disabled
 ehci_hcd 0000:00:1d.7: PCI INT D disabled
 uhci_hcd 0000:00:1d.2: PCI INT C disabled
 uhci_hcd 0000:00:1d.1: PCI INT B disabled
 uhci_hcd 0000:00:1d.0: PCI INT A disabled
 HDA Intel 0000:00:1b.0: PCI INT B disabled
 ehci_hcd 0000:00:1a.7: PCI INT C disabled
 uhci_hcd 0000:00:1a.1: PCI INT B disabled
 uhci_hcd 0000:00:1a.0: PCI INT A disabled
 ata_piix 0000:00:1f.1: PCI INT C disabled
 i915 0000:00:02.0: power state changed by ACPI to D3
 e1000e 0000:00:19.0: wake-up capability enabled by ACPI
 PM: suspend of devices complete after 444.623 msecs
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
 PM: late suspend of devices complete after 56.868 msecs
 ACPI: Preparing to enter system sleep state S3
 ------------[ cut here ]------------
 WARNING: at drivers/gpu/drm/i915/intel_display.c:1203 assert_pipe+0x75/0x80 [i915]()
 Hardware name: 6464CTO
 pipe B assertion failure (expected off, current on)
 Modules linked in: tun binfmt_misc cryptd crypto_hash crypto_wq aes_x86_64 aes_generic ip6_tables ebtable_nat ebtables iptable_mangle xt_tcpudp bridge ipv6 stp llc sunrpc ipt_REJECT xt_physdev xt_state iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables dm_mirror dm_region_hash dm_log dm_mod snd_hda_codec_analog arc4 ecb crypto_blkcipher cryptomgr aead crypto_algapi virtio_net kvm_intel snd_hda_intel kvm iwl3945 snd_hda_codec snd_seq snd_seq_device psmouse iwl_legacy serio_raw snd_pcm thinkpad_acpi i2c_i801 btusb mac80211 bluetooth snd_timer iTCO_wdt e1000e iTCO_vendor_support nvram cfg80211 snd wmi soundcore snd_page_alloc evdev i915 drm_kms_helper drm i2c_algo_bit i2c_core uinput autofs4 pcmcia uhci_hcd sdhci_pci sdhci ehci_hcd sr_mod cdrom yenta_socket mmc_core usbcore video backlight [last unloaded: scsi_wait_scan]
 Pid: 10608, comm: kworker/0:0 Not tainted 2.6.39-rc2-00005-gf04d4dc #119
 Call Trace:
  [<ffffffff8105032f>] warn_slowpath_common+0x7f/0xc0
  [<ffffffff81050426>] warn_slowpath_fmt+0x46/0x50
  [<ffffffffa026c8e5>] assert_pipe+0x75/0x80 [i915]
  [<ffffffffa02725ed>] i9xx_crtc_disable+0x14d/0x1a0 [i915]
  [<ffffffffa027267e>] i9xx_crtc_prepare+0xe/0x10 [i915]
  [<ffffffffa00ec3d8>] drm_crtc_helper_set_mode+0x2f8/0x4c0 [drm_kms_helper]
  [<ffffffffa00ec612>] drm_helper_resume_force_mode+0x72/0x150 [drm_kms_helper]
  [<ffffffffa027e8d6>] intel_lid_notify+0xa6/0xc0 [i915]
  [<ffffffff81498713>] notifier_call_chain+0x93/0x100
  [<ffffffff8107ccd8>] __blocking_notifier_call_chain+0x78/0xb0
  [<ffffffff812d9b12>] ? acpi_os_wait_events_complete+0x23/0x23
  [<ffffffff8107cd26>] blocking_notifier_call_chain+0x16/0x20
  [<ffffffff813077e0>] acpi_lid_send_state+0x86/0xaf
  [<ffffffff81307866>] acpi_button_notify+0x3f/0xe3
  [<ffffffff810702cd>] ? process_one_work+0x12d/0x6d0
  [<ffffffff812dd6cb>] acpi_device_notify+0x19/0x1b
  [<ffffffff812ebbd0>] acpi_ev_notify_dispatch+0x67/0x7e
  [<ffffffff812d9b39>] acpi_os_execute_deferred+0x27/0x34
  [<ffffffff8107032e>] process_one_work+0x18e/0x6d0
  [<ffffffff810702cd>] ? process_one_work+0x12d/0x6d0
  [<ffffffff81070c4e>] worker_thread+0x15e/0x340
  [<ffffffff81070af0>] ? rescuer_thread+0x240/0x240
  [<ffffffff81075c6b>] kthread+0x9b/0xa0
  [<ffffffff8149d1d4>] kernel_thread_helper+0x4/0x10
  [<ffffffff81036694>] ? finish_task_switch+0x74/0x110
  [<ffffffff81494e6b>] ? _raw_spin_unlock_irq+0x3b/0x60
  [<ffffffff81495444>] ? retint_restore_args+0xe/0xe
  [<ffffffff81075bd0>] ? __init_kthread_worker+0x70/0x70
  [<ffffffff8149d1d0>] ? gs_change+0xb/0xb
 ---[ end trace 4912d132faa27442 ]---
 PM: Saving platform NVS memory
 Disabling non-boot CPUs ...
 CPU 1 is now offline
 lockdep: fixing up alternatives.
 Extended CMOS year: 2000
 ACPI: Low-level resume complete
 PM: Restoring platform NVS memory
 Extended CMOS year: 2000
 Enabling non-boot CPUs ...
 lockdep: fixing up alternatives.
 Booting Node 0 Processor 1 APIC 0x1
 Switched to NOHz mode on CPU #1
 NMI watchdog enabled, takes one hw-pmu counter.
 CPU1 is up
 ACPI: Waking up from system sleep state S3
 [drm] Changing LVDS panel from (+hsync, +vsync) to (-hsync, -vsync)
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
 sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
 sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
 PM: early resume of devices complete after 47.390 msecs
Comment 1 Zdenek Kabelac 2011-04-07 04:37:13 UTC
Created attachment 45368 [details]
Plasma effect on Intel display during resume
Comment 2 Chris Wilson 2011-04-07 08:29:59 UTC
Might be an underrun, but looks more like an incorrect pageflip. The last bug purporting to be a pageflip issue with KDE was bug 32303 and was fixed by
http://lists.x.org/archives/xorg-devel/2010-December/016511.html.
Comment 3 Zdenek Kabelac 2011-04-07 09:13:23 UTC
As more information could be helpful here - I'm using kernel build with a lot of debug stuff enabled - so maybe it could be some timing issue.

I've today tried to debug this with serial console and with drm.debug=0xe - but instead I got couple USB errors ;) - but no plasma - so it looks really something with timings.

Also - I'm switching to console and running manually pm-suspend - to avoid any clash with 'Xserver'  (as running rawhide is sometime a problem)
So I get this 'plasma' even when I'm just on console.

Also running rawhide means:
xorg-x11-server-Xorg-1.10.0-7.fc15.x86_64

And  drm & intel driver are taken from git repositories - and they are uptodate.

But as I said - I've seen this plasma even in past - so it's not a new problem from this week - but I don't remember where it has started :(

Anyway - it's not so easy debug it - as there is no 'straight' way to trigger it.

I'll try to collect GPU dump when this happens.
Comment 4 Zdenek Kabelac 2011-04-11 01:23:18 UTC
Created attachment 45465 [details]
dmesg from undock

I've started to play a bit more with 'undocking' mechanism used in my T61.

As there are couple other weird things going on when try to play with this stuff a bit more.

In the attached file - you may find couple message like:

[30034.339914] [drm:i915_pageflip_stall_check], Pageflip stall detected

Maybe these thing could be related to this problem ?
(Thought for now I'm NOT able to get the plasma effect on resume)

Also - why is the CRT being detected twice ?
Comment 5 Zdenek Kabelac 2011-04-13 01:14:09 UTC
Ok - today I've got another plasma - I've trie to grab some more info - though I've missed probably few important parts (next time I'll do better - if current info wouldn't be enough)

So first - here is the messsage log
(unfortunately without debug log :(  )

Timing info is left in - the problem might be related to very 'quick' resume after suspend - while the lid is kept closed.
(Kernel contains fix for problematic Bluetooth as Keith posted on lkml)
I'm using 'options drm_kms_helper poll=0'
Still it looks like 'Warning' in this log is related to drm_kms_helper thread ??

08:55:54 [26047.426394] PM: early resume of devices complete after 58.755 msecs
08:55:54 [26047.426946] i915 0000:00:02.0: power state changed by ACPI to D0
08:55:54 [26047.427300] i915 0000:00:02.0: power state changed by ACPI to D0
08:55:54 [26047.428613] e1000e 0000:00:19.0: wake-up capability disabled by ACPI
08:55:54 [26047.434101] uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
08:55:54 [26047.434803] usb usb1: root hub lost power or was reset
08:55:54 [26047.435092] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:55:54 [26047.435427] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:55:54 [26047.435758] uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
08:55:54 [26047.436456] usb usb3: root hub lost power or was reset
08:55:54 [26047.436746] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
08:55:54 [26047.437081] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
08:55:54 [26047.437437] ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 22 (level, low) -> IRQ 22
08:55:54 [26047.438281] HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
08:55:54 [26047.439511] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:55:54 [26047.439845] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:55:54 [26047.440175] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
08:55:54 [26047.440890] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
08:55:54 [26047.441592] usb usb6: root hub lost power or was reset
08:55:54 [26047.441880] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:55:54 [26047.442213] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:55:54 [26047.442542] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
08:55:54 [26047.443239] usb usb7: root hub lost power or was reset
08:55:54 [26047.443540] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
08:55:54 [26047.443791] ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
08:55:54 [26047.444005] sdhci-pci 0000:15:00.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
08:55:54 [26047.444010] sdhci-pci 0000:15:00.2: Will use DMA mode even though HW doesn't fully claim to support it.
08:55:54 [26047.444091] sdhci-pci 0000:15:00.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
08:55:54 [26047.444329] sd 0:0:0:0: [sda] Starting disk
08:55:54 [26047.446822] usb usb5: root hub lost power or was reset
08:55:54 [26047.447127] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
08:55:54 [26047.447495] ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
08:55:54 [26047.611513] ata4.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
08:55:54 [26047.611517] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
08:55:54 [26047.607497] non asle set request??
08:55:54 [26047.631169] ata4.00: configured for UDMA/33
08:55:54 [26047.764168] ata3: SATA link down (SStatus 0 SControl 300)
08:55:54 [26047.801108] usb 1-2: reset full speed USB device number 3 using uhci_hcd
08:55:54 [26048.800894] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
08:55:54 [26049.009298] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
08:55:54 [26049.009678] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
08:55:54 [26049.857958] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
08:55:54 [26049.858339] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
08:55:54 [26050.327759] ata1.00: configured for UDMA/100
08:55:54 [26050.660576] thinkpad_acpi: ACPI backlight control delay disabled
08:55:54 [26050.661047] max backlight PWM = 12056655
08:55:54 [26050.675832] SDVOB: W: 05 00 00                   (SDVO_CMD_SET_ACTIVE_OUTPUTS)
08:55:54 [26050.777072] PM: resume of devices complete after 3350.251 msecs
08:55:54 [26050.778782] Restarting tasks ... done.
08:55:54 [26050.841387] video LNXVIDEO:00: Restoring backlight state
08:56:01 [26057.962685] ACPI: \_SB_.GDCK - undocking
08:56:19 [26059.518686] PM: Syncing filesystems ... done.
08:56:19 [26059.574810] Freezing user space processes ... (elapsed 0.01 seconds) done.
08:56:19 [26059.591168] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
08:56:19 [26059.792705] sd 0:0:0:0: [sda] Synchronizing SCSI cache
08:56:19 [26059.793908] sd 0:0:0:0: [sda] Stopping disk
08:56:19 [26059.845497] sdhci-pci 0000:15:00.3: PCI INT C disabled
08:56:19 [26059.847249] sdhci-pci 0000:15:00.2: PCI INT C disabled
08:56:19 [26059.848920] ata_piix 0000:00:1f.1: PCI INT C disabled
08:56:19 [26059.849307] ehci_hcd 0000:00:1d.7: PCI INT D disabled
08:56:19 [26059.849307] uhci_hcd 0000:00:1d.2: PCI INT C disabled
08:56:19 [26059.849339] uhci_hcd 0000:00:1d.1: PCI INT B disabled
08:56:19 [26059.849369] uhci_hcd 0000:00:1d.0: PCI INT A disabled
08:56:19 [26059.849724] HDA Intel 0000:00:1b.0: PCI INT B disabled
08:56:19 [26059.850404] ehci_hcd 0000:00:1a.7: PCI INT C disabled
08:56:19 [26059.850446] uhci_hcd 0000:00:1a.1: PCI INT B disabled
08:56:19 [26059.850476] uhci_hcd 0000:00:1a.0: PCI INT A disabled
08:56:19 [26059.864161] i915 0000:00:02.0: power state changed by ACPI to D3
08:56:19 [26060.041134] ------------[ cut here ]------------
08:56:19 [26060.041392] WARNING: at drivers/gpu/drm/i915/intel_display.c:1203 assert_pipe+0x75/0x80 [i915]()
08:56:19 [26060.041840] Hardware name: 6464CTO
08:56:19 [26060.042019] pipe B assertion failure (expected off, current on)
08:56:19 [26060.042323] Modules linked in: cryptd crypto_hash crypto_wq aes_x86_64 aes_generic nfsd lockd nfs_acl auth_rpcgss loop binfmt_misc ip6_tables ebtable_nat ebtables iptable_mangle xt_tcpudp tun bridge ipv6 stp llc sunrpc ipt_REJECT xt_physdev xt_state iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables dm_mirror dm_region_hash dm_log dm_mod snd_hda_codec_analog arc4 ecb crypto_blkcipher cryptomgr aead crypto_algapi virtio_net kvm_intel kvm iwl3945 snd_hda_intel snd_hda_codec iwl_legacy snd_seq mac80211 snd_seq_device snd_pcm btusb usbhid snd_timer iTCO_wdt psmouse hid cfg80211 bluetooth thinkpad_acpi e1000e serio_raw iTCO_vendor_support i2c_i801 snd wmi snd_page_alloc soundcore nvram evdev i915 drm_kms_helper drm i2c_algo_bit i2c_core uinput autofs4 pcmcia uhci_hcd ehci_hcd sdhci_pci sdhci mmc_core sr_mod usbcore yenta_socket cdrom video backlight [last unloaded: scsi_wait_scan]
08:56:19 [26060.047434] Pid: 19042, comm: kworker/0:2 Not tainted 2.6.39-rc2-00145-g77c2e9a #122
08:56:19 [26060.047828] Call Trace:
08:56:19 [26060.047971]  [<ffffffff8105022f>] warn_slowpath_common+0x7f/0xc0
08:56:19 [26060.048281]  [<ffffffff81050326>] warn_slowpath_fmt+0x46/0x50
08:56:19 [26060.048605]  [<ffffffffa01a36c5>] assert_pipe+0x75/0x80 [i915]
08:56:19 [26060.048920]  [<ffffffffa01a93bd>] i9xx_crtc_disable+0x14d/0x1a0 [i915]
08:56:19 [26060.049271]  [<ffffffffa01a944e>] i9xx_crtc_prepare+0xe/0x10 [i915]
08:56:19 [26060.049602]  [<ffffffffa007c398>] drm_crtc_helper_set_mode+0x2f8/0x4c0 [drm_kms_helper]
08:56:19 [26060.050032]  [<ffffffffa007c5d2>] drm_helper_resume_force_mode+0x72/0x150 [drm_kms_helper]
08:56:19 [26060.050467]  [<ffffffffa01b56b6>] intel_lid_notify+0xa6/0xc0 [i915]
08:56:19 [26060.050811]  [<ffffffff81496e93>] notifier_call_chain+0x93/0x100
08:56:19 [26060.051122]  [<ffffffff8107d388>] __blocking_notifier_call_chain+0x78/0xb0
08:56:19 [26060.051476]  [<ffffffff8107d3d6>] blocking_notifier_call_chain+0x16/0x20
08:56:19 [26060.051822]  [<ffffffff8130728c>] acpi_lid_send_state+0x86/0xaf
08:56:19 [26060.052127]  [<ffffffff81307312>] acpi_button_notify+0x3f/0xe3
08:56:19 [26060.052430]  [<ffffffff81070c27>] ? process_one_work+0x167/0x6f0
08:56:19 [26060.052740]  [<ffffffff812dd2db>] acpi_device_notify+0x19/0x1b
08:56:19 [26060.053043]  [<ffffffff812eb67c>] acpi_ev_notify_dispatch+0x67/0x7e
08:56:19 [26060.053366]  [<ffffffff812d9779>] acpi_os_execute_deferred+0x27/0x34
08:56:19 [26060.053694]  [<ffffffff81070c88>] process_one_work+0x1c8/0x6f0
08:56:19 [26060.053995]  [<ffffffff81070c27>] ? process_one_work+0x167/0x6f0
08:56:19 [26060.054329]  [<ffffffff812d9752>] ? acpi_os_wait_events_complete+0x23/0x23
08:56:19 [26060.054694]  [<ffffffff81071589>] worker_thread+0x159/0x340
08:56:19 [26060.054992]  [<ffffffff81071430>] ? rescuer_thread+0x240/0x240
08:56:19 [26060.055302]  [<ffffffff8107614b>] kthread+0x9b/0xa0
08:56:19 [26060.055566]  [<ffffffff8149b954>] kernel_thread_helper+0x4/0x10
08:56:19 [26060.055881]  [<ffffffff810367a4>] ? finish_task_switch+0x74/0x110
08:56:19 [26060.056215]  [<ffffffff814935eb>] ? _raw_spin_unlock_irq+0x3b/0x60
08:56:19 [26060.056560]  [<ffffffff81493bc4>] ? retint_restore_args+0xe/0xe
08:56:19 [26060.056892]  [<ffffffff810760b0>] ? __init_kthread_worker+0x70/0x70
08:56:19 [26060.057243]  [<ffffffff8149b950>] ? gs_change+0xb/0xb
08:56:19 [26060.057546] ---[ end trace dd68828d62d5c035 ]---
08:56:19 [26060.060720] e1000e 0000:00:19.0: wake-up capability enabled by ACPI
08:56:19 [26060.074251] PM: suspend of devices complete after 467.654 msecs
08:56:19 [26060.100806] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
08:56:19 [26060.101223] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
08:56:19 [26060.101716] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
08:56:19 [26060.114138] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
08:56:19 [26060.134223] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
08:56:19 [26060.134759] PM: late suspend of devices complete after 60.506 msecs
08:56:19 [26060.135508] ACPI: Preparing to enter system sleep state S3
08:56:19 [26060.290932] PM: Saving platform NVS memory
08:56:19 [26060.292517] Disabling non-boot CPUs ...
08:56:19 [26060.440789] CPU 1 is now offline
08:56:19 [26060.440942] lockdep: fixing up alternatives.
08:56:19 [26060.442071] Extended CMOS year: 2000
08:56:19 [26060.442738] ACPI: Low-level resume complete
08:56:19 [26060.442738] PM: Restoring platform NVS memory
08:56:19 [26060.442738] Extended CMOS year: 2000
08:56:19 [26060.442738] Enabling non-boot CPUs ...
08:56:19 [26060.449574] lockdep: fixing up alternatives.
08:56:19 [26060.449776] Booting Node 0 Processor 1 APIC 0x1
08:56:19 [26060.547426] Switched to NOHz mode on CPU #1
08:56:19 [26060.588561] NMI watchdog enabled, takes one hw-pmu counter.
08:56:19 [26060.607580] CPU1 is up
08:56:19 [26060.609101] ACPI: Waking up from system sleep state S3
08:56:19 [26060.924184] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:56:19 [26060.924493] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:56:19 [26060.925336] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:56:19 [26060.925645] uhci_hcd 0000:00:1a.1: power state changed by ACPI to D0
08:56:19 [26060.926528] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
08:56:19 [26060.926842] ehci_hcd 0000:00:1a.7: power state changed by ACPI to D0
08:56:19 [26060.931115] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:56:19 [26060.931422] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:56:19 [26060.932264] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:56:19 [26060.932573] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
08:56:19 [26060.933429] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:56:19 [26060.933734] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:56:19 [26060.934604] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:56:19 [26060.934910] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
08:56:19 [26060.935809] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
08:56:19 [26060.936119] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
08:56:19 [26060.950780] sdhci-pci 0000:15:00.2: BAR 0: set to [mem 0xf8301000-0xf83010ff] (PCI address [0xf8301000-0xf83010ff])
08:56:19 [26060.964110] sdhci-pci 0000:15:00.3: BAR 0: set to [mem 0xf8301400-0xf83014ff] (PCI address [0xf8301400-0xf83014ff])
08:56:19 [26060.966425] PM: early resume of devices complete after 58.787 msecs
Comment 6 Zdenek Kabelac 2011-04-13 01:16:44 UTC
Created attachment 45563 [details]
intel_gpu_dump

This is GPU dump - however not in the moment of the first resume  - so might not be really helpful.

Repeating  0x0000000 we 'cut off'
Comment 7 Zdenek Kabelac 2011-04-13 01:17:20 UTC
Created attachment 45564 [details]
Intel gtt
Comment 8 Zdenek Kabelac 2011-04-13 01:19:25 UTC
Created attachment 45565 [details]
i915_error_state

Hopefully something interesting could be found here.

Repeating 0000000  were cut-off at the end
(Size dropped from 689681 -> 195211)
Comment 9 Zdenek Kabelac 2011-04-13 01:22:30 UTC
Created attachment 45566 [details]
i915_gem_pinned
Comment 10 Chris Wilson 2011-04-13 01:31:45 UTC
Seeing that assert_pipe again reminded me of:

commit f6e5b1603b8bb7131b6778d0d4e2e5dda120a379
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Apr 12 18:06:51 2011 +0100

    drm/i915: Sanitize the output registers after resume
    
    Similar to booting, we need to inspect the state left by the BIOS and
    remove any conflicting bits before we take over. The example reported by
    Seth Forshee is very similar to the bug we encountered with the state left
    by grub2, that the crtc pipe<->planning mapping was reversed from our
    expectations and so we failed to turn off the outputs when booting or,
    in this case, resuming. This may be in fact the same bug, but triggered
    at resume time.
    
    This patch rearranges the code we already have to clear up the
    conflicting state upon init and calls it from reset (which is called
    after we have lost control of the hardware, i.e. along both the boot and
    resume paths) instead.
    
Though I didn't expect 965GM to be affected by that bug. Can you please test that patch (on drm-intel-fixes) and see if it is in fact the same bug?
Comment 11 Zdenek Kabelac 2011-04-13 02:15:43 UTC
> Though I didn't expect 965GM to be affected by that bug. Can you please test
> that patch (on drm-intel-fixes) and see if it is in fact the same bug?

So taking this one:

http://git.kernel.org/?p=linux/kernel/git/ickle/drm-intel.git;a=commitdiff;h=f6e5b1603b8bb7131b6778d0d4e2e5dda120a379

But do I need to change anything for 965GM ?

Also note I'm not able to trigger this bug easily - though I could enable drm_kms_helper thread which seemed to bring this problem more often.

I'll keep running my laptop for a few days to see whether I'll hit this problem again.
Comment 12 Chris Wilson 2011-04-13 02:23:22 UTC
It'll work (or not) as is for 965GM.

/me crosses his fingers that this is the answer.
Comment 13 Zdenek Kabelac 2011-04-13 02:29:15 UTC
(In reply to comment #12)
> It'll work (or not) as is for 965GM.
> 
> /me crosses his fingers that this is the answer.

We will see.

Another user with similar laptop does not experience these troubles - thought I'm seeing the plasma effect for quite some time. Anyway it would be good to see it finally fixed before I get a new one ;)

Anyway:

dmidecode about my T61 bios:

BIOS Information
        Vendor: LENOVO
        Version: 7LETC7WW (2.27 )
        Release Date: 04/08/2010


And here is the one - which 'might not' be giving troubles:

BIOS Information
        Vendor: LENOVO
        Version: 7LETC5WW (2.25 )
        Release Date: 11/14/2008
Comment 14 Zdenek Kabelac 2011-04-18 05:44:25 UTC
Ok - I really start to feel you've really hit the nail on the head - I've not seen the plasma problem from that day - so you could probably close it as a duplicate of your already fixed bug for other chipset (if there is other Xorg bug except the Ubuntu one).
Comment 15 Zdenek Kabelac 2011-04-21 10:26:32 UTC
Created attachment 45926 [details]
pipe assert

Ok - my display seems to be fine so far - i.e. no plasma effect.
But I'm still getting those warnings logged occasionally during suspend/resume
Comment 16 Zdenek Kabelac 2011-05-09 01:38:01 UTC
Sad news today - plasma strikes back - my actual kernel is past 2.6.39-rc6 - so it has your sanitize patch already included upstream.

I'll try to collect few more info about this state.
Then I'll make a reboot.

WARNING: at drivers/gpu/drm/i915/intel_display.c:1203 assert_pipe+0x75/0x80 [i915]()

Is present in dmesg log - seems like the problem happens during suspend?

(Maybe it was a bad idea to enable drm_kms_helper thread - which I've made with the hope the problem was gone)

ACPI handle has no context!
ata_piix 0000:00:1f.1: PCI INT C disabled
ehci_hcd 0000:00:1d.7: PCI INT D disabled
uhci_hcd 0000:00:1d.2: PCI INT C disabled
uhci_hcd 0000:00:1d.1: PCI INT B disabled
uhci_hcd 0000:00:1d.0: PCI INT A disabled
HDA Intel 0000:00:1b.0: PCI INT B disabled
ehci_hcd 0000:00:1a.7: PCI INT C disabled
uhci_hcd 0000:00:1a.1: PCI INT B disabled
uhci_hcd 0000:00:1a.0: PCI INT A disabled
i915 0000:00:02.0: power state changed by ACPI to D3
------------[ cut here ]------------
WARNING: at drivers/gpu/drm/i915/intel_display.c:1203 assert_pipe+0x75/0x80 [i915]()
Hardware name: 6464CTO
pipe B assertion failure (expected off, current on)
Modules linked in: binfmt_misc i915 drm_kms_helper drm i2c_algo_bit cryptd crypto_hash crypto_wq aes_x86_64 aes_generic ip6_tables ebtable_nat ebtables iptable_mangle xt_tcpudp tun bridge ipv6 stp llc sunrpc bluetooth ipt_REJECT xt_physdev xt_state iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables loop dm_mirror dm_region_hash dm_log dm_mod snd_hda_codec_analog arc4 ecb crypto_blkcipher cryptomgr aead crypto_algapi iwl3945 iwl_legacy snd_hda_intel mac80211 snd_hda_codec snd_seq snd_seq_device cfg80211 snd_pcm i2c_i801 psmouse e1000e iTCO_wdt i2c_core thinkpad_acpi snd_timer serio_raw snd_page_alloc iTCO_vendor_support wmi snd soundcore nvram evdev virtio_net kvm_intel kvm autofs4 pcmcia ehci_hcd uhci_hcd sdhci_pci sdhci usbcore mmc_core sr_mod cdrom yenta_socket video backlight [last unloaded: scsi_wait_scan]
Pid: 8677, comm: kworker/0:0 Not tainted 2.6.39-rc6-00047-gc7bf45d #11
Call Trace:
 [<ffffffff810501ff>] warn_slowpath_common+0x7f/0xc0
 [<ffffffff810502f6>] warn_slowpath_fmt+0x46/0x50
 [<ffffffffa05336b5>] assert_pipe+0x75/0x80 [i915]
 [<ffffffffa05394ad>] i9xx_crtc_disable+0x14d/0x1a0 [i915]
 [<ffffffffa053953e>] i9xx_crtc_prepare+0xe/0x10 [i915]
 [<ffffffffa03973c8>] drm_crtc_helper_set_mode+0x2f8/0x4c0 [drm_kms_helper]
 [<ffffffffa0397602>] drm_helper_resume_force_mode+0x72/0x150 [drm_kms_helper]
 [<ffffffffa05456d6>] intel_lid_notify+0xa6/0xc0 [i915]
 [<ffffffff814973f3>] notifier_call_chain+0x93/0x100
 [<ffffffff8107d3a8>] __blocking_notifier_call_chain+0x78/0xb0
 [<ffffffff8107d3f6>] blocking_notifier_call_chain+0x16/0x20
 [<ffffffff81307430>] acpi_lid_send_state+0x86/0xaf
 [<ffffffff813074b6>] acpi_button_notify+0x3f/0xe3
 [<ffffffff81070c37>] ? process_one_work+0x167/0x6f0
 [<ffffffff812dd47b>] acpi_device_notify+0x19/0x1b
 [<ffffffff812eb820>] acpi_ev_notify_dispatch+0x67/0x7e
 [<ffffffff812d9919>] acpi_os_execute_deferred+0x27/0x34
 [<ffffffff81070c98>] process_one_work+0x1c8/0x6f0
 [<ffffffff81070c37>] ? process_one_work+0x167/0x6f0
 [<ffffffff81494144>] ? retint_restore_args+0xe/0xe
 [<ffffffff812d98f2>] ? acpi_os_wait_events_complete+0x23/0x23
 [<ffffffff81071599>] worker_thread+0x159/0x340
 [<ffffffff81071440>] ? rescuer_thread+0x240/0x240
 [<ffffffff8107616b>] kthread+0x9b/0xa0
 [<ffffffff8149be94>] kernel_thread_helper+0x4/0x10
 [<ffffffff810367c4>] ? finish_task_switch+0x74/0x110
 [<ffffffff81493b8b>] ? _raw_spin_unlock_irq+0x3b/0x60
 [<ffffffff81494144>] ? retint_restore_args+0xe/0xe
 [<ffffffff810760d0>] ? __init_kthread_worker+0x70/0x70
 [<ffffffff8149be90>] ? gs_change+0xb/0xb
---[ end trace 8f59c14123580cf2 ]---
i2c i2c-10: NAK from device addr 0x38 msg #0
e1000e 0000:00:19.0: PME# enabled
e1000e 0000:00:19.0: wake-up capability enabled by ACPI
PM: suspend of devices complete after 484.264 msecs
ehci_hcd 0000:00:1d.7: power state changed by ACPI to D3
uhci_hcd 0000:00:1d.2: power state changed by ACPI to D3
uhci_hcd 0000:00:1d.0: power state changed by ACPI to D3
ehci_hcd 0000:00:1a.7: power state changed by ACPI to D3
uhci_hcd 0000:00:1a.1: power state changed by ACPI to D3
PM: late suspend of devices complete after 56.863 msecs
ACPI: Preparing to enter system sleep state S3
PM: Saving platform NVS memory
Disabling non-boot CPUs ...
CPU 1 is now offline
lockdep: fixing up alternatives.
Comment 17 Zdenek Kabelac 2011-06-21 06:44:20 UTC
Created attachment 48229 [details]
trace of intel lock

Here is quite similar error which happened today - with my rawhide - after like 3 minutes from running xlock.   So it seems like the error could be triggered even without  suspend.

This is mostly plain  2.6.39 kernel with few minor local patches (dm related)

xorg-x11-drv-intel-2.15.0-4.fc16.x86_64
xorg-x11-server-Xorg-1.10.99.1-6.20110510.fc16.x86_64

Unfortunately I've had remote access to this machine in the moment of crash.

I'll eventually try later to trigger same conditions to grab same more error info.
Comment 18 Florian Mickler 2011-06-30 03:13:13 UTC
A patch referencing this bug report has been merged in Linux v3.0-rc1:

commit 2c7111dbaec72b01c804afb8ad77c6c7523986fd
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Mar 29 10:40:27 2011 +0100

    drm/i915: Disable all outputs early, before KMS takeover
Comment 19 Jesse Barnes 2012-04-16 14:49:42 UTC
Hoping this isn't an issue anymore, but it would be good to get confirmation.

Zdenek?
Comment 20 Zdenek Kabelac 2012-05-30 05:37:46 UTC
(In reply to comment #19)
> Hoping this isn't an issue anymore, but it would be good to get confirmation.
> 


I've not see any plasma efect on my display for quite some time.
I've different problem with GPU hang bug 50393 instead ;)
Comment 21 Jesse Barnes 2012-05-30 08:37:09 UTC
Great, thanks for confirming.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.