drm_debug_enabled([1]) is the canonical bit-test for drm.debug.

Commit 6ce6fae84536 ("drm_print: optimize drm_debug_enabled for
jump-label") did several things:

A- renamed [1] to drm_debug_enabled_raw()

B- introduced __drm_debug_enabled(), which evald to either 'true' or
   _raw([A]), depending upon [2] CONFIG_DRM_USE_DYNAMIC_DEBUG=y/n.

C- altered *dev_dbg() to call __drm_debug_enabled().

D- redefined [1] to drm_debug_enabled_instrumented().  This called
   _raw(), but added a pr_debug() too.  This allowed us to see how
   where and often remaining callsites were called.

When [2]=y, [B] short-circuited the bit-test, since dyndbg's wrapper
macro had already set the callsite reachable/unreachable.

Later, commit 9fd6f61a297e ("drm/print: add drm_dbg_printer() for drm
device specific printer") added __drm_printfn_dbg(), but mistakenly
used the internal bypass __drm_debug_enabled() instead of the
canonical drm_debug_enabled(). This went unnoticed because at the
time, [2]=y was marked BROKEN.

Because __drm_printfn_dbg() is a shared callback where the callpath is
not directly guarded by dyndbg's static-key, checking the bypass macro
caused it to evaluate to 'true' and always print, ignoring the drm.debug
bit-mask entirely.

This results in a flood of messages in environments with slow serial
consoles, as seen in DRM-CI on i915 CML devices. When IGT causes a
mismatch in intel_pipe_config_compare(), the resulting UART storm
causes a hard timeout after 20 minutes (see below the snip).

To fix this, change __drm_printfn_dbg() to use the explicit
drm_debug_enabled_instrumented() instead. This ensures the bit-test is
performed at runtime for this unguarded helper, stopping the UART storm.

[1] drm_debug_enabled
[2] CONFIG_DRM_USE_DYNAMIC_DEBUG

Fixes: 9fd6f61a297e ("drm/print: add drm_dbg_printer() for drm device specific 
printer")
Signed-off-by: Jim Cromie <[email protected]>
---

some of the many:

 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:57:pipe A] 
fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, 
found 1083)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:57:pipe A] 
fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, 
found 1097)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:57:pipe A] 
fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 
1116)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:57:pipe A] 
fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, 
found 1116)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
112800)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
141000)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
141000)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
61040)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
76300)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 
76300)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in port_clock (expected 0, found 216000)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in port_clock (expected 0, found 216000)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in port_clock (expected 0, found 270000)
 i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe B] 
fastset requirement not met in port_clock (expected 0, found 270000)
---
 drivers/gpu/drm/drm_print.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
index ceede094ff13..b431881de2c1 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -214,7 +214,7 @@ void __drm_printfn_dbg(struct drm_printer *p, struct 
va_format *vaf)
        const struct drm_device *drm = p->arg;
        const struct device *dev = drm ? drm->dev : NULL;
 
-       if (!__drm_debug_enabled(p->category))
+       if (!drm_debug_enabled_instrumented(p->category))
                return;
 
        __drm_dev_vprintk(dev, KERN_DEBUG, p->origin, p->prefix, vaf);
-- 
2.53.0

Reply via email to