inteldrm: cleanup_done timed out with external monitor

classic Classic list List threaded Threaded
12 messages Options
Reply | Threaded
Open this post in threaded view
|

inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
First of all, apologies for posting this to the wrong list (tech@)
earlier. Here is a sendbug(1) report with additional info.

>Synopsis: inteldrm timeouts at boot when external monitor is connected
>Category: kernel
>Environment:
        System      : OpenBSD 6.5
        Details     : OpenBSD 6.5-current (GENERIC.MP) #4: Fri May 24 12:47:38 CEST 2019
                         [hidden email]:/sys/arch/amd64/compile/GENERIC.MP

        Architecture: OpenBSD.amd64
        Machine     : amd64
>Description:
        Since updating my snapshot machine a few days ago, I'm seeing the following
        when an external monitor is attached through the dock (DisplayPort). The
        machine is a Lenovo Thinkpad X250.

        The "timed out" lines appear near the end of boot and halt the start of X
        (xenodm) - the machine becomes unresponsive with a blank screen. After a
        few minutes, things "clear up", X comes up, and the error no longer
        appears. I've verified that the error also appears without X (xenodm turned
        off for testing). In that case, the machine stays responsive while the
        errors appear on the console.

    OpenBSD 6.5-current (GENERIC.MP) #32: Thu May 16 09:45:13 MDT 2019
    ...
    inteldrm0 at pci0 dev 2 function 0 "Intel HD Graphics 5500" rev 0x09
    drm0 at inteldrm0
    inteldrm0: msi
    ...
    [drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
    [drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out

        I tracked the error message down to the function stall_checks() in
        dev/pci/drm/drm_atomic_helper.c. As far as I understand the comments before
        that function and drm_atomic_helper_setup_commit(), "atomic commits" are
        supposed to always call drm_atomic_helper_commit_cleanup_done at the end
        and the timeout message means that this somehow didn't occur.

        To debug further, I've compiled a kernel with DRM_DEBUG_ATOMIC enabled and
        some debug output added to trace the atomic helper functions being called.
        See the attached diff.

        I am including dmesg for this kernel booting with external display as well
        as one without the display where everything works fine.

        Looking at the trace of drm_atomic_helper calls (search for XXX) and their
        respective state arguments, it appears that all the cleanup_done calls
        eventually happen, but not before the third commit comes in and complains.
        This appears consistent with the code of stall_checks(), where AFAICT the
        error is generated if there are two elements in a list of commits.
>How-To-Repeat:
        - connect external monitor (via display port?) to Intel onboard graphics
        - boot GENERIC or GENERIC.MP kernel
>Fix:
        ?

dmesg (with external display):
OpenBSD 6.5-current (GENERIC.MP) #6: Fri May 24 15:08:19 CEST 2019
    [hidden email]:/sys/arch/amd64/compile/GENERIC.MP
real mem = 8277159936 (7893MB)
avail mem = 8011235328 (7640MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.7 @ 0xacbfd000 (65 entries)
bios0: vendor LENOVO version "N10ET36W (1.15 )" date 06/19/2015
bios0: LENOVO 20CLS2LK00
acpi0 at bios0: rev 2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP ASF! HPET ECDT APIC MCFG SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT PCCT SSDT TCPA SSDT UEFI POAT BATB FPDT UEFI DMAR
acpi0: wakeup devices LID_(S4) SLPB(S3) IGBE(S4) EXP2(S4) XHCI(S3) EHC1(S3)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpihpet0 at acpi0: 14318179 Hz
acpiec0 at acpi0
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.49 MHz, 06-3d-04
cpu0: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
cpu1 at mainbus0: apid 1 (application processor)
cpu1: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.15 MHz, 06-3d-04
cpu1: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 1, core 0, package 0
cpu2 at mainbus0: apid 2 (application processor)
cpu2: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.16 MHz, 06-3d-04
cpu2: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu2: 256KB 64b/line 8-way L2 cache
cpu2: smt 0, core 1, package 0
cpu3 at mainbus0: apid 3 (application processor)
cpu3: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.15 MHz, 06-3d-04
cpu3: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu3: 256KB 64b/line 8-way L2 cache
cpu3: smt 1, core 1, package 0
ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 40 pins
acpimcfg0 at acpi0
acpimcfg0: addr 0xf8000000, bus 0-63
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus -1 (PEG_)
acpiprt2 at acpi0: bus 2 (EXP1)
acpiprt3 at acpi0: bus 3 (EXP2)
acpiprt4 at acpi0: bus -1 (EXP3)
acpicpu0 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu1 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu2 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu3 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpipwrres0 at acpi0: PUBS, resource for XHCI, EHC1
acpipwrres1 at acpi0: NVP3, resource for PEG_
acpipwrres2 at acpi0: NVP2, resource for PEG_
acpitz0 at acpi0: critical temperature is 128 degC
acpibtn0 at acpi0: LID_
acpibtn1 at acpi0: SLPB
acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
acpicmos0 at acpi0
acpibat0 at acpi0: BAT0 model "45N1111" serial 16669 type LiP oem "SONY"
acpibat1 at acpi0: BAT1 model "45N1777" serial  3056 type LION oem "SANYO"
acpiac0 at acpi0: AC unit online
acpithinkpad0 at acpi0
tpm0 at acpi0: TPM_ addr 0xfed40000/0x5000, device 0x0000104a rev 0x4e
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"INT340F" at acpi0 not configured
acpivideo0 at acpi0: VID_
acpivout at acpivideo0 not configured
acpivideo1 at acpi0: VID_
cpu0: using VERW MDS workaround
cpu0: Enhanced SpeedStep 2095 MHz: speeds: 2201, 2200, 2100, 2000, 1800, 1700, 1600, 1500, 1300, 1200, 1100, 1000, 900, 700, 600, 500 MHz
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel Core 5G Host" rev 0x09
inteldrm0 at pci0 dev 2 function 0 "Intel HD Graphics 5500" rev 0x09
drm0 at inteldrm0
inteldrm0: msi
azalia0 at pci0 dev 3 function 0 "Intel Core 5G HD Audio" rev 0x09: msi
azalia0: No codecs found
xhci0 at pci0 dev 20 function 0 "Intel 9 Series xHCI" rev 0x03: msi, xHCI 1.0
usb0 at xhci0: USB revision 3.0
uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev 3.00/1.00 addr 1
"Intel 9 Series MEI" rev 0x03 at pci0 dev 22 function 0 not configured
em0 at pci0 dev 25 function 0 "Intel I218-LM" rev 0x03: msi, address 50:7b:9d:11:24:e8
azalia1 at pci0 dev 27 function 0 "Intel 9 Series HD Audio" rev 0x03: msi
azalia1: codecs: Realtek ALC292
audio0 at azalia1
ppb0 at pci0 dev 28 function 0 "Intel 9 Series PCIE" rev 0xe3: msi
pci1 at ppb0 bus 2
rtsx0 at pci1 dev 0 function 0 "Realtek RTS5227 Card Reader" rev 0x01: msi
sdmmc0 at rtsx0: 4-bit, dma
ppb1 at pci0 dev 28 function 1 "Intel 9 Series PCIE" rev 0xe3: msi
pci2 at ppb1 bus 3
iwm0 at pci2 dev 0 function 0 "Intel Dual Band Wireless AC 7265" rev 0x59, msi
pcib0 at pci0 dev 31 function 0 "Intel 9 Series LPC" rev 0x03
ahci0 at pci0 dev 31 function 2 "Intel 9 Series AHCI" rev 0x03: msi, AHCI 1.3
ahci0: port 0: 6.0Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 0 lun 0: <ATA, Samsung SSD 850, EMT0> SCSI3 0/direct fixed naa.5002538d40242fcb
sd0: 476940MB, 512 bytes/sector, 976773168 sectors, thin
ichiic0 at pci0 dev 31 function 3 "Intel 9 Series SMBus" rev 0x03: apic 2 int 18
iic0 at ichiic0
pchtemp0 at pci0 dev 31 function 6 "Intel 9 Series Thermal" rev 0x03
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard
pms0 at pckbc0 (aux slot)
wsmouse0 at pms0 mux 0
wsmouse1 at pms0 mux 0
pms0: Synaptics clickpad, firmware 8.1, 0x1e2b1 0x943300
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: VMX/EPT
uhub1 at uhub0 port 3 configuration 1 interface 0 "LENOVO Lenovo ThinkPad Dock" rev 2.10/50.40 addr 2
uhidev0 at uhub1 port 2 configuration 1 interface 0 "Kensington Kensington Slimblade Trackball" rev 1.10/1.05 addr 3
uhidev0: iclass 3/1
ums0 at uhidev0: 5 buttons, Z dir
wsmouse2 at ums0 mux 0
uhidev1 at uhub1 port 3 configuration 1 interface 0 "Holtek USB Keyboard" rev 1.10/1.10 addr 4
uhidev1: iclass 3/1
ukbd0 at uhidev1: 8 variable keys, 6 key codes
wskbd1 at ukbd0 mux 1
uhidev2 at uhub1 port 3 configuration 1 interface 1 "Holtek USB Keyboard" rev 1.10/1.10 addr 4
uhidev2: iclass 3/1, 2 report ids
uhid0 at uhidev2 reportid 1: input=6, output=0, feature=0
uhid1 at uhidev2 reportid 2: input=1, output=0, feature=0
uhub2 at uhub1 port 4 configuration 1 interface 0 "Lenovo Lenovo ThinkPad Dock" rev 2.00/0.01 addr 5
ugen0 at uhub0 port 5 "Generic EMV Smartcard Reader" rev 2.01/1.20 addr 6
usbd_free_xfer: xfer=0xfffffd824d8555a0 not free
ugen0: setting configuration index 0 failed
ugen1 at uhub0 port 6 "Validity Sensors VFS5011 Fingerprint Reader" rev 1.10/0.78 addr 7
ugen2 at uhub0 port 7 "Intel Bluetooth" rev 2.01/0.01 addr 8
uhub3 at uhub0 port 14 configuration 1 interface 0 "LENOVO Lenovo ThinkPad Dock" rev 3.00/50.41 addr 9
vscsi0 at root
scsibus2 at vscsi0: 256 targets
softraid0 at root
scsibus3 at softraid0: 256 targets
sd1 at scsibus3 targ 1 lun 0: <OPENBSD, SR CRYPTO, 006> SCSI2 0/direct fixed
sd1: 409599MB, 512 bytes/sector, 838860209 sectors
root on sd1a (1aebccd650f38400.a) swap on sd1b dump on sd1b
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005c5800
[drm] Allocated atomic state 0xffff8000005d6000
[drm] Added [CRTC:39:pipe ] 0xffff8000005d6800 state to 0xffff8000005d6000
[drm] Added [CRTC:51:pipe ] 0xffff8000005d7000 state to 0xffff8000005d6000
[drm] Added [CRTC:63:pipe ] 0xffff8000005d7800 state to 0xffff8000005d6000
[drm] Added [PLANE:28:primary ] 0xffff8000005cd600 state to 0xffff8000005d6000
[drm] Added [PLANE:31:sprite ] 0xffff8000005cd700 state to 0xffff8000005d6000
[drm] Added [PLANE:36:cursor ] 0xffff8000005cd800 state to 0xffff8000005d6000
[drm] Added [PLANE:40:primary ] 0xffff8000005cd900 state to 0xffff8000005d6000
[drm] Added [PLANE:43:sprite ] 0xffff8000005cda00 state to 0xffff8000005d6000
[drm] Added [PLANE:48:cursor ] 0xffff8000005cdb00 state to 0xffff8000005d6000
[drm] Added [PLANE:52:primary ] 0xffff8000005cdc00 state to 0xffff8000005d6000
[drm] Added [PLANE:55:sprite ] 0xffff8000005cdd00 state to 0xffff8000005d6000
[drm] Added [PLANE:60:cursor ] 0xffff8000005cde00 state to 0xffff8000005d6000
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005c8a00 state to 0xffff8000005d6000
[drm] Added [CONNECTOR:72:DP-] 0xffff8000005c8780 state to 0xffff8000005d6000
[drm] Added [CONNECTOR:78:HDMI-A-] 0xffff8000005c8980 state to 0xffff8000005d6000
[drm] Added [CONNECTOR:83:DP-] 0xffff8000005c8700 state to 0xffff8000005d6000
[drm] Added [CONNECTOR:88:HDMI-A-] 0xffff8000005d8000 state to 0xffff8000005d6000
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:72:DP-]
[drm] Disabling [CONNECTOR:72:DP-]
[drm] Updating routing for [CONNECTOR:78:HDMI-A-]
[drm] Disabling [CONNECTOR:78:HDMI-A-]
[drm] Updating routing for [CONNECTOR:83:DP-]
[drm] Disabling [CONNECTOR:83:DP-]
[drm] Updating routing for [CONNECTOR:88:HDMI-A-]
[drm] Disabling [CONNECTOR:88:HDMI-A-]
[drm] Clearing atomic state 0xffff8000005d6000
[drm] Freeing atomic state 0xffff8000005d6000
inteldrm0: 1920x1080, 32bpp
[drm] Allocated atomic state 0xffff8000005d6800
[drm] Added [PLANE:28:primary ] 0xffff8000005cdc00 state to 0xffff8000005d6800
[drm] Added [PLANE:31:sprite ] 0xffff8000005cdd00 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff8000005cdd00
[drm] Added [PLANE:36:cursor ] 0xffff8000005cd200 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff8000005cd200
[drm] Added [PLANE:40:primary ] 0xffff8000005cd500 state to 0xffff8000005d6800
[drm] Added [PLANE:43:sprite ] 0xffff8000005f1000 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff8000005f1000
[drm] Added [PLANE:48:cursor ] 0xffff8000005f1100 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff8000005f1100
[drm] Added [PLANE:52:primary ] 0xffff8000005f1200 state to 0xffff8000005d6800
[drm] Added [PLANE:55:sprite ] 0xffff8000005f1300 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff8000005f1300
[drm] Added [PLANE:60:cursor ] 0xffff8000005f1400 state to 0xffff8000005d6800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff8000005f1400
[drm] Added [CRTC:39:pipe ] 0xffff8000005d7000 state to 0xffff8000005d6800
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005d7000
[drm] Link [PLANE:28:primary ] state 0xffff8000005cdc00 to [CRTC:39:pipe ]
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff8000005cdc00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005d6800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005d8f80 state to 0xffff8000005d6800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005d8f80 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005d8f80 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff8000005d7800 state to 0xffff8000005d6800
[drm] Set [NOMODE] for [CRTC:51:pipe ] state 0xffff8000005d7800
[drm] Set [NOFB] for [PLANE:40:primary ] state 0xffff8000005cd500
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff8000005d6800
[drm] Added [CRTC:63:pipe ] 0xffff8000005d6000 state to 0xffff8000005d6800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff8000005d6000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff8000005f1200
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff8000005d6800
[drm] checking 0xffff8000005d6800
[drm] [CRTC:39:pipe ] mode changed
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] [CRTC:39:pipe ] needs all connectors, enable: y, active: y
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005d6800
[drm] Adding all current planes for [CRTC:39:pipe ] to 0xffff8000005d6800
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 0 -> 1, off 0, on 1, ms 1
[drm] committing 0xffff8000005d6800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff8000005d6800)
[drm] XXX drm_atomic_helper_swap_state(0xffff8000005d6800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff8000005d6800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff8000005d6800)
wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
wskbd1: connecting to wsdisplay0
wsdisplay0: screen 1-5 added (std, vt100 emulation)
[drm] Allocated atomic state 0xffff800000964000
[drm] Added [PLANE:28:primary ] 0xffff800000963900 state to 0xffff800000964000
[drm] Added [CRTC:39:pipe ] 0xffff800000964800 state to 0xffff800000964000
[drm] Added [PLANE:31:sprite ] 0xffff800000963b00 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000963b00
[drm] Added [PLANE:36:cursor ] 0xffff800000963d00 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000963d00
[drm] Added [PLANE:40:primary ] 0xffff80000083a400 state to 0xffff800000964000
[drm] Added [PLANE:43:sprite ] 0xffff80000083a600 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff80000083a600
[drm] Added [PLANE:48:cursor ] 0xffff80000083aa00 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff80000083aa00
[drm] Added [PLANE:52:primary ] 0xffff800000962300 state to 0xffff800000964000
[drm] Added [PLANE:55:sprite ] 0xffff800000962700 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000962700
[drm] Added [PLANE:60:cursor ] 0xffff800000962800 state to 0xffff800000964000
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff800000962800
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff800000964800
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000963900
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000964000
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000006b6700 state to 0xffff800000964000
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000006b6700 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000006b6700 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff800000965000 state to 0xffff800000964000
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff800000965000
[drm] Link [PLANE:40:primary ] state 0xffff80000083a400 to [CRTC:51:pipe ]
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff80000083a400
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000964000
[drm] Added [CONNECTOR:94:DP-] 0xffff8000006b6780 state to 0xffff800000964000
[drm] Link [CONNECTOR:94:DP-] state 0xffff8000006b6780 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff800000965800 state to 0xffff800000964000
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff800000965800
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000962300
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff800000964000
[drm] checking 0xffff800000964000
[drm] [CRTC:51:pipe ] mode changed
[drm] [CRTC:51:pipe ] enable changed
[drm] [CRTC:51:pipe ] active changed
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] using [ENCODER:85:DP-MST ] on [CRTC:51:pipe ]
[drm] [CRTC:51:pipe ] needs all connectors, enable: y, active: y
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000964000
[drm] Adding all current planes for [CRTC:51:pipe ] to 0xffff800000964000
[drm] Added new private object 0xffff8000005d4448 state 0xffff80000014a4e0 to 0xffff800000964000
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000964000
[drm] Adding all current planes for [CRTC:39:pipe ] to 0xffff800000964000
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 1, on 1, ms 1
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 0 -> 1, off 0, on 1, ms 1
[drm] committing 0xffff800000964000
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff800000964000)
[drm] XXX drm_atomic_helper_swap_state(0xffff800000964000, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff800000964000)
iwm0: hw rev 0x210, fw ver 16.242414.0, address 94:65:9c:46:8a:f2
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff800000964000)
[drm] Allocated atomic state 0xffff80000096a800
[drm] Added [PLANE:28:primary ] 0xffff80000083a100 state to 0xffff80000096a800
[drm] Added [CRTC:39:pipe ] 0xffff80000096e000 state to 0xffff80000096a800
[drm] Added [PLANE:31:sprite ] 0xffff80000096b000 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff80000096b000
[drm] Added [PLANE:36:cursor ] 0xffff80000096b200 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff80000096b200
[drm] Added [PLANE:40:primary ] 0xffff80000096b300 state to 0xffff80000096a800
[drm] Added [CRTC:51:pipe ] 0xffff80000096e800 state to 0xffff80000096a800
[drm] Added [PLANE:43:sprite ] 0xffff80000096b400 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff80000096b400
[drm] Added [PLANE:48:cursor ] 0xffff80000096b600 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff80000096b600
[drm] Added [PLANE:52:primary ] 0xffff80000096b700 state to 0xffff80000096a800
[drm] Added [PLANE:55:sprite ] 0xffff80000096b800 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff80000096b800
[drm] Added [PLANE:60:cursor ] 0xffff80000096b900 state to 0xffff80000096a800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff80000096b900
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff80000096e000
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff80000083a100
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff80000096a800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000006b6c00 state to 0xffff80000096a800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000006b6c00 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000006b6c00 to [CRTC:39:pipe ]
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff80000096e800
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff80000096b300
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff80000096a800
[drm] Added [CONNECTOR:94:DP-] 0xffff8000006b6680 state to 0xffff80000096a800
[drm] Link [CONNECTOR:94:DP-] state 0xffff8000006b6680 to [NOCRTC]
[drm] Link [CONNECTOR:94:DP-] state 0xffff8000006b6680 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff80000096f000 state to 0xffff80000096a800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff80000096f000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff80000096b700
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff80000096a800
[drm] checking 0xffff80000096a800
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] keeps [ENCODER:85:DP-MST ], now on [CRTC:51:pipe ]
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff80000096a800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff80000096a800)
[drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
[drm] XXX drm_atomic_helper_swap_state(0xffff80000096a800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff80000096a800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff80000096a800)
[drm] Allocated atomic state 0xffff800000c1f800
[drm] Added [PLANE:28:primary ] 0xffff800000c3ea00 state to 0xffff800000c1f800
[drm] Added [CRTC:39:pipe ] 0xffff800000c3f000 state to 0xffff800000c1f800
[drm] Added [PLANE:31:sprite ] 0xffff800000c3eb00 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000c3eb00
[drm] Added [PLANE:36:cursor ] 0xffff800000c3ec00 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000c3ec00
[drm] Added [PLANE:40:primary ] 0xffff800000c3ed00 state to 0xffff800000c1f800
[drm] Added [CRTC:51:pipe ] 0xffff800000c3f800 state to 0xffff800000c1f800
[drm] Added [PLANE:43:sprite ] 0xffff800000c3ee00 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff800000c3ee00
[drm] Added [PLANE:48:cursor ] 0xffff800000c3ef00 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000c3ef00
[drm] Added [PLANE:52:primary ] 0xffff800000c14e00 state to 0xffff800000c1f800
[drm] Added [PLANE:55:sprite ] 0xffff800000c14400 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000c14400
[drm] Added [PLANE:60:cursor ] 0xffff800000c14600 state to 0xffff800000c1f800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff800000c14600
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff800000c3f000
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000c3ea00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000c1f800
[drm] Added [CONNECTOR:65:eDP-] 0xffff800000bbfe00 state to 0xffff800000c1f800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000bbfe00 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000bbfe00 to [CRTC:39:pipe ]
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff800000c3f800
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff800000c3ed00
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000c1f800
[drm] Added [CONNECTOR:94:DP-] 0xffff800000c20c00 state to 0xffff800000c1f800
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c20c00 to [NOCRTC]
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c20c00 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff800000c40000 state to 0xffff800000c1f800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff800000c40000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000c14e00
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff800000c1f800
[drm] checking 0xffff800000c1f800
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] keeps [ENCODER:85:DP-MST ], now on [CRTC:51:pipe ]
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff800000c1f800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff800000c1f800)
[drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
[drm] XXX drm_atomic_helper_swap_state(0xffff800000c1f800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff800000c1f800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff800000c1f800)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff8000005d6800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff8000005d6800)
[drm] Clearing atomic state 0xffff8000005d6800
[drm] Freeing atomic state 0xffff8000005d6800
[drm] Allocated atomic state 0xffff800000c40800
[drm] Added [PLANE:28:primary ] 0xffff8000005cdb00 state to 0xffff800000c40800
[drm] Added [CRTC:39:pipe ] 0xffff8000005c5800 state to 0xffff800000c40800
[drm] Added [PLANE:31:sprite ] 0xffff800000c14b00 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000c14b00
[drm] Added [PLANE:36:cursor ] 0xffff800000c3c600 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000c3c600
[drm] Added [PLANE:40:primary ] 0xffff800000c3c700 state to 0xffff800000c40800
[drm] Added [CRTC:51:pipe ] 0xffff8000005ca000 state to 0xffff800000c40800
[drm] Added [PLANE:43:sprite ] 0xffff800000c3c900 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff800000c3c900
[drm] Added [PLANE:48:cursor ] 0xffff800000c3cc00 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000c3cc00
[drm] Added [PLANE:52:primary ] 0xffff800000c3cd00 state to 0xffff800000c40800
[drm] Added [PLANE:55:sprite ] 0xffff800000c3d000 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000c3d000
[drm] Added [PLANE:60:cursor ] 0xffff800000c3d200 state to 0xffff800000c40800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff800000c3d200
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005c5800
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff8000005cdb00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000c40800
[drm] Added [CONNECTOR:65:eDP-] 0xffff800000c20600 state to 0xffff800000c40800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000c20600 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000c20600 to [CRTC:39:pipe ]
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff8000005ca000
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff800000c3c700
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000c40800
[drm] Added [CONNECTOR:94:DP-] 0xffff800000c20900 state to 0xffff800000c40800
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c20900 to [NOCRTC]
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c20900 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff8000005cc800 state to 0xffff800000c40800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000c3cd00
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff800000c40800
[drm] checking 0xffff800000c40800
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] keeps [ENCODER:85:DP-MST ], now on [CRTC:51:pipe ]
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff800000c40800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff800000c40800)
[drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
[drm] XXX drm_atomic_helper_swap_state(0xffff800000c40800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff800000c40800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff800000c40800)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff800000964000)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff800000964000)
[drm] Clearing atomic state 0xffff800000964000
[drm] Freeing atomic state 0xffff800000964000
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff80000096a800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff80000096a800)
[drm] Clearing atomic state 0xffff80000096a800
[drm] Freeing atomic state 0xffff80000096a800
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff800000c1f800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff800000c1f800)
[drm] Clearing atomic state 0xffff800000c1f800
[drm] Freeing atomic state 0xffff800000c1f800
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff800000c40800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff800000c40800)
[drm] Clearing atomic state 0xffff800000c40800
[drm] Freeing atomic state 0xffff800000c40800

