[Intel-gfx] [PATCH 1/2] drm/i915: Track last register written (debug)

[Ben Widawsky]

Register writes are supposed to be posted, and therefore "fast." In order to try
to preserve this behavior, the patch uses percpu variables to make the overhead
minimal. The slow data collection is done at error time, and that only occurs if
the user specified mmio_debug=1 module parameter.

I wrote this patch to try to track down annoying and sporadic errors on my
Broadwell laptop. Sometimes it's obvious how you got to this point from the
backtrace, but other times it isn't.

Output looks like this:
[   63.122716] [drm:hsw_unclaimed_reg_detect] *ERROR* Unclaimed register detected. Please use the i915.mmio_debug=1 to debug this problem.
[  658.662961] ------------[ cut here ]------------
...
[  658.663113] ---[ end trace c7f0a18c4d4e027b ]---
[  658.663114] [drm:hsw_unclaimed_reg_debug] *ERROR* Last registers written:
[  658.663115] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00002030
[  658.663116] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00022030
[  658.663117] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00002030
[  658.663118] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00002030
[  658.663119] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00000000
[  658.663120] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00000000
[  658.663121] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00000000
[  658.663122] [drm:hsw_unclaimed_reg_debug] *ERROR* 	0x00000000

The same data is obtainable with using the various perf/ftrace hooks, but that
is a bit larger of a hammer. It's hard to tell how useful this is/would be.

Cc: Paulo Zanoni <przanoni at gmail.com>
Signed-off-by: Ben Widawsky <ben at bwidawsk.net>
---
 drivers/gpu/drm/i915/i915_drv.h     | 11 +++++++++--
 drivers/gpu/drm/i915/intel_uncore.c | 11 ++++++++++-
 2 files changed, 19 insertions(+), 3 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_drv.h b/drivers/gpu/drm/i915/i915_drv.h
index c33327d..6fa22db 100644
--- a/drivers/gpu/drm/i915/i915_drv.h
+++ b/drivers/gpu/drm/i915/i915_drv.h
@@ -2882,10 +2882,17 @@ int vlv_freq_opcode(struct drm_i915_private *dev_priv, int val);
 #define I915_READ16_NOTRACE(reg)	dev_priv->uncore.funcs.mmio_readw(dev_priv, (reg), false)
 #define I915_WRITE16_NOTRACE(reg, val)	dev_priv->uncore.funcs.mmio_writew(dev_priv, (reg), (val), false)
 
+DECLARE_PER_CPU(uint32_t, i915_last_written);
 #define I915_READ(reg)		dev_priv->uncore.funcs.mmio_readl(dev_priv, (reg), true)
-#define I915_WRITE(reg, val)	dev_priv->uncore.funcs.mmio_writel(dev_priv, (reg), (val), true)
+#define I915_WRITE(reg, val)	do {						\
+	dev_priv->uncore.funcs.mmio_writel(dev_priv, (reg), (val), true);	\
+	raw_cpu_write(i915_last_written, reg);					\
+} while (0)
 #define I915_READ_NOTRACE(reg)		dev_priv->uncore.funcs.mmio_readl(dev_priv, (reg), false)
-#define I915_WRITE_NOTRACE(reg, val)	dev_priv->uncore.funcs.mmio_writel(dev_priv, (reg), (val), false)
+#define I915_WRITE_NOTRACE(reg, val)	do {					\
+	dev_priv->uncore.funcs.mmio_writel(dev_priv, (reg), (val), false);	\
+	raw_cpu_write(i915_last_written, reg);					\
+} while (0)
 
 /* Be very careful with read/write 64-bit values. On 32-bit machines, they
  * will be implemented using 2 32-bit writes in an arbitrary order with
diff --git a/drivers/gpu/drm/i915/intel_uncore.c b/drivers/gpu/drm/i915/intel_uncore.c
index b29091b..001ce55 100644
--- a/drivers/gpu/drm/i915/intel_uncore.c
+++ b/drivers/gpu/drm/i915/intel_uncore.c
@@ -33,7 +33,10 @@
 #define __raw_i915_write16(dev_priv__, reg__, val__) writew(val__, (dev_priv__)->regs + (reg__))
 
 #define __raw_i915_read32(dev_priv__, reg__) readl((dev_priv__)->regs + (reg__))
-#define __raw_i915_write32(dev_priv__, reg__, val__) writel(val__, (dev_priv__)->regs + (reg__))
+#define __raw_i915_write32(dev_priv__, reg__, val__) do { \
+	writel(val__, (dev_priv__)->regs + (reg__));	  \
+	raw_cpu_write(i915_last_written, reg__);	  \
+} while (0)
 
 #define __raw_i915_read64(dev_priv__, reg__) readq((dev_priv__)->regs + (reg__))
 #define __raw_i915_write64(dev_priv__, reg__, val__) writeq(val__, (dev_priv__)->regs + (reg__))
@@ -513,6 +516,7 @@ ilk_dummy_write(struct drm_i915_private *dev_priv)
 	__raw_i915_write32(dev_priv, MI_MODE, 0);
 }
 
+DEFINE_PER_CPU(uint32_t, i915_last_written);
 static void
 hsw_unclaimed_reg_debug(struct drm_i915_private *dev_priv, u32 reg, bool read,
 			bool before)
@@ -524,8 +528,13 @@ hsw_unclaimed_reg_debug(struct drm_i915_private *dev_priv, u32 reg, bool read,
 		return;
 
 	if (__raw_i915_read32(dev_priv, FPGA_DBG) & FPGA_DBG_RM_NOCLAIM) {
+		int cpu;
 		WARN(1, "Unclaimed register detected %s %s register 0x%x\n",
 		     when, op, reg);
+		DRM_ERROR("Last registers written:\n");
+		for_each_possible_cpu(cpu)
+			DRM_ERROR("\t0x%08x\n", per_cpu(i915_last_written, cpu));
+
 		__raw_i915_write32(dev_priv, FPGA_DBG, FPGA_DBG_RM_NOCLAIM);
 	}
 }
-- 
2.3.0