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 <jim.cromie@gmail.com>
---
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