dmesg (no external display):
OpenBSD 6.5-current (GENERIC.MP) #6: Fri May 24 15:08:19 CEST 2019
    [hidden email]:/sys/arch/amd64/compile/GENERIC.MP
real mem = 8277159936 (7893MB)
avail mem = 8011235328 (7640MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.7 @ 0xacbfd000 (65 entries)
bios0: vendor LENOVO version "N10ET36W (1.15 )" date 06/19/2015
bios0: LENOVO 20CLS2LK00
acpi0 at bios0: rev 2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP ASF! HPET ECDT APIC MCFG SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT PCCT SSDT TCPA SSDT UEFI POAT BATB FPDT UEFI DMAR
acpi0: wakeup devices LID_(S4) SLPB(S3) IGBE(S4) EXP2(S4) XHCI(S3) EHC1(S3)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpihpet0 at acpi0: 14318179 Hz
acpiec0 at acpi0
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 798.28 MHz, 06-3d-04
cpu0: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
cpu1 at mainbus0: apid 1 (application processor)
cpu1: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 798.16 MHz, 06-3d-04
cpu1: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 1, core 0, package 0
cpu2 at mainbus0: apid 2 (application processor)
cpu2: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 798.16 MHz, 06-3d-04
cpu2: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu2: 256KB 64b/line 8-way L2 cache
cpu2: smt 0, core 1, package 0
cpu3 at mainbus0: apid 3 (application processor)
cpu3: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 798.16 MHz, 06-3d-04
cpu3: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu3: 256KB 64b/line 8-way L2 cache
cpu3: smt 1, core 1, package 0
ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 40 pins
acpimcfg0 at acpi0
acpimcfg0: addr 0xf8000000, bus 0-63
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus -1 (PEG_)
acpiprt2 at acpi0: bus 2 (EXP1)
acpiprt3 at acpi0: bus 3 (EXP2)
acpiprt4 at acpi0: bus -1 (EXP3)
acpicpu0 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu1 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu2 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu3 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpipwrres0 at acpi0: PUBS, resource for XHCI, EHC1
acpipwrres1 at acpi0: NVP3, resource for PEG_
acpipwrres2 at acpi0: NVP2, resource for PEG_
acpitz0 at acpi0: critical temperature is 128 degC
acpibtn0 at acpi0: LID_
acpibtn1 at acpi0: SLPB
acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
acpicmos0 at acpi0
acpibat0 at acpi0: BAT0 model "45N1111" serial 16669 type LiP oem "SONY"
acpibat1 at acpi0: BAT1 model "45N1777" serial  3056 type LION oem "SANYO"
acpiac0 at acpi0: AC unit offline
acpithinkpad0 at acpi0
tpm0 at acpi0: TPM_ addr 0xfed40000/0x5000, device 0x0000104a rev 0x4e
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"INT340F" at acpi0 not configured
acpivideo0 at acpi0: VID_
acpivout at acpivideo0 not configured
acpivideo1 at acpi0: VID_
cpu0: using VERW MDS workaround
cpu0: Enhanced SpeedStep 798 MHz: speeds: 2201, 2200, 2100, 2000, 1800, 1700, 1600, 1500, 1300, 1200, 1100, 1000, 900, 700, 600, 500 MHz
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel Core 5G Host" rev 0x09
inteldrm0 at pci0 dev 2 function 0 "Intel HD Graphics 5500" rev 0x09
drm0 at inteldrm0
inteldrm0: msi
azalia0 at pci0 dev 3 function 0 "Intel Core 5G HD Audio" rev 0x09: msi
azalia0: No codecs found
xhci0 at pci0 dev 20 function 0 "Intel 9 Series xHCI" rev 0x03: msi, xHCI 1.0
usb0 at xhci0: USB revision 3.0
uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev 3.00/1.00 addr 1
"Intel 9 Series MEI" rev 0x03 at pci0 dev 22 function 0 not configured
em0 at pci0 dev 25 function 0 "Intel I218-LM" rev 0x03: msi, address 50:7b:9d:11:24:e8
azalia1 at pci0 dev 27 function 0 "Intel 9 Series HD Audio" rev 0x03: msi
azalia1: codecs: Realtek ALC292
audio0 at azalia1
ppb0 at pci0 dev 28 function 0 "Intel 9 Series PCIE" rev 0xe3: msi
pci1 at ppb0 bus 2
rtsx0 at pci1 dev 0 function 0 "Realtek RTS5227 Card Reader" rev 0x01: msi
sdmmc0 at rtsx0: 4-bit, dma
ppb1 at pci0 dev 28 function 1 "Intel 9 Series PCIE" rev 0xe3: msi
pci2 at ppb1 bus 3
iwm0 at pci2 dev 0 function 0 "Intel Dual Band Wireless AC 7265" rev 0x59, msi
pcib0 at pci0 dev 31 function 0 "Intel 9 Series LPC" rev 0x03
ahci0 at pci0 dev 31 function 2 "Intel 9 Series AHCI" rev 0x03: msi, AHCI 1.3
ahci0: port 0: 6.0Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 0 lun 0: <ATA, Samsung SSD 850, EMT0> SCSI3 0/direct fixed naa.5002538d40242fcb
sd0: 476940MB, 512 bytes/sector, 976773168 sectors, thin
ichiic0 at pci0 dev 31 function 3 "Intel 9 Series SMBus" rev 0x03: apic 2 int 18
iic0 at ichiic0
pchtemp0 at pci0 dev 31 function 6 "Intel 9 Series Thermal" rev 0x03
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard
pms0 at pckbc0 (aux slot)
wsmouse0 at pms0 mux 0
wsmouse1 at pms0 mux 0
pms0: Synaptics clickpad, firmware 8.1, 0x1e2b1 0x943300
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: VMX/EPT
ugen0 at uhub0 port 5 "Generic EMV Smartcard Reader" rev 2.01/1.20 addr 2
ugen1 at uhub0 port 6 "Validity Sensors VFS5011 Fingerprint Reader" rev 1.10/0.78 addr 3
ugen2 at uhub0 port 7 "Intel Bluetooth" rev 2.01/0.01 addr 4
vscsi0 at root
scsibus2 at vscsi0: 256 targets
softraid0 at root
scsibus3 at softraid0: 256 targets
sd1 at scsibus3 targ 1 lun 0: <OPENBSD, SR CRYPTO, 006> SCSI2 0/direct fixed
sd1: 409599MB, 512 bytes/sector, 838860209 sectors
root on sd1a (1aebccd650f38400.a) swap on sd1b dump on sd1b
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005bb000
[drm] Allocated atomic state 0xffff8000005ca800
[drm] Added [CRTC:39:pipe ] 0xffff8000005cb000 state to 0xffff8000005ca800
[drm] Added [CRTC:51:pipe ] 0xffff8000005cb800 state to 0xffff8000005ca800
[drm] Added [CRTC:63:pipe ] 0xffff8000005cc000 state to 0xffff8000005ca800
[drm] Added [PLANE:28:primary ] 0xffff8000005c2900 state to 0xffff8000005ca800
[drm] Added [PLANE:31:sprite ] 0xffff8000005c2a00 state to 0xffff8000005ca800
[drm] Added [PLANE:36:cursor ] 0xffff8000005c2b00 state to 0xffff8000005ca800
[drm] Added [PLANE:40:primary ] 0xffff8000005c2c00 state to 0xffff8000005ca800
[drm] Added [PLANE:43:sprite ] 0xffff8000005c2d00 state to 0xffff8000005ca800
[drm] Added [PLANE:48:cursor ] 0xffff8000005c2e00 state to 0xffff8000005ca800
[drm] Added [PLANE:52:primary ] 0xffff8000005c2f00 state to 0xffff8000005ca800
[drm] Added [PLANE:55:sprite ] 0xffff8000005cd000 state to 0xffff8000005ca800
[drm] Added [PLANE:60:cursor ] 0xffff8000005cd100 state to 0xffff8000005ca800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005bea00 state to 0xffff8000005ca800
[drm] Added [CONNECTOR:72:DP-] 0xffff8000005bea80 state to 0xffff8000005ca800
[drm] Added [CONNECTOR:78:HDMI-A-] 0xffff8000005bec00 state to 0xffff8000005ca800
[drm] Added [CONNECTOR:83:DP-] 0xffff8000005be880 state to 0xffff8000005ca800
[drm] Added [CONNECTOR:88:HDMI-A-] 0xffff8000005bec80 state to 0xffff8000005ca800
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:72:DP-]
[drm] Disabling [CONNECTOR:72:DP-]
[drm] Updating routing for [CONNECTOR:78:HDMI-A-]
[drm] Disabling [CONNECTOR:78:HDMI-A-]
[drm] Updating routing for [CONNECTOR:83:DP-]
[drm] Disabling [CONNECTOR:83:DP-]
[drm] Updating routing for [CONNECTOR:88:HDMI-A-]
[drm] Disabling [CONNECTOR:88:HDMI-A-]
[drm] Clearing atomic state 0xffff8000005ca800
[drm] Freeing atomic state 0xffff8000005ca800
inteldrm0: 1920x1080, 32bpp
[drm] Allocated atomic state 0xffff8000005cc800
[drm] Added [PLANE:28:primary ] 0xffff8000005c2900 state to 0xffff8000005cc800
[drm] Added [PLANE:31:sprite ] 0xffff8000005c2a00 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff8000005c2a00
[drm] Added [PLANE:36:cursor ] 0xffff8000005c2b00 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff8000005c2b00
[drm] Added [PLANE:40:primary ] 0xffff8000005c2c00 state to 0xffff8000005cc800
[drm] Added [PLANE:43:sprite ] 0xffff8000005c2d00 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff8000005c2d00
[drm] Added [PLANE:48:cursor ] 0xffff8000005c2e00 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff8000005c2e00
[drm] Added [PLANE:52:primary ] 0xffff8000005c2f00 state to 0xffff8000005cc800
[drm] Added [PLANE:55:sprite ] 0xffff8000005cd000 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff8000005cd000
[drm] Added [PLANE:60:cursor ] 0xffff8000005cd100 state to 0xffff8000005cc800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff8000005cd100
[drm] Added [CRTC:39:pipe ] 0xffff8000005cb000 state to 0xffff8000005cc800
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005cb000
[drm] Link [PLANE:28:primary ] state 0xffff8000005c2900 to [CRTC:39:pipe ]
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff8000005c2900
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005cc800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005d3b00 state to 0xffff8000005cc800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005d3b00 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005d3b00 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff8000005cb800 state to 0xffff8000005cc800
[drm] Set [NOMODE] for [CRTC:51:pipe ] state 0xffff8000005cb800
[drm] Set [NOFB] for [PLANE:40:primary ] state 0xffff8000005c2c00
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff8000005cc800
[drm] Added [CRTC:63:pipe ] 0xffff8000005cc000 state to 0xffff8000005cc800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff8000005cc000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff8000005c2f00
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff8000005cc800
[drm] checking 0xffff8000005cc800
[drm] [CRTC:39:pipe ] mode changed
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] [CRTC:39:pipe ] needs all connectors, enable: y, active: y
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005cc800
[drm] Adding all current planes for [CRTC:39:pipe ] to 0xffff8000005cc800
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 0 -> 1, off 0, on 1, ms 1
[drm] committing 0xffff8000005cc800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff8000005cc800)
[drm] XXX drm_atomic_helper_swap_state(0xffff8000005cc800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff8000005cc800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff8000005cc800)
wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
wsdisplay0: screen 1-5 added (std, vt100 emulation)
[drm] Allocated atomic state 0xffff8000005ca800
[drm] Added [PLANE:28:primary ] 0xffff800000767700 state to 0xffff8000005ca800
[drm] Added [CRTC:39:pipe ] 0xffff800000832000 state to 0xffff8000005ca800
[drm] Added [PLANE:31:sprite ] 0xffff800000767800 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000767800
[drm] Added [PLANE:36:cursor ] 0xffff800000767900 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000767900
[drm] Added [PLANE:40:primary ] 0xffff800000767a00 state to 0xffff8000005ca800
[drm] Added [PLANE:43:sprite ] 0xffff800000767b00 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff800000767b00
[drm] Added [PLANE:48:cursor ] 0xffff800000767c00 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000767c00
[drm] Added [PLANE:52:primary ] 0xffff800000767d00 state to 0xffff8000005ca800
[drm] Added [PLANE:55:sprite ] 0xffff800000767e00 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000767e00
[drm] Added [PLANE:60:cursor ] 0xffff800000767f00 state to 0xffff8000005ca800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff800000767f00
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff800000832000
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000767700
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005ca800
[drm] Added [CONNECTOR:65:eDP-] 0xffff80000082b200 state to 0xffff8000005ca800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff80000082b200 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff80000082b200 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff800000832800 state to 0xffff8000005ca800
[drm] Set [NOMODE] for [CRTC:51:pipe ] state 0xffff800000832800
[drm] Set [NOFB] for [PLANE:40:primary ] state 0xffff800000767a00
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff8000005ca800
[drm] Added [CRTC:63:pipe ] 0xffff800000833000 state to 0xffff8000005ca800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff800000833000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000767d00
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff8000005ca800
[drm] checking 0xffff8000005ca800
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff8000005ca800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff8000005ca800)
[drm] XXX drm_atomic_helper_swap_state(0xffff8000005ca800, true)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff8000005ca800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff8000005ca800)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff8000005cc800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff8000005cc800)
[drm] Clearing atomic state 0xffff8000005cc800
[drm] Freeing atomic state 0xffff8000005cc800
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff8000005ca800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff8000005ca800)
[drm] Clearing atomic state 0xffff8000005ca800
[drm] Freeing atomic state 0xffff8000005ca800
iwm0: hw rev 0x210, fw ver 16.242414.0, address 94:65:9c:46:8a:f2

