Re: X freezes for a second or every now and then when lid closed

[Joel Fernandes <joel-QYYGw3jwrUn5owFQY34kdNi2O/JbrIOy@public.gmane.org>]

On Mon, Oct 29, 2018 at 01:11:30PM +0000, Chris Wilson wrote:
> Quoting Joel Fernandes (2018-10-27 09:14:07)
> > On Sat, Oct 27, 2018 at 12:38:56AM -0700, Joel Fernandes wrote:
> > > Hi!
> > > My Linux laptop running kernel v4.17 freezes intermittently when the laptop
> > > lid is closed but external monitors are connected to 2 HDMI ports. I provided
> > > details on the issue, any idea what could be causing it?
> > > 
> > > I ruled out many different subsystems by trial and error, finally I enabled
> > > ftrace events on power subsystem and see that the freeze is precisely at the
> > > same time as drm_mode_getconnector is called on these events and its the Xorg
> > > process. I think since Xorg is busy on this drm_mode_getconnector ioctl, its
> > > not able to perform its duties.
> > > 
> > > I get a stacktrace like so:
> > >           Xorg-1285  [001] ....   801.156606: pm_qos_update_request:
> > >                pm_qos_class=CPU_DMA_LATENCY value=-1
> > >           Xorg-1285  [001] ....   801.156607: pm_qos_update_target:
> > >                action=UPDATE_REQ prev_value=0 curr_value=2000000000
> > >           Xorg-1285  [001] ....   801.156609: <stack trace>
> > >  => pm_qos_update_target
> > >  => intel_dp_aux_xfer
> > >  => intel_dp_aux_transfer
> > >  => drm_dp_dpcd_access
> > >  => drm_dp_dpcd_read
> > >  => intel_dp_read_dpcd
> > >  => intel_dp_detect
> > >  => drm_helper_probe_single_connector_modes
> > >  => drm_mode_getconnector
> > >  => drm_ioctl_kernel
> > >  => drm_ioctl
> > >  => do_vfs_ioctl
> > >  => ksys_ioctl
> > >  => __x64_sys_ioctl
> > >  => do_syscall_64
> > >  => entry_SYSCALL_64_after_hwframe
> > > 
> > > The X version I'm running is X.Org X Server 1.19.6
> > > 
> > > I also see these in /var/log/Xorg.0.log every 30 seconds and it seems
> > > correlated to the time of freezing:
> > > [  1141.925] (--) modeset(0): HDMI max TMDS frequency 170000KHz
> > > [  1142.223] (II) modeset(0): EDID vendor "HWP", prod id 13093
> > > [  1142.223] (II) modeset(0): Using hsync ranges from config file
> > > [  1142.223] (II) modeset(0): Using vrefresh ranges from config file
> > > [  1142.223] (II) modeset(0): Printing DDC gathered Modelines:
> > > [  1142.223] (II) modeset(0): Modeline "1920x1080"x0.0  148.50  1920 2008
> > > 2052 2200  1080 1084 1089 1125 +hsync +vsync (67.5 kHz eP)
> > > [  1142.223] (II) modeset(0): Modeline "1920x1080"x0.0  148.50  1920 2448
> > > 2492 2640  1080 1084 1089 1125 +hsync +vsync (56.2 kHz e)
> > > 
> > > Let me know if you spot anything weird, and if you have any suggestions?
> > 
> > Just for documenting it, the issue seems very similar to what is reported in
> > this comment:
> > https://forums.linuxmint.com/viewtopic.php?t=253475#p1457587 
> > 
> > I am indeed using Cinammon as well. With the lid closed, the same 'modeset'
> > log messages appear and freeze the system every 30 seconds.
> 
> 30s == hotplug polling kthread; the implication would be that it is
> generating a hotplug uevent everytime. drm.debug=0xe should record what
> it going on, so capture a dmesg with the lid closed.
> 
> Platform and panel HW would be useful to know, dmesg from boot is
> usually sufficient

