Attempting to diagnose suspend/resume issue

Tue Jul 14 00:34:37 UTC 2015

Here is the output from before the problematic patch (ie. when the
screen worked with suspend/resume).

A couple of things:

* It looks like the card is getting powered down twice.
* It looks like the video state is saved after attempting to set the
power state the first time.  So that probably isn't the problem

So the code that saves the card state is failing mysteriously after
274386.  I doubt this is the fault of the ACPI changes that patch made.
 Add to that the fact that the efifb and vga text mode suspends
apparently never worked, and I'd say it's probably something in the card
state save/restore code.

So I guess I'll go poke around in that code for a while and see what I
can find.

On 07/10/2015 02:10 PM, Adrian Chadd wrote:
> Hi,
> 
> can you post some more debugging showing that the VGA driver is
> restoring the VGA state before the power is applied?
> 
> Thanks!
> 
> 
> -a
> 
> 
> On 9 July 2015 at 21:34, Eric McCorkle <eric at metricspace.net> wrote:
>> A long while ago, I reported my screen not coming back on after resume,
>> shortly after r274386 went in.  Unfortunately, the follow-on patch
>> didn't seem to work for me.
>>
>> (r274386 changed the way devices get powered down/up, and r274397 fixed
>> a typo in r274386 that tried to power down/up the wrong devices.)
>>
>> I finally found the time to try and track this thing down, and I got
>> some information that might prove useful in tracking it down.
>>
>>
>> * The screen comes back up only for syscons in pixel mode up to r274835.
>>  As far as I can tell, it doesn't work for vt in any revision (not as
>> sure about text-mode syscons, but there is at least one revision where
>> it works for pixel mode, but not text mode)
>>
>> * Comparing logs from r274385 and r274397, it seems the likely cause is
>> that the changes in r274386 reordered things so that the VGA driver
>> attempts to restore the state of the card before its power has been
>> turned back on (you can clearly see this happening, and you can see the
>> attempt to restore the state failing).
>>
>> * Suspend/resume works fine in Linux (I'm not sure how to get linux to
>> printout a debug trace similar to debug.bootverbose), so the hardware
>> can't be /that/ broken.
>>
>> * The order in which things happen during resume seems to be different
>> between vt and syscons resumes, though I can't tell where vt restores
>> the state of the card (or the efifb device)
>>
>> My guess as to the likely cause is that vt also tries to restore the
>> state of the card before its power has been turned back on similar to
>> what syscons does after r274386, or else the dual happens during suspend
>> (it tries to save the state after the device is powered down).  It does
>> seem a little wierd that syscons would behave differently in that
>> respect for pixel mode vs text mode, though.
>>
>> I'm open to suggestions as to what to look at next, or theories as to
>> what might be the culprit.  I also have dmesg logs for the various
>> revisions and drivers.
>>
>> Best,
>> Eric
>>
> _______________________________________________
> freebsd-mobile at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-mobile
> To unsubscribe, send any mail to "freebsd-mobile-unsubscribe at freebsd.org"
> 
-------------- next part --------------
Copyright (c) 1992-2014 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 11.0-CURRENT #3 r274085: Thu Jul  9 08:26:24 EDT 2015
    root at atom-edge:/usr/obj/usr/src/sys/CUSTOM amd64
FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512
CPU: Intel(R) Core(TM) i7-4700MQ CPU @ 2.40GHz (2394.51-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x306c3  Family=0x6  Model=0x3c  Stepping=3
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0x7fdafbbf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,<b11>,FMA,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,MOVBE,POPCNT,TSCDLT,AESNI,XSAVE,OSXSAVE,AVX,F16C,RDRAND>
  AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM>
  AMD Features2=0x21<LAHF,ABM>
  Structured Extended Features=0x27ab<FSGSBASE,TSCADJ,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID>
  XSAVE Features=0x1<XSAVEOPT>
  VT-x: (disabled in BIOS) PAT,HLT,MTF,PAUSE,EPT,UG,VPID
  TSC: P-state invariant, performance statistics
real memory  = 8589934592 (8192 MB)
avail memory = 7825338368 (7462 MB)
Event timer "LAPIC" quality 600
ACPI APIC Table: <LENOVO TP-GN   >
FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs
FreeBSD/SMP: 1 package(s) x 4 core(s) x 2 SMT threads
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
 cpu2 (AP): APIC ID:  2
 cpu3 (AP): APIC ID:  3
 cpu4 (AP): APIC ID:  4
 cpu5 (AP): APIC ID:  5
 cpu6 (AP): APIC ID:  6
 cpu7 (AP): APIC ID:  7
ioapic0 <Version 2.0> irqs 0-23 on motherboard
random: entropy device infrastructure driver
random: selecting highest priority adaptor <Dummy>
kbd1 at kbdmux0
random: SOFT: yarrow init()
random: selecting highest priority adaptor <Yarrow>
random: live provider: "Intel Secure Key RNG"
cryptosoft0: <software crypto> on motherboard
acpi0: <LENOVO TP-GN> on motherboard
acpi_ec0: <Embedded Controller: GPE 0x11, ECDT> port 0x62,0x66 on acpi0
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 7f900000 (3) failed
cpu0: <ACPI CPU> on acpi0
cpu1: <ACPI CPU> on acpi0
cpu2: <ACPI CPU> on acpi0
cpu3: <ACPI CPU> on acpi0
cpu4: <ACPI CPU> on acpi0
cpu5: <ACPI CPU> on acpi0
cpu6: <ACPI CPU> on acpi0
cpu7: <ACPI CPU> on acpi0
attimer0: <AT timer> port 0x40-0x43 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 14318180 Hz quality 950
Event timer "HPET" frequency 14318180 Hz quality 550
atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0
Event timer "RTC" frequency 32768 Hz quality 0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0
acpi_lid0: <Control Method Lid Switch> on acpi0
acpi_button0: <Sleep Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> irq 16 at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
vgapci0: <VGA-compatible display> port 0x4000-0x407f mem 0xb0000000-0xb0ffffff,0x80000000-0x8fffffff,0x90000000-0x91ffffff irq 16 at device 0.0 on pci1
acpi_video0: <ACPI video extension> on vgapci0
nvidia0: <Quadro K1100M> on vgapci0
vgapci0: child nvidia0 requested pci_enable_io
vgapci0: child nvidia0 requested pci_enable_io
vgapci1: <VGA-compatible display> port 0x5000-0x503f mem 0xb1400000-0xb17fffff,0xa0000000-0xafffffff irq 16 at device 2.0 on pci0
acpi_video1: <ACPI video extension> on vgapci1
vgapci1: Boot video device
hdac0: <Intel Haswell HDA Controller> mem 0xb2a30000-0xb2a33fff irq 16 at device 3.0 on pci0
xhci0: <Intel Lynx Point USB 3.0 controller> mem 0xb2a20000-0xb2a2ffff irq 16 at device 20.0 on pci0
xhci0: 32 byte context size.
xhci0: Port routing mask set to 0xffffffff
usbus0 on xhci0
pci0: <simple comms> at device 22.0 (no driver attached)
em0: <Intel(R) PRO/1000 Network Connection 7.4.2> port 0x5080-0x509f mem 0xb2a00000-0xb2a1ffff,0xb2a3e000-0xb2a3efff irq 20 at device 25.0 on pci0
em0: Using an MSI interrupt
em0: Ethernet address: 54:ee:75:16:eb:9d
hdac1: <Intel Lynx Point HDA Controller> mem 0xb2a34000-0xb2a37fff irq 22 at device 27.0 on pci0
pcib2: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
pci2: <ACPI PCI bus> on pcib2
sdhci_pci0: <Generic SD HCI> mem 0xb2901000-0xb2901fff,0xb2900000-0xb29007ff irq 16 at device 0.0 on pci2
sdhci_pci0: Hardware doesn't specify timeout clock frequency, setting BROKEN_TIMEOUT quirk.
sdhci_pci0: 1 slot(s) allocated
mmc0: <MMC/SD bus> on sdhci_pci0
pcib3: <ACPI PCI-PCI bridge> irq 17 at device 28.1 on pci0
pci3: <ACPI PCI bus> on pcib3
pci3: <network> at device 0.0 (no driver attached)
pcib4: <ACPI PCI-PCI bridge> irq 18 at device 28.2 on pci0
pci4: <ACPI PCI bus> on pcib4
pcib5: <ACPI PCI-PCI bridge> irq 16 at device 28.4 on pci0
pci6: <ACPI PCI bus> on pcib5
ehci0: <Intel Lynx Point USB 2.0 controller USB-A> mem 0xb2a3d000-0xb2a3d3ff irq 23 at device 29.0 on pci0
usbus1: EHCI version 1.0
usbus1 on ehci0
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
ahci0: <Intel Lynx Point AHCI SATA controller> port 0x50a8-0x50af,0x50b4-0x50b7,0x50a0-0x50a7,0x50b0-0x50b3,0x5060-0x507f mem 0xb2a3c000-0xb2a3c7ff irq 19 at device 31.2 on pci0
ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not supported
ahcich0: <AHCI channel> at channel 0 on ahci0
ahcich4: <AHCI channel> at channel 4 on ahci0
ahcich5: <AHCI channel> at channel 5 on ahci0
ahciem0: <AHCI enclosure management bridge> on ahci0
ichsmb0: <Intel Lynx Point SMBus controller> port 0xefa0-0xefbf mem 0xb2a38000-0xb2a380ff irq 18 at device 31.3 on pci0
smbus0: <System Management Bus> on ichsmb0
smb0: <SMBus generic I/O> on smbus0
acpi_tz0: <Thermal Zone> on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model Synaptics Touchpad, device ID 0
battery0: <ACPI Control Method Battery> on acpi0
acpi_acad0: <AC Adapter> on acpi0
acpi_ibm0: <IBM ThinkPad ACPI Extras> on acpi0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
coretemp0: <CPU On-Die Thermal Sensors> on cpu0
est0: <Enhanced SpeedStep Frequency Control> on cpu0
coretemp1: <CPU On-Die Thermal Sensors> on cpu1
est1: <Enhanced SpeedStep Frequency Control> on cpu1
coretemp2: <CPU On-Die Thermal Sensors> on cpu2
est2: <Enhanced SpeedStep Frequency Control> on cpu2
coretemp3: <CPU On-Die Thermal Sensors> on cpu3
est3: <Enhanced SpeedStep Frequency Control> on cpu3
coretemp4: <CPU On-Die Thermal Sensors> on cpu4
est4: <Enhanced SpeedStep Frequency Control> on cpu4
coretemp5: <CPU On-Die Thermal Sensors> on cpu5
est5: <Enhanced SpeedStep Frequency Control> on cpu5
coretemp6: <CPU On-Die Thermal Sensors> on cpu6
est6: <Enhanced SpeedStep Frequency Control> on cpu6
coretemp7: <CPU On-Die Thermal Sensors> on cpu7
est7: <Enhanced SpeedStep Frequency Control> on cpu7
ZFS filesystem version: 5
ZFS storage pool version: features support (5000)
Timecounters tick every 1.000 msec
hdacc0: <Intel Haswell HDA CODEC> at cad 0 on hdac0
hdaa0: <Intel Haswell Audio Function Group> at nid 1 on hdacc0
pcm0: <Intel Haswell (HDMI/DP 8ch)> at nid 3 on hdaa0
hdacc1: <Realtek (0x0292) HDA CODEC> at cad 0 on hdac1
hdaa1: <Realtek (0x0292) Audio Function Group> at nid 1 on hdacc1
pcm1: <Realtek (0x0292) (Analog 2.0+HP/2.0)> at nid 20,21 and 26 on hdaa1
pcm2: <Realtek (0x0292) (Internal Analog Mic)> at nid 18 on hdaa1
usbus0: 5.0Gbps Super Speed USB v3.0
usbus1: 480Mbps High Speed USB v2.0
ugen0.1: <0x8086> at usbus0
uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
ugen1.1: <Intel> at usbus1
uhub1: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
mmc0: No compatible cards found on bus
ses0 at ahciem0 bus 0 scbus3 target 0 lun 0
ses0: <AHCI SGPIO Enclosure 1.00 0001> SEMB S-E-S 2.00 device
ses0: SEMB SES Device
cd0 at ahcich5 bus 0 scbus2 target 0 lun 0
cd0: <MATSHITA DVD-RAM UJ8E2 SB01> Removable CD-ROM SCSI-0 device 
cd0: Serial Number H086 757747
cd0: 150.000MB/s transfers (SATA 1.x, UDMA6, ATAPI 12bytes, PIO 8192bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present - tray closed
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <HGST HTS725050A7E630 GH2ZB550> ATA-8 SATA 3.x device
ada0: Serial Number TF655AWH3WBHTL
ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
ada0: Command Queueing enabled
ada0: 476940MB (976773168 512 byte sectors: 16H 63S/T 16383C)
ada0: Previously was known as ad4
ada1 at ahcich4 bus 0 scbus1 target 0 lun 0
ada1: <LITEONIT LSS-16L6G DS42202> ATA-8 SATA 3.x device
ada1: Serial Number S0C41154Z1ZSCA151537
ada1: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
ada1: Command Queueing enabled
ada1: 15272MB (31277232 512 byte sectors: 16H 63S/T 16383C)
ada1: Previously was known as ad6
random: unblocking device.
SMP: AP CPU #1 Launched!
SMP: AP CPU #4 Launched!
SMP: AP CPU #3 Launched!
SMP: AP CPU #7 Launched!
SMP: AP CPU #2 Launched!
SMP: AP CPU #5 Launched!
SMP: AP CPU #6 Launched!
Timecounter "TSC-low" frequency 1197253950 Hz quality 1000
Root mount waiting for: usbus1 usbus0
uhub0: 21 ports with 21 removable, self powered
uhub1: 3 ports with 3 removable, self powered
Root mount waiting for: usbus1 usbus0
ugen1.2: <vendor 0x8087> at usbus1
uhub2: <vendor 0x8087 product 0x8000, class 9/0, rev 2.00/0.04, addr 2> on usbus1
Root mount waiting for: usbus1 usbus0
uhub2: 8 ports with 8 removable, self powered
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
Root mount waiting for: usbus0
ugen0.2: <Unknown> at usbus0 (disconnected)
Root mount waiting for: usbus0
ugen0.2: <SunplusIT INC.> at usbus0
Trying to mount root from zfs:data/freebsd []...
acpi_timer0: switching timecounter, TSC-low -> ACPI-fast
(ada0:ahcich0:0:0:0): spin-down
(ada1:ahcich4:0:0:0): spin-down
acpi_lid0: wake_prep enabled for \134_SB_.LID_ (S3)
acpi_button0: wake_prep enabled for \134_SB_.SLPB (S3)
pci0:1:0:0: Transition from D0 to D3
pci1: set ACPI power state D3 on \134_SB_.PCI0.PEG_.VID_
pci0:0:1:0: Transition from D0 to D3
pci0: set ACPI power state D3 on \134_SB_.PCI0.PEG_
pci0: failed to set ACPI power state D2 on \134_SB_.PCI0.PEG_: AE_BAD_PARAMETER
uhub0: at usbus0, port 1, addr 1 (disconnected)
ugen0.2: <SunplusIT INC.> at usbus0 (disconnected)
pci0:2:0:0: Transition from D0 to D3
pci0:0:28:0: Transition from D0 to D3
pci0: failed to set ACPI power state D2 on \134_SB_.PCI0.EXP1: AE_BAD_PARAMETER
pci0:0:28:1: Transition from D0 to D3
pci0: failed to set ACPI power state D2 on \134_SB_.PCI0.EXP2: AE_BAD_PARAMETER
pci0:0:28:2: Transition from D0 to D3
pci0: failed to set ACPI power state D2 on \134_SB_.PCI0.EXP3: AE_BAD_PARAMETER
pci0:0:28:4: Transition from D0 to D3
pci0: failed to set ACPI power state D2 on \134_SB_.PCI0.EXP5: AE_BAD_PARAMETER
uhub1: at usbus1, port 1, addr 1 (disconnected)
ugen1.2: <vendor 0x8087> at usbus1 (disconnected)
uhub2: at uhub1, port 1, addr 2 (disconnected)
vga0: saving 6660 bytes of video state
vga0: saving color palette
acpi_lid0: wake_prep enabled for \134_SB_.LID_ (S3)
acpi_button0: wake_prep enabled for \134_SB_.SLPB (S3)
pci0: set ACPI power state D0 on \134_SB_.PCI0.PEG_
pci0:0:1:0: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.PEG_
pci1: set ACPI power state D0 on \134_SB_.PCI0.PEG_.VID_
pci0:1:0:0: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.VID_
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP1
pci0:0:28:0: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP1
pci0:2:0:0: Transition from D3 to D0
sdhci_pci0-slot0: Divider 260 for freq 400000 (max 208000000)
mmc0: Probing bus
mmc0: SD probe: failed
mmc0: MMC probe: failed
mmc0: Current OCR: 0x00000000
mmc0: No compatible cards found on bus
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP2
pci0:0:28:1: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP2
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP3
pci0:0:28:2: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP3
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP5
pci0:0:28:4: Transition from D3 to D0
pci0: set ACPI power state D0 on \134_SB_.PCI0.EXP5
pci0: set ACPI power state D0 on \134_SB_.PCI0.LPC_
vga0: calling BIOS POST
pci0: set ACPI power state D0 on \134_SB_.PCI0.B0D3
pci0: set ACPI power state D0 on \134_SB_.PCI0.XHCI
pci0: set ACPI power state D0 on \134_SB_.PCI0.IGBE
em0: Link is Down
em0: link state changed to DOWN
pci0: set ACPI power state D0 on \134_SB_.PCI0.HDEF
hdaa1: Headphones redirection for association 0 nid=21 using unsolicited responses.
xhci0: 32 byte context size.
pci0: set ACPI power state D0 on \134_SB_.PCI0.EHC1
pci0: set ACPI power state D0 on \134_SB_.PCI0.SAT1
ahcich0: AHCI reset...
ahcich0: SATA connect time=100us status=00000133
ahcich0: AHCI reset: device found
ahcich0: AHCI reset: device ready after 0ms
ahcich4: AHCI reset...
ahcich4: SATA connect time=100us status=00000133
ahcich4: AHCI reset: device found
ahcich4: AHCI reset: device ready after 0ms
ahcich5: AHCI reset...
ahcich5: SATA connect time=1800us status=00000113
ahcich5: AHCI reset: device found
ahcich5: AHCI reset: device ready after 0ms
pci0: set ACPI power state D0 on \134_SB_.PCI0.SMBU
atkbd: the current kbd controller command byte 0065
atkbd: keyboard ID 0x54ab (2)
kbdc: RESET_KBD return code:00fa
kbdc: RESET_KBD status:00aa
kbdc: TEST_AUX_PORT status:0000
kbdc: RESET_AUX return code:00fa
kbdc: RESET_AUX status:00aa
kbdc: RESET_AUX ID:0000
(ada0:ahcich0:0:0:0): resume
(ada1:ahcich4:0:0:0): resume
xhci0: acpi_timer0: Port routing mask set to 0xffffffff
restoring timecounter, ACPI-fast -> TSC-low
uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
uhub1: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
uhub0: 21 ports with 21 removable, self powered
uhub1: 3 ports with 3 removable, self powered
em0: Link is up 1000 Mbps Full Duplex
em0: link state changed to UP
ugen1.2: <vendor 0x8087> at usbus1
uhub2: <vendor 0x8087 product 0x8000, class 9/0, rev 2.00/0.04, addr 2> on usbus1
uhub2: 8 ports with 8 removable, self powered
ugen0.2: <Unknown> at usbus0 (disconnected)
ugen0.2: <SunplusIT INC.> at usbus0
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freebsd.org/pipermail/freebsd-mobile/attachments/20150713/7883d937/attachment.bin>