kernel diff:
Index: dev/pci/drm/drm_atomic_helper.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/drm_atomic_helper.c,v
retrieving revision 1.2
diff -u -p -r1.2 drm_atomic_helper.c
--- dev/pci/drm/drm_atomic_helper.c 14 Apr 2019 10:14:51 -0000 1.2
+++ dev/pci/drm/drm_atomic_helper.c 24 May 2019 17:11:47 -0000
@@ -2024,6 +2024,8 @@ void drm_atomic_helper_wait_for_dependen
  int i;
  long ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_wait_for_dependencies(%p)\n", old_state);
+
  for_each_old_crtc_in_state(old_state, crtc, old_crtc_state, i) {
  commit = old_crtc_state->commit;
 
@@ -2150,6 +2152,8 @@ void drm_atomic_helper_commit_hw_done(st
  struct drm_crtc_commit *commit;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_hw_done(%p)\n", old_state);
+
  for_each_oldnew_crtc_in_state(old_state, crtc, old_crtc_state, new_crtc_state, i) {
  commit = new_crtc_state->commit;
  if (!commit)
@@ -2195,6 +2199,8 @@ void drm_atomic_helper_commit_cleanup_do
  struct drm_crtc_commit *commit;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_cleanup_done(%p)\n", old_state);
+
  for_each_old_crtc_in_state(old_state, crtc, old_crtc_state, i) {
  commit = old_crtc_state->commit;
  if (WARN_ON(!commit))
@@ -2233,6 +2239,8 @@ int drm_atomic_helper_prepare_planes(str
  struct drm_plane_state *new_plane_state;
  int ret, i, j;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_prepare_planes(dev, %p)\n", state);
+
  for_each_new_plane_in_state(state, plane, new_plane_state, i) {
  const struct drm_plane_helper_funcs *funcs;
 
@@ -2322,6 +2330,8 @@ void drm_atomic_helper_commit_planes(str
  bool active_only = flags & DRM_PLANE_COMMIT_ACTIVE_ONLY;
  bool no_disable = flags & DRM_PLANE_COMMIT_NO_DISABLE_AFTER_MODESET;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_planes(dev, %p, flags)\n", old_state);
+
  for_each_oldnew_crtc_in_state(old_state, crtc, old_crtc_state, new_crtc_state, i) {
  const struct drm_crtc_helper_funcs *funcs;
 
@@ -2523,6 +2533,8 @@ void drm_atomic_helper_cleanup_planes(st
  struct drm_plane_state *old_plane_state, *new_plane_state;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_cleanup_planes(dev, %p)\n", old_state);
+
  for_each_oldnew_plane_in_state(old_state, plane, old_plane_state, new_plane_state, i) {
  const struct drm_plane_helper_funcs *funcs;
  struct drm_plane_state *plane_state;
@@ -2592,6 +2604,8 @@ int drm_atomic_helper_swap_state(struct
  struct drm_crtc_commit *commit;
  struct drm_private_obj *obj;
  struct drm_private_state *old_obj_state, *new_obj_state;
+
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_swap_state(%p, %s)\n", state, stall?"true":"false");
 
  if (stall) {
  /*
Index: dev/pci/drm/i915/intel_display.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
retrieving revision 1.63
diff -u -p -r1.63 intel_display.c
--- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
+++ dev/pci/drm/i915/intel_display.c 24 May 2019 17:14:55 -0000
@@ -12873,8 +12873,11 @@ static int intel_atomic_commit(struct dr
  ret = drm_atomic_helper_setup_commit(state, nonblock);
  if (!ret)
  ret = drm_atomic_helper_swap_state(state, true);
+    else
+ DRM_DEBUG_ATOMIC("Setting up commit failed with %i\n", ret);
 
  if (ret) {
+ DRM_DEBUG_ATOMIC("State swap failed with %i\n", ret);
  i915_sw_fence_commit(&intel_state->commit_ready);
 
  drm_atomic_helper_cleanup_planes(dev, state);
Index: dev/pci/drm/include/drm/drmP.h
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/include/drm/drmP.h,v
retrieving revision 1.2
diff -u -p -r1.2 drmP.h
--- dev/pci/drm/include/drm/drmP.h 4 May 2019 11:34:48 -0000 1.2
+++ dev/pci/drm/include/drm/drmP.h 24 May 2019 17:14:55 -0000
@@ -126,7 +126,7 @@ struct fb_fillrect;
 struct fb_copyarea;
 struct fb_image;
 
-#define drm_debug 0
+#define drm_debug DRM_UT_ATOMIC
 
  /* Internal types and structures */
 #define DRM_IF_VERSION(maj, min) (maj << 16 | min)

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
Sven M. Hallberg on Fri, May 24 2019:
>>Fix:
> ?

I discovered the immediate culprit to be these lines in
/sys/dev/pci/drm/i915/intel_display.c:

    static void intel_atomic_commit_tail(struct drm_atomic_state *state)
    {
        ...

        /*    
         * Defer the cleanup of the old state to a separate worker to not
         * impede the current task (userspace for blocking modesets) that
         * are executed inline. For out-of-line asynchronous modesets/flips,
         * deferring to a new worker seems overkill, but we would place a
         * schedule point (cond_resched()) here anyway to keep latencies
         * down.
         */    
        INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
        schedule_work(&state->commit_work);
    }

The comment seems to indicate that the cleanup work is expected to be
performed (almost) immediately as if called directly. So, as a
workaround, replacing the last line with the direct call

        intel_atomic_cleanup_work(&state->commit_work);

makes things work fine for me.

As for when and why the scheduled tasks do or don't run, my best theory
is that there is a subtle difference between Linux workqueues and BSD
taskqs (which are used to emulate the former here).
Also, the "commits" where cleanup is delayed happen to be those which
perform actual modesetting. This could of course be pure coincidence.

I'm attaching a more verbose and slightly commented dmesg as well as the
kernel diff used to produce it.


OpenBSD 6.5-current (GENERIC.MP) #8: Mon May 27 19:49:16 CEST 2019
    [hidden email]:/sys/arch/amd64/compile/GENERIC.MP
real mem = 8277159936 (7893MB)
avail mem = 8011235328 (7640MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.7 @ 0xacbfd000 (65 entries)
bios0: vendor LENOVO version "N10ET36W (1.15 )" date 06/19/2015
bios0: LENOVO 20CLS2LK00
acpi0 at bios0: rev 2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP ASF! HPET ECDT APIC MCFG SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT SSDT PCCT SSDT TCPA SSDT UEFI POAT BATB FPDT UEFI DMAR
acpi0: wakeup devices LID_(S4) SLPB(S3) IGBE(S4) EXP2(S4) XHCI(S3) EHC1(S3)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpihpet0 at acpi0: 14318179 Hz
acpiec0 at acpi0
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.43 MHz, 06-3d-04
cpu0: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
cpu1 at mainbus0: apid 1 (application processor)
cpu1: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.16 MHz, 06-3d-04
cpu1: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 1, core 0, package 0
cpu2 at mainbus0: apid 2 (application processor)
cpu2: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.16 MHz, 06-3d-04
cpu2: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu2: 256KB 64b/line 8-way L2 cache
cpu2: smt 0, core 1, package 0
cpu3 at mainbus0: apid 3 (application processor)
cpu3: Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz, 2095.15 MHz, 06-3d-04
cpu3: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,RDSEED,ADX,SMAP,PT,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,MELTDOWN
cpu3: 256KB 64b/line 8-way L2 cache
cpu3: smt 1, core 1, package 0
ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 40 pins
acpimcfg0 at acpi0
acpimcfg0: addr 0xf8000000, bus 0-63
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus -1 (PEG_)
acpiprt2 at acpi0: bus 2 (EXP1)
acpiprt3 at acpi0: bus 3 (EXP2)
acpiprt4 at acpi0: bus -1 (EXP3)
acpicpu0 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu1 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu2 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpicpu3 at acpi0: C3(200@233 mwait.1@0x40), C2(200@148 mwait.1@0x33), C1(1000@1 mwait.1), PSS
acpipwrres0 at acpi0: PUBS, resource for XHCI, EHC1
acpipwrres1 at acpi0: NVP3, resource for PEG_
acpipwrres2 at acpi0: NVP2, resource for PEG_
acpitz0 at acpi0: critical temperature is 128 degC
acpibtn0 at acpi0: LID_
acpibtn1 at acpi0: SLPB
acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
acpicmos0 at acpi0
acpibat0 at acpi0: BAT0 model "45N1111" serial 16669 type LiP oem "SONY"
acpibat1 at acpi0: BAT1 model "45N1777" serial  3056 type LION oem "SANYO"
acpiac0 at acpi0: AC unit online
acpithinkpad0 at acpi0
tpm0 at acpi0: TPM_ addr 0xfed40000/0x5000, device 0x0000104a rev 0x4e
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"INT340F" at acpi0 not configured
acpivideo0 at acpi0: VID_
acpivout at acpivideo0 not configured
acpivideo1 at acpi0: VID_
cpu0: using VERW MDS workaround
cpu0: Enhanced SpeedStep 2095 MHz: speeds: 2201, 2200, 2100, 2000, 1800, 1700, 1600, 1500, 1300, 1200, 1100, 1000, 900, 700, 600, 500 MHz
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel Core 5G Host" rev 0x09
inteldrm0 at pci0 dev 2 function 0 "Intel HD Graphics 5500" rev 0x09
drm0 at inteldrm0
inteldrm0: msi
azalia0 at pci0 dev 3 function 0 "Intel Core 5G HD Audio" rev 0x09: msi
azalia0: No codecs found
xhci0 at pci0 dev 20 function 0 "Intel 9 Series xHCI" rev 0x03: msi, xHCI 1.0
usb0 at xhci0: USB revision 3.0
uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev 3.00/1.00 addr 1
"Intel 9 Series MEI" rev 0x03 at pci0 dev 22 function 0 not configured
em0 at pci0 dev 25 function 0 "Intel I218-LM" rev 0x03: msi, address 50:7b:9d:11:24:e8
azalia1 at pci0 dev 27 function 0 "Intel 9 Series HD Audio" rev 0x03: msi
azalia1: codecs: Realtek ALC292
audio0 at azalia1
ppb0 at pci0 dev 28 function 0 "Intel 9 Series PCIE" rev 0xe3: msi
pci1 at ppb0 bus 2
rtsx0 at pci1 dev 0 function 0 "Realtek RTS5227 Card Reader" rev 0x01: msi
sdmmc0 at rtsx0: 4-bit, dma
ppb1 at pci0 dev 28 function 1 "Intel 9 Series PCIE" rev 0xe3: msi
pci2 at ppb1 bus 3
iwm0 at pci2 dev 0 function 0 "Intel Dual Band Wireless AC 7265" rev 0x59, msi
pcib0 at pci0 dev 31 function 0 "Intel 9 Series LPC" rev 0x03
ahci0 at pci0 dev 31 function 2 "Intel 9 Series AHCI" rev 0x03: msi, AHCI 1.3
ahci0: port 0: 6.0Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 0 lun 0: <ATA, Samsung SSD 850, EMT0> SCSI3 0/direct fixed naa.5002538d40242fcb
sd0: 476940MB, 512 bytes/sector, 976773168 sectors, thin
ichiic0 at pci0 dev 31 function 3 "Intel 9 Series SMBus" rev 0x03: apic 2 int 18
iic0 at ichiic0
pchtemp0 at pci0 dev 31 function 6 "Intel 9 Series Thermal" rev 0x03
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard
pms0 at pckbc0 (aux slot)
wsmouse0 at pms0 mux 0
wsmouse1 at pms0 mux 0
pms0: Synaptics clickpad, firmware 8.1, 0x1e2b1 0x943300
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: VMX/EPT
uhub1 at uhub0 port 3 configuration 1 interface 0 "LENOVO Lenovo ThinkPad Dock" rev 2.10/50.40 addr 2
uhub2 at uhub1 port 1 configuration 1 interface 0 "Terminus Technology USB 2.0 Hub" rev 2.00/1.11 addr 3
uhub3 at uhub2 port 1 configuration 1 interface 0 "NEC hub" rev 2.00/1.00 addr 4
uhidev0 at uhub3 port 1 configuration 1 interface 0 "Topre Corporation HHKB Professional" rev 1.10/1.02 addr 5
uhidev0: iclass 3/1
ukbd0 at uhidev0: 8 variable keys, 6 key codes
wskbd1 at ukbd0 mux 1
uhidev1 at uhub3 port 2 configuration 1 interface 0 "Logitech USB Receiver" rev 2.00/12.09 addr 6
uhidev1: iclass 3/1
ukbd1 at uhidev1: 8 variable keys, 6 key codes
wskbd2 at ukbd1 mux 1
uhidev2 at uhub3 port 2 configuration 1 interface 1 "Logitech USB Receiver" rev 2.00/12.09 addr 6
uhidev2: iclass 3/1, 8 report ids
ums0 at uhidev2 reportid 2: 16 buttons, Z and W dir
wsmouse2 at ums0 mux 0
uhid0 at uhidev2 reportid 3: input=4, output=0, feature=0
uhid1 at uhidev2 reportid 4: input=1, output=0, feature=0
uhid2 at uhidev2 reportid 8: input=1, output=0, feature=0
uhidev3 at uhub3 port 2 configuration 1 interface 2 "Logitech USB Receiver" rev 2.00/12.09 addr 6
uhidev3: iclass 3/0, 33 report ids
uhid3 at uhidev3 reportid 16: input=6, output=6, feature=0
uhid4 at uhidev3 reportid 17: input=19, output=19, feature=0
uhid5 at uhidev3 reportid 32: input=14, output=14, feature=0
uhid6 at uhidev3 reportid 33: input=31, output=31, feature=0
ugen0 at uhub3 port 3 "Broadcom Corp BCM20702A0" rev 2.00/1.12 addr 7
uhub4 at uhub1 port 4 configuration 1 interface 0 "Lenovo Lenovo ThinkPad Dock" rev 2.00/0.01 addr 8
ugen1 at uhub0 port 5 "Generic EMV Smartcard Reader" rev 2.01/1.20 addr 9
usbd_free_xfer: xfer=0xfffffd824d855b40 not free
ugen1: setting configuration index 0 failed
ugen2 at uhub0 port 6 "Validity Sensors VFS5011 Fingerprint Reader" rev 1.10/0.78 addr 10
ugen3 at uhub0 port 7 "Intel Bluetooth" rev 2.01/0.01 addr 11
uhub5 at uhub0 port 14 configuration 1 interface 0 "LENOVO Lenovo ThinkPad Dock" rev 3.00/50.41 addr 12
vscsi0 at root
scsibus2 at vscsi0: 256 targets
softraid0 at root
scsibus3 at softraid0: 256 targets
sd1 at scsibus3 targ 1 lun 0: <OPENBSD, SR CRYPTO, 006> SCSI2 0/direct fixed
sd1: 409599MB, 512 bytes/sector, 838860209 sectors
root on sd1a (1aebccd650f38400.a) swap on sd1b dump on sd1b


// init defaults?

[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005d1000
[drm] Allocated atomic state 0xffff8000005e1800
[drm] Added [CRTC:39:pipe ] 0xffff8000005e2000 state to 0xffff8000005e1800
[drm] Added [CRTC:51:pipe ] 0xffff8000005e2800 state to 0xffff8000005e1800
[drm] Added [CRTC:63:pipe ] 0xffff8000005e3000 state to 0xffff8000005e1800
[drm] Added [PLANE:28:primary ] 0xffff8000005db300 state to 0xffff8000005e1800
[drm] Added [PLANE:31:sprite ] 0xffff8000005db400 state to 0xffff8000005e1800
[drm] Added [PLANE:36:cursor ] 0xffff8000005db500 state to 0xffff8000005e1800
[drm] Added [PLANE:40:primary ] 0xffff8000005db600 state to 0xffff8000005e1800
[drm] Added [PLANE:43:sprite ] 0xffff8000005db700 state to 0xffff8000005e1800
[drm] Added [PLANE:48:cursor ] 0xffff8000005db800 state to 0xffff8000005e1800
[drm] Added [PLANE:52:primary ] 0xffff8000005db900 state to 0xffff8000005e1800
[drm] Added [PLANE:55:sprite ] 0xffff8000005dba00 state to 0xffff8000005e1800
[drm] Added [PLANE:60:cursor ] 0xffff8000005dbb00 state to 0xffff8000005e1800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005d8e00 state to 0xffff8000005e1800
[drm] Added [CONNECTOR:72:DP-] 0xffff8000005d8e80 state to 0xffff8000005e1800
[drm] Added [CONNECTOR:78:HDMI-A-] 0xffff8000005d8f00 state to 0xffff8000005e1800
[drm] Added [CONNECTOR:83:DP-] 0xffff8000005d8f80 state to 0xffff8000005e1800
[drm] Added [CONNECTOR:88:HDMI-A-] 0xffff8000005d8380 state to 0xffff8000005e1800
[drm] XXX drm_atomic_helper_check_modeset(dev, 0xffff8000005e1800)
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:72:DP-]
[drm] Disabling [CONNECTOR:72:DP-]
[drm] Updating routing for [CONNECTOR:78:HDMI-A-]
[drm] Disabling [CONNECTOR:78:HDMI-A-]
[drm] Updating routing for [CONNECTOR:83:DP-]
[drm] Disabling [CONNECTOR:83:DP-]
[drm] Updating routing for [CONNECTOR:88:HDMI-A-]
[drm] Disabling [CONNECTOR:88:HDMI-A-]
[drm] XXX drm_atomic_helper_check_planes(dev, 0xffff8000005e1800)
[drm] Clearing atomic state 0xffff8000005e1800
[drm] Freeing atomic state 0xffff8000005e1800
inteldrm0: 1920x1080, 32bpp


// init hardware; ext. display off
// modeset happens (drm_atomic_helper_update_legacy_modeset_state)
//   -> flush_workqueue(dev_priv->modeset_wq)
// cleanup_planes (5e3) missing

[drm] Allocated atomic state 0xffff8000005e3800
[drm] Added [PLANE:28:primary ] 0xffff8000005db200 state to 0xffff8000005e3800
[drm] Added [PLANE:31:sprite ] 0xffff8000005db400 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff8000005db400
[drm] Added [PLANE:36:cursor ] 0xffff8000005db500 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff8000005db500
[drm] Added [PLANE:40:primary ] 0xffff8000005db600 state to 0xffff8000005e3800
[drm] Added [PLANE:43:sprite ] 0xffff8000005db700 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff8000005db700
[drm] Added [PLANE:48:cursor ] 0xffff8000005d3f00 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff8000005d3f00
[drm] Added [PLANE:52:primary ] 0xffff8000005dba00 state to 0xffff8000005e3800
[drm] Added [PLANE:55:sprite ] 0xffff8000005fd000 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff8000005fd000
[drm] Added [PLANE:60:cursor ] 0xffff8000005fd100 state to 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff8000005fd100
[drm] Added [CRTC:39:pipe ] 0xffff8000005e2000 state to 0xffff8000005e3800
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005e2000
[drm] Link [PLANE:28:primary ] state 0xffff8000005db200 to [CRTC:39:pipe ]
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff8000005db200
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005e3800
[drm] Added [CONNECTOR:65:eDP-] 0xffff8000005f0900 state to 0xffff8000005e3800
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005f0900 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff8000005f0900 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff8000005e2800 state to 0xffff8000005e3800
[drm] Set [NOMODE] for [CRTC:51:pipe ] state 0xffff8000005e2800
[drm] Set [NOFB] for [PLANE:40:primary ] state 0xffff8000005db600
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff8000005e3800
[drm] Added [CRTC:63:pipe ] 0xffff8000005e3000 state to 0xffff8000005e3800
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff8000005e3000
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff8000005dba00
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff8000005e3800
[drm] checking 0xffff8000005e3800
[drm] XXX drm_atomic_helper_check_modeset(dev, 0xffff8000005e3800)
[drm] [CRTC:39:pipe ] mode changed
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] [CRTC:39:pipe ] needs all connectors, enable: y, active: y
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005e3800
[drm] Adding all current planes for [CRTC:39:pipe ] to 0xffff8000005e3800
[drm] XXX drm_atomic_helper_check_planes(dev, 0xffff8000005e3800)
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 0 -> 1, off 0, on 1, ms 1
[drm] committing 0xffff8000005e3800
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff8000005e3800)
[drm] XXX drm_atomic_helper_setup_commit(0xffff8000005e3800, false)
[drm] XXX drm_atomic_helper_swap_state(0xffff8000005e3800, true)
[drm] XXX intel_atomic_commit_tail(0xffff8000005e3800)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff8000005e3800)
[drm] XXX drm_atomic_helper_update_legacy_modeset_state(dev, 0xffff8000005e3800)
[drm] XXX drm_atomic_helper_wait_for_flip_done(dev, 0xffff8000005e3800)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff8000005e3800)
[drm] XXX schedule_work(0xffff8000005e3800->commit_work) [intel_atomic_cleanup_work]
wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
wskbd1: connecting to wsdisplay0
wskbd2: connecting to wsdisplay0
wsdisplay0: screen 1-5 added (std, vt100 emulation)
iwm0: hw rev 0x210, fw ver 16.242414.0, address 94:65:9c:46:8a:f2


// enable external display
// modeset happens (drm_atomic_helper_update_legacy_modeset_state)
//   -> flush_workqueue(dev_priv->modeset_wq)
// cleanup_planes (974) missing

[drm] Allocated atomic state 0xffff800000974000
[drm] Added [PLANE:28:primary ] 0xffff800000973e00 state to 0xffff800000974000
[drm] Added [CRTC:39:pipe ] 0xffff800000974800 state to 0xffff800000974000
[drm] Added [PLANE:31:sprite ] 0xffff800000973f00 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000973f00
[drm] Added [PLANE:36:cursor ] 0xffff8000005db100 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff8000005db100
[drm] Added [PLANE:40:primary ] 0xffff800000973200 state to 0xffff800000974000
[drm] Added [PLANE:43:sprite ] 0xffff800000973300 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff800000973300
[drm] Added [PLANE:48:cursor ] 0xffff800000973400 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000973400
[drm] Added [PLANE:52:primary ] 0xffff800000973600 state to 0xffff800000974000
[drm] Added [PLANE:55:sprite ] 0xffff800000973800 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000973800
[drm] Added [PLANE:60:cursor ] 0xffff8000005fdf00 state to 0xffff800000974000
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff8000005fdf00
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff800000974800
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000973e00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000974000
[drm] Added [CONNECTOR:65:eDP-] 0xffff800000787500 state to 0xffff800000974000
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000787500 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000787500 to [CRTC:39:pipe ]
[drm] Added [CRTC:51:pipe ] 0xffff800000975000 state to 0xffff800000974000
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff800000975000
[drm] Link [PLANE:40:primary ] state 0xffff800000973200 to [CRTC:51:pipe ]
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff800000973200
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000974000
[drm] Added [CONNECTOR:94:DP-] 0xffff800000787580 state to 0xffff800000974000
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000787580 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff800000975800 state to 0xffff800000974000
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff800000975800
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000973600
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff800000974000
[drm] checking 0xffff800000974000
[drm] XXX drm_atomic_helper_check_modeset(dev, 0xffff800000974000)
[drm] [CRTC:51:pipe ] mode changed
[drm] [CRTC:51:pipe ] enable changed
[drm] [CRTC:51:pipe ] active changed
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] using [ENCODER:85:DP-MST ] on [CRTC:51:pipe ]
[drm] [CRTC:51:pipe ] needs all connectors, enable: y, active: y
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000974000
[drm] Adding all current planes for [CRTC:51:pipe ] to 0xffff800000974000
[drm] Added new private object 0xffff8000005e0448 state 0xffff80000014afa0 to 0xffff800000974000
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000974000
[drm] Adding all current planes for [CRTC:39:pipe ] to 0xffff800000974000
[drm] XXX drm_atomic_helper_check_planes(dev, 0xffff800000974000)
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 1, on 1, ms 1
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 0 -> 1, off 0, on 1, ms 1
[drm] committing 0xffff800000974000
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff800000974000)
[drm] XXX drm_atomic_helper_setup_commit(0xffff800000974000, false)
[drm] XXX drm_atomic_helper_swap_state(0xffff800000974000, true)
[drm] XXX intel_atomic_commit_tail(0xffff800000974000)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff800000974000)
[drm] XXX drm_atomic_helper_update_legacy_modeset_state(dev, 0xffff800000974000)
[drm] XXX drm_atomic_helper_wait_for_flip_done(dev, 0xffff800000974000)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff800000974000)
[drm] XXX schedule_work(0xffff800000974000->commit_work) [intel_atomic_cleanup_work]


// set both planes to "off 0, on 0, ms 0" (?)
// no modeset
// stall_checks times out
// cleanup_planes (979) missing
// cleanup_planes (5e3) happens

[drm] Allocated atomic state 0xffff800000979000
[drm] Added [PLANE:28:primary ] 0xffff800000978d00 state to 0xffff800000979000
[drm] Added [CRTC:39:pipe ] 0xffff800000979800 state to 0xffff800000979000
[drm] Added [PLANE:31:sprite ] 0xffff800000978e00 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000978e00
[drm] Added [PLANE:36:cursor ] 0xffff800000978f00 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000978f00
[drm] Added [PLANE:40:primary ] 0xffff8000005dbb00 state to 0xffff800000979000
[drm] Added [CRTC:51:pipe ] 0xffff80000097a000 state to 0xffff800000979000
[drm] Added [PLANE:43:sprite ] 0xffff8000005fde00 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff8000005fde00
[drm] Added [PLANE:48:cursor ] 0xffff800000976000 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000976000
[drm] Added [PLANE:52:primary ] 0xffff800000976100 state to 0xffff800000979000
[drm] Added [PLANE:55:sprite ] 0xffff800000976200 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000976200
[drm] Added [PLANE:60:cursor ] 0xffff800000976300 state to 0xffff800000979000
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff800000976300
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff800000979800
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000978d00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff800000979000
[drm] Added [CONNECTOR:65:eDP-] 0xffff800000787800 state to 0xffff800000979000
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000787800 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000787800 to [CRTC:39:pipe ]
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff80000097a000
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff8000005dbb00
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff800000979000
[drm] Added [CONNECTOR:94:DP-] 0xffff800000787880 state to 0xffff800000979000
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000787880 to [NOCRTC]
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000787880 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff80000097a800 state to 0xffff800000979000
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff80000097a800
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000976100
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff800000979000
[drm] checking 0xffff800000979000
[drm] XXX drm_atomic_helper_check_modeset(dev, 0xffff800000979000)
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] keeps [ENCODER:85:DP-MST ], now on [CRTC:51:pipe ]
[drm] XXX drm_atomic_helper_check_planes(dev, 0xffff800000979000)
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff800000979000
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff800000979000)
[drm] XXX drm_atomic_helper_setup_commit(0xffff800000979000, false)
[drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
[drm] XXX drm_atomic_helper_swap_state(0xffff800000979000, true)
[drm] XXX intel_atomic_commit_tail(0xffff800000979000)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff800000979000)
[drm] XXX drm_atomic_helper_wait_for_flip_done(dev, 0xffff800000979000)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff800000979000)
[drm] XXX schedule_work(0xffff800000979000->commit_work) [intel_atomic_cleanup_work]
[drm] XXX intel_atomic_cleanup_work(0xffff8000005e3800->commit_work)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff8000005e3800)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff8000005e3800)
[drm] Clearing atomic state 0xffff8000005e3800
[drm] Freeing atomic state 0xffff8000005e3800