Thanks a lot Chris. So here is what I get with drm.debug=0xe. Below is a
small part of it close to the "stuck" state. I do see some errors. Any insights are appreciated!
I attached the full dmesg dump here at this link:
https://gist.github.com/joelagnel/72806b2e1a4a0c97e11915315158cbde

[  297.414429] [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:71:eDP-1]
[  297.414497] [drm:intel_dp_detect [i915]] [CONNECTOR:71:eDP-1]
[  297.414560] [drm:intel_dp_print_rates [i915]] source rates: 162000, 216000, 270000, 324000, 432000, 540000
[  297.414610] [drm:intel_dp_print_rates [i915]] sink rates: 162000, 270000
[  297.414656] [drm:intel_dp_print_rates [i915]] common rates: 162000, 270000
[  297.414717] [drm:edp_panel_vdd_on [i915]] Turning eDP port A VDD on
[  297.414771] [drm:wait_panel_power_cycle [i915]] Wait for panel power cycle
[  297.414882] [drm:wait_panel_status [i915]] mask b800000f value 00000000 status 00000000 control 00000000
[  297.414991] [drm:wait_panel_status [i915]] Wait complete
[  297.415102] [drm:edp_panel_vdd_on [i915]] PP_STATUS: 0x00000000 PP_CONTROL: 0x00000008
[  297.415165] [drm:edp_panel_vdd_on [i915]] eDP port A panel power wasn't enabled
[  297.514369] [drm:gen8_de_irq_handler [i915]] hotplug event received, stat 0x01000000, dig 0x12101010, pins 0x00000010
[  297.514429] [drm:intel_hpd_irq_handler [i915]] digital hpd port A - long
[  297.514482] [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 0
[  297.514619] [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP port A
[  297.623908] [drm:drm_dp_read_desc [drm_kms_helper]] DP sink: OUI 00-1c-f8 dev-ID a\006UA\024\001 HW-rev 10.0 SW-rev 1.48 quirks 0x0000
[  297.624283] [drm:drm_add_display_info [drm]] non_desktop set to 0
[  297.624315] [drm:drm_add_edid_modes [drm]] ELD: no CEA Extension found
[  297.624337] [drm:drm_add_display_info [drm]] non_desktop set to 0
[  297.624392] [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:71:eDP-1] probed modes :
[  297.624419] [drm:drm_mode_debug_printmodeline [drm]] Modeline 72:"1920x1080" 60 141000 1920 1936 1952 2104 1080 1083 1097 1116 0x48 0xa
[  297.624884] [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:78:DP-1]
[  297.624943] [drm:intel_dp_detect [i915]] [CONNECTOR:78:DP-1]
[  297.633348] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.641715] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.650081] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.658445] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.666809] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.675174] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.683537] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.691907] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.700270] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.708632] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.716992] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.725352] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.733712] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.742072] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.750432] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.758790] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.767150] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.775509] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.783869] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.792229] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.800588] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.808947] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.817313] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.825671] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.834030] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.842389] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff
[  297.850747] [drm:intel_dp_aux_xfer [i915]] dp_aux_ch timeout status 0x7d4003ff

Right around this, I see the following in Xorg.0.log:

[   297.932] (--) modeset(0): HDMI max TMDS frequency 170000KHz
[   298.231] (II) modeset(0): EDID vendor "HWP", prod id 13093
[   298.231] (II) modeset(0): Using hsync ranges from config file
[   298.231] (II) modeset(0): Using vrefresh ranges from config file
[   298.231] (II) modeset(0): Printing DDC gathered Modelines:
[   298.231] (II) modeset(0): Modeline "1920x1080"x0.0  148.50  1920 2008 2052 2200  1080 1084 1089 1125 +hsync +vsync (67.5 kHz eP)
[   298.231] (II) modeset(0): Modeline "1920x1080"x0.0  148.50  1920 2448 2492 2640  1080 1084 1089 1125 +hsync +vsync (56.2 kHz e)

_______________________________________________
xorg-devel@lists.x.org: X.Org development
Archives: http://lists.x.org/archives/xorg-devel
Info: https://lists.x.org/mailman/listinfo/xorg-devel