[Intel-gfx] Performance regression with debug logs spammed with lots of warnings/errors

[Greg Stark]

I updated my kernel to 4.11.0 and my laptop is now very slow and
laggy. I'm not sure if the graphics driver are directly causing the
slowdown or it's just systemd having trouble keeping up with the debug
messages though (systemd is consuming 4% of cpu just dealing with
messages which is impressively inefficient in its own right).

My boot arguments enable debug messages but in previous kernels this
resulted in only a few occasional messages, not a constant stream:

BOOT_IMAGE=/vmlinuz-4.11.0-2-amd64 root=/dev/mapper/pixel-root ro
quiet drm.debug=0xe log_buf_len=1M libata.force=1.5G,noncq

I'm now seeing a stream of messages that look like this:

Jul 30 13:17:17 pixel kernel: [ 3221.841265] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.843773] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.843787] [drm:drm_dp_dpcd_access
[drm_kms_helper]] Too many retries, giving up. First error: -110
Jul 30 13:17:17 pixel kernel: [ 3221.846400] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.848905] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.851411] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.853902] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.856389] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.858864] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.861343] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.863816] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.866289] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.868765] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.871239] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.873714] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.876186] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.880442] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.882931] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.885489] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.887999] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.890487] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.893057] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.895531] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.898063] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.900542] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.903015] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.905550] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.908031] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.914711] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.917199] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.919698] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.922183] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.924766] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.927282] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.929777] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.929790] [drm:drm_dp_dpcd_access
[drm_kms_helper]] Too many retries, giving up. First error: -110
Jul 30 13:17:17 pixel kernel: [ 3221.929812]
[drm:i915_hotplug_work_func [i915]] running encoder hotplug functions
Jul 30 13:17:17 pixel kernel: [ 3221.929831]
[drm:i915_hotplug_work_func [i915]] Connector HDMI-A-1 (pin 7)
received hotplug event.
Jul 30 13:17:17 pixel kernel: [ 3221.929850] [drm:intel_hdmi_detect
[i915]] [CONNECTOR:57:HDMI-A-1]
Jul 30 13:17:17 pixel kernel: [ 3221.935918] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.935936]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.935964] [drm:intel_dp_hpd_pulse
[i915]] got hpd irq on port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.937926] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.937957]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.938488] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.939937] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.939959]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.940993] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.941957] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.941979]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.943491] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.943959] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.943981]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.945969] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.945990]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.946026] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.947988] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.948014]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.948550] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.950631] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.950657]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.951042] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.952624] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.952647]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.953532] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.954638] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.954660]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.956015] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.956648] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.956670]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.958517] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.958662] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.958694]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.960679] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.960712]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.961007] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.962684] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.962705]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.963507] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.964770] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.964840]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.966035] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.968540] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.970758] [drm:intel_get_hpd_pins
[i915]] hotplug event received, stat 0x00800000, dig 0x00111010, pins
0x00000080
Jul 30 13:17:17 pixel kernel: [ 3221.970784]
[drm:intel_hpd_irq_handler [i915]] digital hpd port D - short
Jul 30 13:17:17 pixel kernel: [ 3221.971026] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.973522] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.973978]
[drm:drm_dp_dual_mode_detect [drm_kms_helper]] DP dual mode HDMI ID:
DP-HDMI ADAPTOR\004 (err 0)
Jul 30 13:17:17 pixel kernel: [ 3221.976005] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.977981]
[drm:drm_dp_dual_mode_detect [drm_kms_helper]] DP dual mode adaptor
ID: 44 (err 0)
Jul 30 13:17:17 pixel kernel: [ 3221.978007] [drm:intel_hdmi_set_edid
[i915]] DP dual mode adaptor (type 1 HDMI) detected (max TMDS clock:
165000 kHz)
Jul 30 13:17:17 pixel kernel: [ 3221.978032]
[drm:i915_hotplug_work_func [i915]] Connector DP-1 (pin 7) received
hotplug event.
Jul 30 13:17:17 pixel kernel: [ 3221.978055] [drm:intel_dp_detect
[i915]] [CONNECTOR:60:DP-1]
Jul 30 13:17:17 pixel kernel: [ 3221.978500] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.980989] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.983468] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.985948] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f
Jul 30 13:17:17 pixel kernel: [ 3221.988432] [drm:intel_dp_aux_ch
[i915]] dp_aux_ch timeout status 0x7145003f

-- 
greg