// ?? (same as above?)
// no modeset
// cleanup_planes (5d1) missing
// stall_checks() times out
// cleanup_planes (974, 979, 5d1) happens

[drm] Allocated atomic state 0xffff8000005d1000
[drm] Added [PLANE:28:primary ] 0xffff800000c6fc00 state to 0xffff8000005d1000
[drm] Added [CRTC:39:pipe ] 0xffff8000005d4800 state to 0xffff8000005d1000
[drm] Added [PLANE:31:sprite ] 0xffff800000c6fd00 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:31:sprite ] state 0xffff800000c6fd00
[drm] Added [PLANE:36:cursor ] 0xffff800000c6fe00 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:36:cursor ] state 0xffff800000c6fe00
[drm] Added [PLANE:40:primary ] 0xffff800000c6ff00 state to 0xffff8000005d1000
[drm] Added [CRTC:51:pipe ] 0xffff8000005d7000 state to 0xffff8000005d1000
[drm] Added [PLANE:43:sprite ] 0xffff800000c46800 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:43:sprite ] state 0xffff800000c46800
[drm] Added [PLANE:48:cursor ] 0xffff800000973c00 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:48:cursor ] state 0xffff800000973c00
[drm] Added [PLANE:52:primary ] 0xffff800000c46700 state to 0xffff8000005d1000
[drm] Added [PLANE:55:sprite ] 0xffff800000c46e00 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:55:sprite ] state 0xffff800000c46e00
[drm] Added [PLANE:60:cursor ] 0xffff8000005fd500 state to 0xffff8000005d1000
[drm] Set [NOFB] for [PLANE:60:cursor ] state 0xffff8000005fd500
[drm] Set [MODE:1920x1080] for [CRTC:39:pipe ] state 0xffff8000005d4800
[drm] Set [FB:92] for [PLANE:28:primary ] state 0xffff800000c6fc00
[drm] Adding all current connectors for [CRTC:39:pipe ] to 0xffff8000005d1000
[drm] Added [CONNECTOR:65:eDP-] 0xffff800000c6af80 state to 0xffff8000005d1000
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000c6af80 to [NOCRTC]
[drm] Link [CONNECTOR:65:eDP-] state 0xffff800000c6af80 to [CRTC:39:pipe ]
[drm] Set [MODE:1920x1080] for [CRTC:51:pipe ] state 0xffff8000005d7000
[drm] Set [FB:92] for [PLANE:40:primary ] state 0xffff800000c6ff00
[drm] Adding all current connectors for [CRTC:51:pipe ] to 0xffff8000005d1000
[drm] Added [CONNECTOR:94:DP-] 0xffff800000c6a200 state to 0xffff8000005d1000
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c6a200 to [NOCRTC]
[drm] Link [CONNECTOR:94:DP-] state 0xffff800000c6a200 to [CRTC:51:pipe ]
[drm] Added [CRTC:63:pipe ] 0xffff8000005e3800 state to 0xffff8000005d1000
[drm] Set [NOMODE] for [CRTC:63:pipe ] state 0xffff8000005e3800
[drm] Set [NOFB] for [PLANE:52:primary ] state 0xffff800000c46700
[drm] Adding all current connectors for [CRTC:63:pipe ] to 0xffff8000005d1000
[drm] checking 0xffff8000005d1000
[drm] XXX drm_atomic_helper_check_modeset(dev, 0xffff8000005d1000)
[drm] Updating routing for [CONNECTOR:65:eDP-]
[drm] [CONNECTOR:65:eDP-] keeps [ENCODER:64:DDI ], now on [CRTC:39:pipe ]
[drm] Updating routing for [CONNECTOR:94:DP-]
[drm] [CONNECTOR:94:DP-] keeps [ENCODER:85:DP-MST ], now on [CRTC:51:pipe ]
[drm] XXX drm_atomic_helper_check_planes(dev, 0xffff8000005d1000)
[drm] [CRTC:39:pipe ] has [PLANE:28:primary ] with fb 92
[drm] [PLANE:28:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] [CRTC:51:pipe ] has [PLANE:40:primary ] with fb 92
[drm] [PLANE:40:primary ] visible 1 -> 1, off 0, on 0, ms 0
[drm] committing 0xffff8000005d1000
[drm] XXX drm_atomic_helper_prepare_planes(dev, 0xffff8000005d1000)
[drm] XXX drm_atomic_helper_setup_commit(0xffff8000005d1000, false)
[drm] *ERROR* [CRTC:39:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:51:pipe ] cleanup_done timed out
[drm] *ERROR* [CRTC:63:pipe ] cleanup_done timed out
[drm] XXX drm_atomic_helper_swap_state(0xffff8000005d1000, true)
[drm] XXX intel_atomic_commit_tail(0xffff8000005d1000)
[drm] XXX drm_atomic_helper_wait_for_dependencies(0xffff8000005d1000)
[drm] XXX drm_atomic_helper_wait_for_flip_done(dev, 0xffff8000005d1000)
[drm] XXX drm_atomic_helper_commit_hw_done(0xffff8000005d1000)
[drm] XXX schedule_work(0xffff8000005d1000->commit_work) [intel_atomic_cleanup_work]
[drm] XXX intel_atomic_cleanup_work(0xffff800000974000->commit_work)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff800000974000)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff800000974000)
[drm] Clearing atomic state 0xffff800000974000
[drm] Freeing atomic state 0xffff800000974000
[drm] XXX intel_atomic_cleanup_work(0xffff800000979000->commit_work)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff800000979000)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff800000979000)
[drm] Clearing atomic state 0xffff800000979000
[drm] Freeing atomic state 0xffff800000979000
[drm] XXX intel_atomic_cleanup_work(0xffff8000005d1000->commit_work)
[drm] XXX drm_atomic_helper_cleanup_planes(dev, 0xffff8000005d1000)
[drm] XXX drm_atomic_helper_cleanup_done(0xffff8000005d1000)
[drm] Clearing atomic state 0xffff8000005d1000
[drm] Freeing atomic state 0xffff8000005d1000

// everything OK from here on...

Index: dev/pci/drm/drm_atomic_helper.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/drm_atomic_helper.c,v
retrieving revision 1.2
diff -u -p -r1.2 drm_atomic_helper.c
--- dev/pci/drm/drm_atomic_helper.c 14 Apr 2019 10:14:51 -0000 1.2
+++ dev/pci/drm/drm_atomic_helper.c 27 May 2019 19:36:57 -0000
@@ -571,6 +571,8 @@ drm_atomic_helper_check_modeset(struct d
  int i, ret;
  unsigned connectors_mask = 0;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_check_modeset(dev, %p)\n", state);
+
  for_each_oldnew_crtc_in_state(state, crtc, old_crtc_state, new_crtc_state, i) {
  bool has_connectors =
  !!new_crtc_state->connector_mask;
@@ -818,6 +820,8 @@ drm_atomic_helper_check_planes(struct dr
  struct drm_plane_state *new_plane_state, *old_plane_state;
  int i, ret = 0;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_check_planes(dev, %p)\n", state);
+
  for_each_oldnew_plane_in_state(state, plane, old_plane_state, new_plane_state, i) {
  const struct drm_plane_helper_funcs *funcs;
 
@@ -889,6 +893,8 @@ int drm_atomic_helper_check(struct drm_d
 {
  int ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_check(dev, %p)\n", state);
+
  ret = drm_atomic_helper_check_modeset(dev, state);
  if (ret)
  return ret;
@@ -1032,6 +1038,8 @@ drm_atomic_helper_update_legacy_modeset_
  struct drm_crtc_state *new_crtc_state;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_update_legacy_modeset_state(dev, %p)\n", old_state);
+
  /* clear out existing links and update dpms */
  for_each_oldnew_connector_in_state(old_state, connector, old_conn_state, new_conn_state, i) {
  if (connector->encoder) {
@@ -1165,6 +1173,8 @@ crtc_set_mode(struct drm_device *dev, st
 void drm_atomic_helper_commit_modeset_disables(struct drm_device *dev,
        struct drm_atomic_state *old_state)
 {
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_modeset_disables(dev, %p)\n", old_state);
+
  disable_outputs(dev, old_state);
 
  drm_atomic_helper_update_legacy_modeset_state(dev, old_state);
@@ -1218,6 +1228,8 @@ void drm_atomic_helper_commit_modeset_en
  struct drm_connector_state *new_conn_state;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_modeset_enables(dev, %p)\n", old_state);
+
  for_each_oldnew_crtc_in_state(old_state, crtc, old_crtc_state, new_crtc_state, i) {
  const struct drm_crtc_helper_funcs *funcs;
 
@@ -1307,6 +1319,8 @@ int drm_atomic_helper_wait_for_fences(st
  struct drm_plane_state *new_plane_state;
  int i, ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_wait_for_fences(dev, %p, %s)\n", state, pre_swap?"true":"false");
+
  for_each_new_plane_in_state(state, plane, new_plane_state, i) {
  if (!new_plane_state->fence)
  continue;
@@ -1354,6 +1368,8 @@ drm_atomic_helper_wait_for_vblanks(struc
  int i, ret;
  unsigned crtc_mask = 0;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_wait_for_vblanks(dev, %p)\n", old_state);
+
  if (cold) {
  delay(50000);
  return;
@@ -1416,6 +1432,8 @@ void drm_atomic_helper_wait_for_flip_don
  struct drm_crtc *crtc;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_wait_for_flip_done(dev, %p)\n", old_state);
+
  for (i = 0; i < dev->mode_config.num_crtc; i++) {
  struct drm_crtc_commit *commit = old_state->crtcs[i].commit;
  int ret;
@@ -1453,6 +1471,8 @@ void drm_atomic_helper_commit_tail(struc
 {
  struct drm_device *dev = old_state->dev;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_tail(%p)\n", old_state);
+
  drm_atomic_helper_commit_modeset_disables(dev, old_state);
 
  drm_atomic_helper_commit_planes(dev, old_state, 0);
@@ -1483,6 +1503,8 @@ void drm_atomic_helper_commit_tail_rpm(s
 {
  struct drm_device *dev = old_state->dev;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_tail_rpm(%p)\n", old_state);
+
  drm_atomic_helper_commit_modeset_disables(dev, old_state);
 
  drm_atomic_helper_commit_modeset_enables(dev, old_state);
@@ -1553,6 +1575,8 @@ int drm_atomic_helper_async_check(struct
  const struct drm_plane_helper_funcs *funcs;
  int i, n_planes = 0;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_async_check(dev, %p)\n", state);
+
  for_each_new_crtc_in_state(state, crtc, crtc_state, i) {
  if (drm_atomic_crtc_needs_modeset(crtc_state))
  return -EINVAL;
@@ -1626,6 +1650,8 @@ void drm_atomic_helper_async_commit(stru
  const struct drm_plane_helper_funcs *funcs;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_async_commit(dev, %p)\n", state);
+
  for_each_new_plane_in_state(state, plane, plane_state, i) {
  funcs = plane->helper_private;
  funcs->atomic_async_update(plane, plane_state);
@@ -1668,6 +1694,8 @@ int drm_atomic_helper_commit(struct drm_
 {
  int ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit(dev, %p, %s)\n", state, nonblock?"true":"false");
+
  if (state->async_update) {
  ret = drm_atomic_helper_prepare_planes(dev, state);
  if (ret)
@@ -1920,6 +1948,8 @@ int drm_atomic_helper_setup_commit(struc
  struct drm_crtc_commit *commit;
  int i, ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_setup_commit(%p, %s)\n", state, nonblock?"true":"false");
+
  for_each_oldnew_crtc_in_state(state, crtc, old_crtc_state, new_crtc_state, i) {
  commit = kzalloc(sizeof(*commit), GFP_KERNEL);
  if (!commit)
@@ -2024,6 +2054,8 @@ void drm_atomic_helper_wait_for_dependen
  int i;
  long ret;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_wait_for_dependencies(%p)\n", old_state);
+
  for_each_old_crtc_in_state(old_state, crtc, old_crtc_state, i) {
  commit = old_crtc_state->commit;
 
@@ -2111,6 +2143,8 @@ void drm_atomic_helper_fake_vblank(struc
  struct drm_crtc *crtc;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_fake_vblank(%p)\n", old_state);
+
  for_each_new_crtc_in_state(old_state, crtc, new_crtc_state, i) {
  unsigned long flags;
 
@@ -2150,6 +2184,8 @@ void drm_atomic_helper_commit_hw_done(st
  struct drm_crtc_commit *commit;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_hw_done(%p)\n", old_state);
+
  for_each_oldnew_crtc_in_state(old_state, crtc, old_crtc_state, new_crtc_state, i) {
  commit = new_crtc_state->commit;
  if (!commit)
@@ -2195,6 +2231,8 @@ void drm_atomic_helper_commit_cleanup_do
  struct drm_crtc_commit *commit;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_cleanup_done(%p)\n", old_state);
+
  for_each_old_crtc_in_state(old_state, crtc, old_crtc_state, i) {
  commit = old_crtc_state->commit;
  if (WARN_ON(!commit))
@@ -2233,6 +2271,8 @@ int drm_atomic_helper_prepare_planes(str
  struct drm_plane_state *new_plane_state;
  int ret, i, j;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_prepare_planes(dev, %p)\n", state);
+
  for_each_new_plane_in_state(state, plane, new_plane_state, i) {
  const struct drm_plane_helper_funcs *funcs;
 
@@ -2322,6 +2362,8 @@ void drm_atomic_helper_commit_planes(str
  bool active_only = flags & DRM_PLANE_COMMIT_ACTIVE_ONLY;
  bool no_disable = flags & DRM_PLANE_COMMIT_NO_DISABLE_AFTER_MODESET;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_planes(dev, %p, flags)\n", old_state);
+
  for_each_oldnew_crtc_in_state(old_state, crtc, old_crtc_state, new_crtc_state, i) {
  const struct drm_crtc_helper_funcs *funcs;
 
@@ -2523,6 +2565,8 @@ void drm_atomic_helper_cleanup_planes(st
  struct drm_plane_state *old_plane_state, *new_plane_state;
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_cleanup_planes(dev, %p)\n", old_state);
+
  for_each_oldnew_plane_in_state(old_state, plane, old_plane_state, new_plane_state, i) {
  const struct drm_plane_helper_funcs *funcs;
  struct drm_plane_state *plane_state;
@@ -2593,6 +2637,8 @@ int drm_atomic_helper_swap_state(struct
  struct drm_private_obj *obj;
  struct drm_private_state *old_obj_state, *new_obj_state;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_swap_state(%p, %s)\n", state, stall?"true":"false");
+
  if (stall) {
  /*
  * We have to stall for hw_done here before
@@ -3223,6 +3269,8 @@ int drm_atomic_helper_commit_duplicated_
  struct drm_crtc *crtc;
  struct drm_crtc_state *new_crtc_state;
 
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_commit_duplicated_state(%p, ctx)\n", state);
+
  state->acquire_ctx = ctx;
 
  for_each_new_plane_in_state(state, plane, new_plane_state, i)
@@ -3263,6 +3311,8 @@ int drm_atomic_helper_resume(struct drm_
 {
  struct drm_modeset_acquire_ctx ctx;
  int err;
+
+    DRM_DEBUG_ATOMIC("XXX drm_atomic_helper_resume(dev, %p)\n", state);
 
  drm_mode_config_reset(dev);
 
Index: dev/pci/drm/i915/intel_display.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
retrieving revision 1.63
diff -u -p -r1.63 intel_display.c
--- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
+++ dev/pci/drm/i915/intel_display.c 27 May 2019 19:36:58 -0000
@@ -12592,6 +12592,8 @@ static void intel_atomic_cleanup_work(st
  container_of(work, struct drm_atomic_state, commit_work);
  struct drm_i915_private *i915 = to_i915(state->dev);
 
+    DRM_DEBUG_ATOMIC("XXX intel_atomic_cleanup_work(%p->commit_work)\n", state);
+
  drm_atomic_helper_cleanup_planes(&i915->drm, state);
  drm_atomic_helper_commit_cleanup_done(state);
  drm_atomic_state_put(state);
@@ -12610,6 +12612,8 @@ static void intel_atomic_commit_tail(str
  u64 put_domains[I915_MAX_PIPES] = {};
  int i;
 
+    DRM_DEBUG_ATOMIC("XXX intel_atomic_commit_tail(%p)\n", state);
+
  intel_atomic_commit_fence_wait(intel_state);
 
  drm_atomic_helper_wait_for_dependencies(state);
@@ -12763,7 +12767,12 @@ static void intel_atomic_commit_tail(str
  * down.
  */
  INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
+#if (drm_debug & DRM_UT_ATOMIC)
+    DRM_DEBUG_ATOMIC("XXX schedule_work(%p->commit_work) [intel_atomic_cleanup_work]\n", state);
  schedule_work(&state->commit_work);
+#else
+ intel_atomic_cleanup_work(&state->commit_work);
+#endif
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)
@@ -12873,8 +12882,11 @@ static int intel_atomic_commit(struct dr
  ret = drm_atomic_helper_setup_commit(state, nonblock);
  if (!ret)
  ret = drm_atomic_helper_swap_state(state, true);
+    else
+ DRM_DEBUG_ATOMIC("Setting up commit failed with %i\n", ret);
 
  if (ret) {
+ DRM_DEBUG_ATOMIC("State swap failed with %i\n", ret);
  i915_sw_fence_commit(&intel_state->commit_ready);
 
  drm_atomic_helper_cleanup_planes(dev, state);
Index: dev/pci/drm/include/drm/drmP.h
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/include/drm/drmP.h,v
retrieving revision 1.2
diff -u -p -r1.2 drmP.h
--- dev/pci/drm/include/drm/drmP.h 4 May 2019 11:34:48 -0000 1.2
+++ dev/pci/drm/include/drm/drmP.h 27 May 2019 19:36:58 -0000
@@ -126,7 +126,7 @@ struct fb_fillrect;
 struct fb_copyarea;
 struct fb_image;
 
-#define drm_debug 0
+#define drm_debug DRM_UT_ATOMIC
 
  /* Internal types and structures */
 #define DRM_IF_VERSION(maj, min) (maj << 16 | min)
Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Jonathan Gray-11
On Mon, May 27, 2019 at 10:22:12PM +0200, Sven M. Hallberg wrote:

> Sven M. Hallberg on Fri, May 24 2019:
> >>Fix:
> > ?
>
> I discovered the immediate culprit to be these lines in
> /sys/dev/pci/drm/i915/intel_display.c:
>
>     static void intel_atomic_commit_tail(struct drm_atomic_state *state)
>     {
>         ...
>
>         /*    
>          * Defer the cleanup of the old state to a separate worker to not
>          * impede the current task (userspace for blocking modesets) that
>          * are executed inline. For out-of-line asynchronous modesets/flips,
>          * deferring to a new worker seems overkill, but we would place a
>          * schedule point (cond_resched()) here anyway to keep latencies
>          * down.
>          */    
>         INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
>         schedule_work(&state->commit_work);
>     }
>
> The comment seems to indicate that the cleanup work is expected to be
> performed (almost) immediately as if called directly. So, as a
> workaround, replacing the last line with the direct call
>
>         intel_atomic_cleanup_work(&state->commit_work);
>
> makes things work fine for me.
>
> As for when and why the scheduled tasks do or don't run, my best theory
> is that there is a subtle difference between Linux workqueues and BSD
> taskqs (which are used to emulate the former here).
> Also, the "commits" where cleanup is delayed happen to be those which
> perform actual modesetting. This could of course be pure coincidence.

The timing is apparently tight in linux as well, in later versions
they switched to using a 'system_highpri_wq', INIT_WORK/schedule_work
results in the task being added to 'system_wq' which for us is a drm
specific taskq.

If we just created another taskq for 'system_highpri_wq' the same thing
would likely happen.

Linux deferred cleanup to avoid lock contention/deadlock.  If you
raise the timeout in drm_atomic_helper.c stall_checks() does that
also avoid the 'cleanup_done timed out' messages at some point?

commit 41db645a33e775855aeeec1a437d5c1e24ff6c88
Author: Chris Wilson <[hidden email]>
Date:   Thu Jul 12 12:57:29 2018 +0100

    drm/i915: Bump priority of clean up work
   
    We require that we keep the list of outstanding work short so that we do
    not "leak" memory while pageflipping under stress. However that system
    stress may delay kernel workers virtually indefinitely, which incurs the
    pageflips stall and eventually hit a timeout waiting for the cleanup.
   
    Try to combat CPU starvation of our short-lived cleanup workers by
    switching to a high priority workqueue.
   
    Testcase: igt/kms_cursor_legacy/all-pipes-torture-move
    References: https://bugs.freedesktop.org/show_bug.cgi?id=107122
    Signed-off-by: Chris Wilson <[hidden email]>
    Cc: Daniel Vetter <[hidden email]>
    Reviewed-by: Mika Kuoppala <[hidden email]>
    Link: https://patchwork.freedesktop.org/patch/msgid/20180712115729.3506-1-chris@...

diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c
index 53e7a7e75384..366ff66e9279 100644
--- a/drivers/gpu/drm/i915/intel_display.c
+++ b/drivers/gpu/drm/i915/intel_display.c
@@ -12738,7 +12738,7 @@ static void intel_atomic_commit_tail(struct drm_atomic_state *state)
  * down.
  */
  INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
- schedule_work(&state->commit_work);
+ queue_work(system_highpri_wq, &state->commit_work);
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)

commit 8d52e447807b350b98ffb4e64bc2fcc1f181c5be
Author: Chris Wilson <[hidden email]>
Date:   Sat Jun 23 11:39:51 2018 +0100

    drm/i915: Defer modeset cleanup to a secondary task
   
    If we avoid cleaning up the old state immediately in
    intel_atomic_commit_tail() and defer it to a second task, we can avoid
    taking heavily contended locks when the caller is ready to procede.
    Subsequent modesets will wait for the cleanup operation (either directly
    via the ordered modeset wq or indirectly through the atomic helperr)
    which keeps the number of inflight cleanup tasks in check.
   
    As an example, during reset an immediate modeset is performed to disable
    the displays before the HW is reset, which must avoid struct_mutex to
    avoid recursion. Moving the cleanup to a separate task, defers acquiring
    the struct_mutex to after the GPU is running again, allowing it to
    complete. Even in a few patches time (optimist!) when we no longer
    require struct_mutex to unpin the framebuffers, it will still be good
    practice to minimise the number of contention points along reset. The
    mutex dependency still exists (as one modeset flushes the other), but in
    the short term it resolves the deadlock for simple reset cases.
   
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=101600
    Signed-off-by: Chris Wilson <[hidden email]>
    Link: https://patchwork.freedesktop.org/patch/msgid/20180623103951.23889-1-chris@...
    Acked-by: Maarten Lankhorst <[hidden email]>
    Acked-by: Daniel Vetter <[hidden email]>

diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c
index 4db576c3e364..1469a56f6c46 100644
--- a/drivers/gpu/drm/i915/intel_display.c
+++ b/drivers/gpu/drm/i915/intel_display.c
@@ -12555,6 +12555,19 @@ static void intel_atomic_commit_fence_wait(struct intel_atomic_state *intel_stat
  finish_wait(&dev_priv->gpu_error.wait_queue, &wait_reset);
 }
 
+static void intel_atomic_cleanup_work(struct work_struct *work)
+{
+ struct drm_atomic_state *state =
+ container_of(work, struct drm_atomic_state, commit_work);
+ struct drm_i915_private *i915 = to_i915(state->dev);
+
+ drm_atomic_helper_cleanup_planes(&i915->drm, state);
+ drm_atomic_helper_commit_cleanup_done(state);
+ drm_atomic_state_put(state);
+
+ intel_atomic_helper_free_state(i915);
+}
+
 static void intel_atomic_commit_tail(struct drm_atomic_state *state)
 {
  struct drm_device *dev = state->dev;
@@ -12715,13 +12728,16 @@ static void intel_atomic_commit_tail(struct drm_atomic_state *state)
  intel_display_power_put(dev_priv, POWER_DOMAIN_MODESET);
  }
 
- drm_atomic_helper_cleanup_planes(dev, state);
-
- drm_atomic_helper_commit_cleanup_done(state);
-
- drm_atomic_state_put(state);
-
- intel_atomic_helper_free_state(dev_priv);
+ /*
+ * Defer the cleanup of the old state to a separate worker to not
+ * impede the current task (userspace for blocking modesets) that
+ * are executed inline. For out-of-line asynchronous modesets/flips,
+ * deferring to a new worker seems overkill, but we would place a
+ * schedule point (cond_resched()) here anyway to keep latencies
+ * down.
+ */
+ INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
+ schedule_work(&state->commit_work);
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
Jonathan Gray on Tue, May 28 2019:
> If you raise the timeout in drm_atomic_helper.c stall_checks() does
> that also avoid the 'cleanup_done timed out' messages at some point?

It's already 10s but even with 30s (per CRTC!), nothing changes.

The blocking call is wait_for_completion_interruptible_timeout(),
defined in /sys/dev/pci/drm/include/linux/completion.h as a loop of

        ret = msleep(x, &x->wait.lock, PCATCH, "wfcit", timo);

where x is the "completion" object (condition/semaphore).

The system is not under any "stress" at this time, so there should be
ample opportunity for those cleanup tasks to be picked up und clear the
stall. Yet it looks like a deadlock...

What about task queues and kernel threads am I missing here?

-pesco

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Jonathan Gray-11
On Tue, May 28, 2019 at 05:32:37PM +0200, Sven M. Hallberg wrote:

> Jonathan Gray on Tue, May 28 2019:
> > If you raise the timeout in drm_atomic_helper.c stall_checks() does
> > that also avoid the 'cleanup_done timed out' messages at some point?
>
> It's already 10s but even with 30s (per CRTC!), nothing changes.
>
> The blocking call is wait_for_completion_interruptible_timeout(),
> defined in /sys/dev/pci/drm/include/linux/completion.h as a loop of
>
>         ret = msleep(x, &x->wait.lock, PCATCH, "wfcit", timo);
>
> where x is the "completion" object (condition/semaphore).
>
> The system is not under any "stress" at this time, so there should be
> ample opportunity for those cleanup tasks to be picked up und clear the
> stall. Yet it looks like a deadlock...
>
> What about task queues and kernel threads am I missing here?
>
> -pesco
>

If changing the delay doesn't help then perhaps we just go with your
change to directly do the callback without a task.

Index: intel_display.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
retrieving revision 1.63
diff -u -p -r1.63 intel_display.c
--- intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
+++ intel_display.c 30 May 2019 08:09:58 -0000
@@ -12763,7 +12763,15 @@ static void intel_atomic_commit_tail(str
  * down.
  */
  INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
+#ifdef __linux__
  schedule_work(&state->commit_work);
+#else
+ /*
+ * Avoid 'cleanup_done timed out' when using an external displayport
+ * monitor with MST dock and call cleanup without delay.
+ */
+ intel_atomic_cleanup_work(&state->commit_work);
+#endif
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Mark Kettenis
> Date: Thu, 30 May 2019 19:13:44 +1000
> From: Jonathan Gray <[hidden email]>
>
> On Tue, May 28, 2019 at 05:32:37PM +0200, Sven M. Hallberg wrote:
> > Jonathan Gray on Tue, May 28 2019:
> > > If you raise the timeout in drm_atomic_helper.c stall_checks() does
> > > that also avoid the 'cleanup_done timed out' messages at some point?
> >
> > It's already 10s but even with 30s (per CRTC!), nothing changes.
> >
> > The blocking call is wait_for_completion_interruptible_timeout(),
> > defined in /sys/dev/pci/drm/include/linux/completion.h as a loop of
> >
> >         ret = msleep(x, &x->wait.lock, PCATCH, "wfcit", timo);
> >
> > where x is the "completion" object (condition/semaphore).
> >
> > The system is not under any "stress" at this time, so there should be
> > ample opportunity for those cleanup tasks to be picked up und clear the
> > stall. Yet it looks like a deadlock...
> >
> > What about task queues and kernel threads am I missing here?
> >
> > -pesco
> >
>
> If changing the delay doesn't help then perhaps we just go with your
> change to directly do the callback without a task.

I doubt that'll work correctly.

I wonder whether the issue is that on OpenBSD we use a single-threaded
task queue, where Linux is pretty much always multi-threaded.  That
means that on OpenBSD, if a task blocks, no other task can run.  At
some point I ran into that issue, but worked around it by using an
additional task queue.

I believe Linux uses a thread per cpu.  I think that means there is
actually a bug in the Linux code somewhere but nobody notices because
most systems have more than one cpu.

Making the task queues multi-threaded on OpenBSD is hard since it
breaks the synchronization mechanism such as takq_barrier(9).

> Index: intel_display.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
> retrieving revision 1.63
> diff -u -p -r1.63 intel_display.c
> --- intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
> +++ intel_display.c 30 May 2019 08:09:58 -0000
> @@ -12763,7 +12763,15 @@ static void intel_atomic_commit_tail(str
>   * down.
>   */
>   INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
> +#ifdef __linux__
>   schedule_work(&state->commit_work);
> +#else
> + /*
> + * Avoid 'cleanup_done timed out' when using an external displayport
> + * monitor with MST dock and call cleanup without delay.
> + */
> + intel_atomic_cleanup_work(&state->commit_work);
> +#endif
>  }
>  
>  static void intel_atomic_commit_work(struct work_struct *work)
>
>

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
Mark Kettenis on Thu, May 30 2019:
>> > What about task queues and kernel threads am I missing here?
>
> [...]
>
> I wonder whether the issue is that on OpenBSD we use a single-threaded
> task queue, where Linux is pretty much always multi-threaded.  That
> means that on OpenBSD, if a task blocks, no other task can run.

I believe that is exactly the issue. Something (driver init?) is putting
tasks in the queue that end up calling drm_atomic_commit() and by
extension stall_checks(). And it's putting in enough of these tasks so
that the cleanups don't get their turn until the third commit runs and
hits the timeout ("two commits active already, better wait until one
finishes cleanup"). So the kernel thread associated with "system_wq"
ends up waiting for itself.


> I believe Linux uses a thread per cpu.  I think that means there is
> actually a bug in the Linux code somewhere but nobody notices because
> most systems have more than one cpu.

That suspicion has crossed my mind as well, in fact.
"driver stall when connecting more displays than CPUs"


I'm still looking for the smoking gun, i.e. the code that places atomic
commits on this queue, but haven't been able to find it with my crude
printf spells. Any hints appreciated. I need to learn how to use the
kernel debugger.


Regards,
pesco

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Kevin Chadwick-4
On 5/31/19 12:47 PM, Sven M. Hallberg wrote:
> I believe Linux uses a thread per cpu.  I think that means there is
> actually a bug in the Linux code somewhere but nobody notices because
> most systems have more than one cpu.

Probably wasting your time but may support the thread per process/cpu notion?;
("On Linux a thread is just a weird process")

https://github.com/go-delve/delve/issues/213

"The biggest challenge to porting Delve to FreeBSD is in the different threading
model. On Linux a thread is just a weird process, and ptrace works more or less
identically on threads and processes. However, on FreeBSD threads are a
first-class concept and ptrace works primarily on processes, using a set of
special requests to for thread-related stuff. That difference has exposed some
Linuxisms that got accidentally assumed in Delve. I expect that there are more
to follow."

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
In reply to this post by Sven M. Hallberg
Sven M. Hallberg on Fri, May 31 2019:
> I'm still looking for the smoking gun, i.e. the code that places atomic
> commits on this queue

AFAICS, the offending task is output_poll_execute() defined in
drm_probe_helper.c.

Stopped at drm_atomic_commit [/usr/src/sys/dev/pci/drm/drm_atomic.c:2006]: movq    acpi_pdirpa+0x77fcf9,%r10
ddb{0}> drm_atomic_commit(ffff8000005ca800,0,3,ffffffff81cf9ff0,14,ffffffff81d30218) at drm_atomic_commit [/usr/src/sys/dev/pci/drm/drm_atomic.c:2006]
restore_fbdev_mode_atomic(ffff8000005c8c00,1,b9e08c849cc7d070,ffff8000005c8d10,ffff8000005c8c00,0) at restore_fbdev_mode_atomic+0x1ac [/usr/src/sys/dev/pci/drm/drm_fb_helper.c:457]
drm_fb_helper_restore_fbdev_mode_unlocked(ffff8000005c8c00,ffff8000005c8c00,5cdcfc62a8f1af3a,ffff8000005c8d10,ffff8000005c8c00,0) at drm_fb_helper_restore_fbdev_mode_unlocked+0x76 [/usr/src/sys/dev/pci/drm/drm_fb_helper.c:523]
drm_fb_helper_hotplug_event(ffff8000005c8c00,ffff8000005c8c00,31df4698846687b9,ffff80000014c078,ffff80000014c388,ffff800000144c01) at drm_fb_helper_hotplug_event+0x193 [/usr/src/sys/dev/pci/drm/drm_fb_helper.c:0]
output_poll_execute(ffff80000014c388,ffff80000014c388,b5401d7d4aa6a463,ffff8000222b8280,ffff800000144c40,ffff800000144c40) at output_poll_execute+0x1a9 [/usr/src/sys/dev/pci/drm/drm_probe_helper.c:655]
taskq_thread(ffff800000144c40,ffff800000144c40,0,0,ffffffff815deb10,0) at taskq_thread+0x4d [/usr/src/sys/kern/kern_task.c:346]
end trace frame: 0x0, count: -5

This task is put on the queue by drm_kms_helper_poll_init() in the same
file. The latter is called, as I suspected, by driver initialization;
specifically i915_driver_register() in i915/i915_drv.c

I'm not sure that output_poll_execute() is the only one; I think there
must be three atomic commits already queued before the worker thread
starts for the observed behavior to happen. I think the order of events
is like this:

1. place commit 1 on queue
2. place commit 2 on queue
3. place commit 3 on queue

kthread for queue starts

4. start commit 1; places cleanup 1 on queue
5. start commit 2; places cleanup 2 on queue

queue is now: commit 3, cleanup 1, cleanup 2

6. start commit 3

stalls because 2 commits in flight but waiting for self to finish
cleanup.

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Sven M. Hallberg
In reply to this post by Mark Kettenis
I've spent some more time poking through the drm code and think I have a
good picture now of what is going on.

The inteldrm (i915) driver is essentially implementing a three-stage
pipeline: setup - hardware - cleanup.

The first and second stage are perfomed in the originating
thread/process (so usually an ioctl from userspace) unless
nonblocking behavior has been requested. In that case, only setup is
performed in the originating context and hardware is deferred to either
'system_unbound_wq' or a special 'modeset_wq'.

sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit():

    if (nonblock && intel_state->modeset) {
            queue_work(dev_priv->modeset_wq, &state->commit_work);
    } else if (nonblock) {
            queue_work(system_unbound_wq, &state->commit_work);
    } else {
            if (intel_state->modeset)
                flush_workqueue(dev_priv->modeset_wq);
            intel_atomic_commit_tail(state);
    }

This mirrors the generic (reference/example?) implementation
sys/dev/pci/drm/drm_atomic_helper.c drm_atomic_helper_commit():

    if (nonblock)
            queue_work(system_unbound_wq, &state->commit_work);
    else
            commit_tail(state);

Finally, the cleanup stage is deferred by i915 to 'system_wq'.
sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit_tail():

    INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
    schedule_work(&state->commit_work);


Mark Kettenis on Thu, May 30 2019:
> I wonder whether the issue is that on OpenBSD we use a single-threaded
> task queue, where Linux is pretty much always multi-threaded.  That
> means that on OpenBSD, if a task blocks, no other task can run.  At
> some point I ran into that issue, but worked around it by using an
> additional task queue.

I'm pretty sure that this is accurate and using an additional queue
would fix it (see below).

> I believe Linux uses a thread per cpu.  I think that means there is
> actually a bug in the Linux code somewhere but nobody notices because
> most systems have more than one cpu.

Yes, I think so, unless Linux dynamically spawns new workers when
the "worker pool" runs out or something.

> Making the task queues multi-threaded on OpenBSD is hard since it
> breaks the synchronization mechanism such as takq_barrier(9).

Agreed.


In summary, I see three main options for fixing this:

1. Multithread the work queue somehow. A few tricks come to mind, but
   like you say, it's going to be fiddly.*

2. Put the cleanup tasks in their own queue. The rationale being that
   this properly assigns a worker to the third stage of the pipeline.

3. Only defer cleanups in the nonblocking case. Rationale: This is
   arguably expected behavior out of a blocking call and if you care
   about the latency introduced by the cleanup, then you probably also
   care about the setup and are doing nonblocking calls already.**

   Note that the nonblocking case will not stall, because nonblocking
   commits go on system_unbound_wq or modeset_wq. Cleanups therefore end
   up separated on system_wq. In fact, there is a comment that seems to
   echo this in drm_atomic_helper_commit():

       /* [...]
        * NOTE: Commit work has multiple phases, first hardware commit, then
        * cleanup. We want them to overlap, hence need system_unbound_wq to
        * make sure work items don't artifically stall on each another.
        */

I'm attaching diffs for options 2 and 3. Both work for me.


-pesco

* For example: In wait_for_completion(), before going to sleep, check
  whether we are a queue worker and if so, quickly spawn another to
  continue in our place.

** I guess the prime example would be fancy compositors that potentially
   shout an ioctl at the kernel every frame. I have not checked whether
   they do blocking or nonblocking calls.


Index: dev/pci/drm/i915/i915_drv.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/i915_drv.c,v
retrieving revision 1.118
diff -u -p -r1.118 i915_drv.c
--- dev/pci/drm/i915/i915_drv.c 8 May 2019 15:55:56 -0000 1.118
+++ dev/pci/drm/i915/i915_drv.c 3 Jun 2019 19:04:30 -0000
@@ -869,8 +869,14 @@ static int i915_workqueues_init(struct d
  if (dev_priv->hotplug.dp_wq == NULL)
  goto out_free_wq;
 
+ dev_priv->cleanup_wq = alloc_ordered_workqueue("i915-cleanup", 0);
+ if (dev_priv->cleanup_wq == NULL)
+ goto out_free_wq2;
+
  return 0;
 
+out_free_wq2:
+ destroy_workqueue(dev_priv->hotplug.dp_wq);
 out_free_wq:
  destroy_workqueue(dev_priv->wq);
 out_err:
Index: dev/pci/drm/i915/i915_drv.h
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/i915_drv.h,v
retrieving revision 1.82
diff -u -p -r1.82 i915_drv.h
--- dev/pci/drm/i915/i915_drv.h 4 May 2019 11:34:47 -0000 1.82
+++ dev/pci/drm/i915/i915_drv.h 3 Jun 2019 19:04:30 -0000
@@ -1876,6 +1876,9 @@ struct inteldrm_softc {
  /* ordered wq for modesets */
  struct workqueue_struct *modeset_wq;
 
+ /* ordered wq for cleanups */
+ struct workqueue_struct *cleanup_wq;
+
  /* Display functions */
  struct drm_i915_display_funcs display;
 
Index: dev/pci/drm/i915/intel_display.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
retrieving revision 1.63
diff -u -p -r1.63 intel_display.c
--- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
+++ dev/pci/drm/i915/intel_display.c 3 Jun 2019 19:04:31 -0000
@@ -12761,9 +12761,14 @@ static void intel_atomic_commit_tail(str
  * deferring to a new worker seems overkill, but we would place a
  * schedule point (cond_resched()) here anyway to keep latencies
  * down.
+ *
+ * NOTE: Some driver code paths (e.g. i915_driver_register) perform
+ * blocking commits (via drm_atomic_commit) from system_wq tasks while
+ * nonblocking commits use system_unbound_wq or our own modeset_wq.
+ * Deferring cleanup to the same queue could cause workers to deadlock.
  */
  INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
- schedule_work(&state->commit_work);
+ queue_work(dev_priv->cleanup_wq, &state->commit_work);
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)

Index: dev/pci/drm/i915/intel_display.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
retrieving revision 1.63
diff -u -p -r1.63 intel_display.c
--- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
+++ dev/pci/drm/i915/intel_display.c 3 Jun 2019 18:33:39 -0000
@@ -12586,10 +12586,8 @@ static void intel_atomic_commit_fence_wa
 #endif
 }
 
-static void intel_atomic_cleanup_work(struct work_struct *work)
+static void intel_atomic_cleanup(struct drm_atomic_state *state)
 {
- struct drm_atomic_state *state =
- container_of(work, struct drm_atomic_state, commit_work);
  struct drm_i915_private *i915 = to_i915(state->dev);
 
  drm_atomic_helper_cleanup_planes(&i915->drm, state);
@@ -12599,7 +12597,15 @@ static void intel_atomic_cleanup_work(st
  intel_atomic_helper_free_state(i915);
 }
 
-static void intel_atomic_commit_tail(struct drm_atomic_state *state)
+static void intel_atomic_cleanup_work(struct work_struct *work)
+{
+ struct drm_atomic_state *state =
+ container_of(work, struct drm_atomic_state, commit_work);
+
+ intel_atomic_cleanup(state);
+}
+
+static void intel_atomic_commit_tail(struct drm_atomic_state *state, bool nonblock)
 {
  struct drm_device *dev = state->dev;
  struct intel_atomic_state *intel_state = to_intel_atomic_state(state);
@@ -12754,16 +12760,22 @@ static void intel_atomic_commit_tail(str
  intel_display_power_put(dev_priv, POWER_DOMAIN_MODESET);
  }
 
- /*
- * Defer the cleanup of the old state to a separate worker to not
- * impede the current task (userspace for blocking modesets) that
- * are executed inline. For out-of-line asynchronous modesets/flips,
- * deferring to a new worker seems overkill, but we would place a
- * schedule point (cond_resched()) here anyway to keep latencies
- * down.
- */
- INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
- schedule_work(&state->commit_work);
+ if (nonblock) {
+ /*
+ * Defer the cleanup of the old state to a separate worker to
+ * keep latencies down.
+ */
+ INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
+ schedule_work(&state->commit_work);
+ } else {
+ /*
+ * NOTE: Some driver code paths (e.g. i915_driver_register)
+ * perform blocking commits (via drm_atomic_commit) from
+ * system_wq tasks. Deferring cleanup to system_wq as well
+ * could cause workers to deadlock.
+ */
+ intel_atomic_cleanup(state);
+ }
 }
 
 static void intel_atomic_commit_work(struct work_struct *work)
@@ -12771,7 +12783,7 @@ static void intel_atomic_commit_work(str
  struct drm_atomic_state *state =
  container_of(work, struct drm_atomic_state, commit_work);
 
- intel_atomic_commit_tail(state);
+ intel_atomic_commit_tail(state, true);
 }
 
 static int __i915_sw_fence_call
@@ -12906,7 +12918,7 @@ static int intel_atomic_commit(struct dr
  } else {
  if (intel_state->modeset)
  flush_workqueue(dev_priv->modeset_wq);
- intel_atomic_commit_tail(state);
+ intel_atomic_commit_tail(state, false);
  }
 
  return 0;
Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Mark Kettenis
> From: "Sven M. Hallberg" <[hidden email]>
> Date: Mon, 03 Jun 2019 21:20:29 +0200
>
> I've spent some more time poking through the drm code and think I have a
> good picture now of what is going on.
>
> The inteldrm (i915) driver is essentially implementing a three-stage
> pipeline: setup - hardware - cleanup.
>
> The first and second stage are perfomed in the originating
> thread/process (so usually an ioctl from userspace) unless
> nonblocking behavior has been requested. In that case, only setup is
> performed in the originating context and hardware is deferred to either
> 'system_unbound_wq' or a special 'modeset_wq'.
>
> sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit():
>
>     if (nonblock && intel_state->modeset) {
>             queue_work(dev_priv->modeset_wq, &state->commit_work);
>     } else if (nonblock) {
>             queue_work(system_unbound_wq, &state->commit_work);
>     } else {
>             if (intel_state->modeset)
>                 flush_workqueue(dev_priv->modeset_wq);
>             intel_atomic_commit_tail(state);
>     }
>
> This mirrors the generic (reference/example?) implementation
> sys/dev/pci/drm/drm_atomic_helper.c drm_atomic_helper_commit():
>
>     if (nonblock)
>             queue_work(system_unbound_wq, &state->commit_work);
>     else
>             commit_tail(state);
>
> Finally, the cleanup stage is deferred by i915 to 'system_wq'.
> sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit_tail():
>
>     INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
>     schedule_work(&state->commit_work);

Thanks for helping figuring this out.

> Mark Kettenis on Thu, May 30 2019:
> > I wonder whether the issue is that on OpenBSD we use a single-threaded
> > task queue, where Linux is pretty much always multi-threaded.  That
> > means that on OpenBSD, if a task blocks, no other task can run.  At
> > some point I ran into that issue, but worked around it by using an
> > additional task queue.
>
> I'm pretty sure that this is accurate and using an additional queue
> would fix it (see below).
>
> > I believe Linux uses a thread per cpu.  I think that means there is
> > actually a bug in the Linux code somewhere but nobody notices because
> > most systems have more than one cpu.
>
> Yes, I think so, unless Linux dynamically spawns new workers when
> the "worker pool" runs out or something.
>
> > Making the task queues multi-threaded on OpenBSD is hard since it
> > breaks the synchronization mechanism such as takq_barrier(9).
>
> Agreed.
>
>
> In summary, I see three main options for fixing this:
>
> 1. Multithread the work queue somehow. A few tricks come to mind, but
>    like you say, it's going to be fiddly.*
>
> 2. Put the cleanup tasks in their own queue. The rationale being that
>    this properly assigns a worker to the third stage of the pipeline.
>
> 3. Only defer cleanups in the nonblocking case. Rationale: This is
>    arguably expected behavior out of a blocking call and if you care
>    about the latency introduced by the cleanup, then you probably also
>    care about the setup and are doing nonblocking calls already.**
>
>    Note that the nonblocking case will not stall, because nonblocking
>    commits go on system_unbound_wq or modeset_wq. Cleanups therefore end
>    up separated on system_wq. In fact, there is a comment that seems to
>    echo this in drm_atomic_helper_commit():
>
>        /* [...]
>         * NOTE: Commit work has multiple phases, first hardware commit, then
>         * cleanup. We want them to overlap, hence need system_unbound_wq to
>         * make sure work items don't artifically stall on each another.
>         */
>
> I'm attaching diffs for options 2 and 3. Both work for me.

Nice.  Nevertheless, I think we need to implement option 1.  We want
to keep the local diffs to a bare minimum such that we can easily diff
the code to the Linux DRM code.

I have some ideas, essentially wrapping the native OpenBSD task/taskq
interface to implement a more Linuxy behaviour.  But it will take me
some time to figure out the details.

> * For example: In wait_for_completion(), before going to sleep, check
>   whether we are a queue worker and if so, quickly spawn another to
>   continue in our place.
>
> ** I guess the prime example would be fancy compositors that potentially
>    shout an ioctl at the kernel every frame. I have not checked whether
>    they do blocking or nonblocking calls.
>
>
> [2:text/x-patch Hide]
>
> Index: dev/pci/drm/i915/i915_drv.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/pci/drm/i915/i915_drv.c,v
> retrieving revision 1.118
> diff -u -p -r1.118 i915_drv.c
> --- dev/pci/drm/i915/i915_drv.c 8 May 2019 15:55:56 -0000 1.118
> +++ dev/pci/drm/i915/i915_drv.c 3 Jun 2019 19:04:30 -0000
> @@ -869,8 +869,14 @@ static int i915_workqueues_init(struct d
>   if (dev_priv->hotplug.dp_wq == NULL)
>   goto out_free_wq;
>  
> + dev_priv->cleanup_wq = alloc_ordered_workqueue("i915-cleanup", 0);
> + if (dev_priv->cleanup_wq == NULL)
> + goto out_free_wq2;
> +
>   return 0;
>  
> +out_free_wq2:
> + destroy_workqueue(dev_priv->hotplug.dp_wq);
>  out_free_wq:
>   destroy_workqueue(dev_priv->wq);
>  out_err:
> Index: dev/pci/drm/i915/i915_drv.h
> ===================================================================
> RCS file: /cvs/src/sys/dev/pci/drm/i915/i915_drv.h,v
> retrieving revision 1.82
> diff -u -p -r1.82 i915_drv.h
> --- dev/pci/drm/i915/i915_drv.h 4 May 2019 11:34:47 -0000 1.82
> +++ dev/pci/drm/i915/i915_drv.h 3 Jun 2019 19:04:30 -0000
> @@ -1876,6 +1876,9 @@ struct inteldrm_softc {
>   /* ordered wq for modesets */
>   struct workqueue_struct *modeset_wq;
>  
> + /* ordered wq for cleanups */
> + struct workqueue_struct *cleanup_wq;
> +
>   /* Display functions */
>   struct drm_i915_display_funcs display;
>  
> Index: dev/pci/drm/i915/intel_display.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
> retrieving revision 1.63
> diff -u -p -r1.63 intel_display.c
> --- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
> +++ dev/pci/drm/i915/intel_display.c 3 Jun 2019 19:04:31 -0000
> @@ -12761,9 +12761,14 @@ static void intel_atomic_commit_tail(str
>   * deferring to a new worker seems overkill, but we would place a
>   * schedule point (cond_resched()) here anyway to keep latencies
>   * down.
> + *
> + * NOTE: Some driver code paths (e.g. i915_driver_register) perform
> + * blocking commits (via drm_atomic_commit) from system_wq tasks while
> + * nonblocking commits use system_unbound_wq or our own modeset_wq.
> + * Deferring cleanup to the same queue could cause workers to deadlock.
>   */
>   INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
> - schedule_work(&state->commit_work);
> + queue_work(dev_priv->cleanup_wq, &state->commit_work);
>  }
>  
>  static void intel_atomic_commit_work(struct work_struct *work)
>
> [3:text/x-patch Hide]
>
> Index: dev/pci/drm/i915/intel_display.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_display.c,v
> retrieving revision 1.63
> diff -u -p -r1.63 intel_display.c
> --- dev/pci/drm/i915/intel_display.c 14 Apr 2019 10:14:52 -0000 1.63
> +++ dev/pci/drm/i915/intel_display.c 3 Jun 2019 18:33:39 -0000
> @@ -12586,10 +12586,8 @@ static void intel_atomic_commit_fence_wa
>  #endif
>  }
>  
> -static void intel_atomic_cleanup_work(struct work_struct *work)
> +static void intel_atomic_cleanup(struct drm_atomic_state *state)
>  {
> - struct drm_atomic_state *state =
> - container_of(work, struct drm_atomic_state, commit_work);
>   struct drm_i915_private *i915 = to_i915(state->dev);
>  
>   drm_atomic_helper_cleanup_planes(&i915->drm, state);
> @@ -12599,7 +12597,15 @@ static void intel_atomic_cleanup_work(st
>   intel_atomic_helper_free_state(i915);
>  }
>  
> -static void intel_atomic_commit_tail(struct drm_atomic_state *state)
> +static void intel_atomic_cleanup_work(struct work_struct *work)
> +{
> + struct drm_atomic_state *state =
> + container_of(work, struct drm_atomic_state, commit_work);
> +
> + intel_atomic_cleanup(state);
> +}
> +
> +static void intel_atomic_commit_tail(struct drm_atomic_state *state, bool nonblock)
>  {
>   struct drm_device *dev = state->dev;
>   struct intel_atomic_state *intel_state = to_intel_atomic_state(state);
> @@ -12754,16 +12760,22 @@ static void intel_atomic_commit_tail(str
>   intel_display_power_put(dev_priv, POWER_DOMAIN_MODESET);
>   }
>  
> - /*
> - * Defer the cleanup of the old state to a separate worker to not
> - * impede the current task (userspace for blocking modesets) that
> - * are executed inline. For out-of-line asynchronous modesets/flips,
> - * deferring to a new worker seems overkill, but we would place a
> - * schedule point (cond_resched()) here anyway to keep latencies
> - * down.
> - */
> - INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
> - schedule_work(&state->commit_work);
> + if (nonblock) {
> + /*
> + * Defer the cleanup of the old state to a separate worker to
> + * keep latencies down.
> + */
> + INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
> + schedule_work(&state->commit_work);
> + } else {
> + /*
> + * NOTE: Some driver code paths (e.g. i915_driver_register)
> + * perform blocking commits (via drm_atomic_commit) from
> + * system_wq tasks. Deferring cleanup to system_wq as well
> + * could cause workers to deadlock.
> + */
> + intel_atomic_cleanup(state);
> + }
>  }
>  
>  static void intel_atomic_commit_work(struct work_struct *work)
> @@ -12771,7 +12783,7 @@ static void intel_atomic_commit_work(str
>   struct drm_atomic_state *state =
>   container_of(work, struct drm_atomic_state, commit_work);
>  
> - intel_atomic_commit_tail(state);
> + intel_atomic_commit_tail(state, true);
>  }
>  
>  static int __i915_sw_fence_call
> @@ -12906,7 +12918,7 @@ static int intel_atomic_commit(struct dr
>   } else {
>   if (intel_state->modeset)
>   flush_workqueue(dev_priv->modeset_wq);
> - intel_atomic_commit_tail(state);
> + intel_atomic_commit_tail(state, false);
>   }
>  
>   return 0;

Reply | Threaded
Open this post in threaded view
|

Re: inteldrm: cleanup_done timed out with external monitor

Mark Kettenis
> Date: Mon, 3 Jun 2019 23:00:31 +0200 (CEST)
> From: Mark Kettenis <[hidden email]>
>
> > From: "Sven M. Hallberg" <[hidden email]>
> > Date: Mon, 03 Jun 2019 21:20:29 +0200
> >
> > I've spent some more time poking through the drm code and think I have a
> > good picture now of what is going on.
> >
> > The inteldrm (i915) driver is essentially implementing a three-stage
> > pipeline: setup - hardware - cleanup.
> >
> > The first and second stage are perfomed in the originating
> > thread/process (so usually an ioctl from userspace) unless
> > nonblocking behavior has been requested. In that case, only setup is
> > performed in the originating context and hardware is deferred to either
> > 'system_unbound_wq' or a special 'modeset_wq'.
> >
> > sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit():
> >
> >     if (nonblock && intel_state->modeset) {
> >             queue_work(dev_priv->modeset_wq, &state->commit_work);
> >     } else if (nonblock) {
> >             queue_work(system_unbound_wq, &state->commit_work);
> >     } else {
> >             if (intel_state->modeset)
> >                 flush_workqueue(dev_priv->modeset_wq);
> >             intel_atomic_commit_tail(state);
> >     }
> >
> > This mirrors the generic (reference/example?) implementation
> > sys/dev/pci/drm/drm_atomic_helper.c drm_atomic_helper_commit():
> >
> >     if (nonblock)
> >             queue_work(system_unbound_wq, &state->commit_work);
> >     else
> >             commit_tail(state);
> >
> > Finally, the cleanup stage is deferred by i915 to 'system_wq'.
> > sys/dev/pci/drm/i915/intel_display.c intel_atomic_commit_tail():
> >
> >     INIT_WORK(&state->commit_work, intel_atomic_cleanup_work);
> >     schedule_work(&state->commit_work);
>
> Thanks for helping figuring this out.
>
> > Mark Kettenis on Thu, May 30 2019:
> > In summary, I see three main options for fixing this:
> >
> > 1. Multithread the work queue somehow. A few tricks come to mind, but
> >    like you say, it's going to be fiddly.*
> >
> > 2. Put the cleanup tasks in their own queue. The rationale being that
> >    this properly assigns a worker to the third stage of the pipeline.
> >
> > 3. Only defer cleanups in the nonblocking case. Rationale: This is
> >    arguably expected behavior out of a blocking call and if you care
> >    about the latency introduced by the cleanup, then you probably also
> >    care about the setup and are doing nonblocking calls already.**
> >
> >    Note that the nonblocking case will not stall, because nonblocking
> >    commits go on system_unbound_wq or modeset_wq. Cleanups therefore end
> >    up separated on system_wq. In fact, there is a comment that seems to
> >    echo this in drm_atomic_helper_commit():
> >
> >        /* [...]
> >         * NOTE: Commit work has multiple phases, first hardware commit, then
> >         * cleanup. We want them to overlap, hence need system_unbound_wq to
> >         * make sure work items don't artifically stall on each another.
> >         */
> >
> > I'm attaching diffs for options 2 and 3. Both work for me.
>
> Nice.  Nevertheless, I think we need to implement option 1.  We want
> to keep the local diffs to a bare minimum such that we can easily diff
> the code to the Linux DRM code.
>
> I have some ideas, essentially wrapping the native OpenBSD task/taskq
> interface to implement a more Linuxy behaviour.  But it will take me
> some time to figure out the details.

I just posted a diff that implements option 1 to tech@.  It is
included below for your convenience.  Can you give this a go?


Index: dev/pci/drm/drm_linux.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/drm_linux.c,v
retrieving revision 1.38
diff -u -p -r1.38 drm_linux.c
--- dev/pci/drm/drm_linux.c 9 Jun 2019 12:58:30 -0000 1.38
+++ dev/pci/drm/drm_linux.c 11 Jun 2019 18:54:38 -0000
@@ -1399,15 +1399,15 @@ drm_linux_init(void)
 {
  if (system_wq == NULL) {
  system_wq = (struct workqueue_struct *)
-    taskq_create("drmwq", 1, IPL_HIGH, 0);
+    taskq_create("drmwq", 4, IPL_HIGH, 0);
  }
  if (system_unbound_wq == NULL) {
  system_unbound_wq = (struct workqueue_struct *)
-    taskq_create("drmubwq", 1, IPL_HIGH, 0);
+    taskq_create("drmubwq", 4, IPL_HIGH, 0);
  }
  if (system_long_wq == NULL) {
  system_long_wq = (struct workqueue_struct *)
-    taskq_create("drmlwq", 1, IPL_HIGH, 0);
+    taskq_create("drmlwq", 4, IPL_HIGH, 0);
  }
 
  if (taskletq == NULL)
Index: dev/pci/drm/i915/intel_hotplug.c
===================================================================
RCS file: /cvs/src/sys/dev/pci/drm/i915/intel_hotplug.c,v
retrieving revision 1.2
diff -u -p -r1.2 intel_hotplug.c
--- dev/pci/drm/i915/intel_hotplug.c 14 Apr 2019 10:14:52 -0000 1.2
+++ dev/pci/drm/i915/intel_hotplug.c 11 Jun 2019 18:54:38 -0000
@@ -619,7 +619,6 @@ void intel_hpd_init_work(struct drm_i915
  INIT_WORK(&dev_priv->hotplug.hotplug_work, i915_hotplug_work_func);
  INIT_WORK(&dev_priv->hotplug.dig_port_work, i915_digport_work_func);
  INIT_WORK(&dev_priv->hotplug.poll_init_work, i915_hpd_poll_init_work);
- dev_priv->hotplug.poll_init_work.tq = systq;
  INIT_DELAYED_WORK(&dev_priv->hotplug.reenable_work,
   intel_hpd_irq_storm_reenable_work);
 }
Index: kern/kern_task.c
===================================================================
RCS file: /cvs/src/sys/kern/kern_task.c,v
retrieving revision 1.25
diff -u -p -r1.25 kern_task.c
--- kern/kern_task.c 28 Apr 2019 04:20:40 -0000 1.25
+++ kern/kern_task.c 11 Jun 2019 18:54:39 -0000
@@ -43,6 +43,7 @@ struct taskq {
  TQ_S_DESTROYED
  } tq_state;
  unsigned int tq_running;
+ unsigned int tq_barrier;
  unsigned int tq_nthreads;
  unsigned int tq_flags;
  const char *tq_name;
@@ -59,6 +60,7 @@ static const char taskq_sys_name[] = "sy
 struct taskq taskq_sys = {
  TQ_S_CREATED,
  0,
+ 0,
  1,
  0,
  taskq_sys_name,
@@ -77,6 +79,7 @@ static const char taskq_sys_mp_name[] =
 struct taskq taskq_sys_mp = {
  TQ_S_CREATED,
  0,
+ 0,
  1,
  TASKQ_MPSAFE,
  taskq_sys_mp_name,
@@ -122,6 +125,7 @@ taskq_create(const char *name, unsigned
 
  tq->tq_state = TQ_S_CREATED;
  tq->tq_running = 0;
+ tq->tq_barrier = 0;
  tq->tq_nthreads = nthreads;
  tq->tq_name = name;
  tq->tq_flags = flags;
@@ -161,6 +165,7 @@ taskq_destroy(struct taskq *tq)
  panic("unexpected %s tq state %u", tq->tq_name, tq->tq_state);
  }
 
+ tq->tq_barrier = 0;
  while (tq->tq_running > 0) {
  wakeup(tq);
  msleep(&tq->tq_running, &tq->tq_mtx, PWAIT, "tqdestroy", 0);
@@ -223,6 +228,7 @@ taskq_barrier(struct taskq *tq)
 
  WITNESS_CHECKORDER(&tq->tq_lock_object, LOP_NEWORDER, NULL);
 
+ SET(t.t_flags, TASK_BARRIER);
  task_add(tq, &t);
  cond_wait(&c, "tqbar");
 }
@@ -238,6 +244,7 @@ taskq_del_barrier(struct taskq *tq, stru
  if (task_del(tq, del))
  return;
 
+ SET(t.t_flags, TASK_BARRIER);
  task_add(tq, &t);
  cond_wait(&c, "tqbar");
 }
@@ -304,6 +311,7 @@ taskq_next_work(struct taskq *tq, struct
  struct task *next;
 
  mtx_enter(&tq->tq_mtx);
+retry:
  while ((next = TAILQ_FIRST(&tq->tq_worklist)) == NULL) {
  if (tq->tq_state != TQ_S_RUNNING) {
  mtx_leave(&tq->tq_mtx);
@@ -311,6 +319,17 @@ taskq_next_work(struct taskq *tq, struct
  }
 
  msleep(tq, &tq->tq_mtx, PWAIT, "bored", 0);
+ }
+
+ if (ISSET(next->t_flags, TASK_BARRIER)) {
+ if (++tq->tq_barrier == tq->tq_nthreads) {
+ tq->tq_barrier = 0;
+ wakeup(tq);
+ } else {
+ while (tq->tq_barrier > 0)
+ msleep(tq, &tq->tq_mtx, PWAIT, "tqblk", 0);
+ goto retry;
+ }
  }
 
  TAILQ_REMOVE(&tq->tq_worklist, next, t_entry);
Index: sys/task.h
===================================================================
RCS file: /cvs/src/sys/sys/task.h,v
retrieving revision 1.15
diff -u -p -r1.15 task.h
--- sys/task.h 28 Apr 2019 04:20:40 -0000 1.15
+++ sys/task.h 11 Jun 2019 18:54:39 -0000
@@ -31,6 +31,7 @@ struct task {
 };
 
 #define TASK_ONQUEUE 1
+#define TASK_BARRIER 2
 
 TAILQ_HEAD(task_list, task);