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

[Paulo Zanoni]

2015-02-20 3:33 GMT-02:00 Ben Widawsky <benjamin.widawsky at intel.com>:
> 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.
>

Register reads can also trigger the unclaimed register error. Don't
you want to also record the last one we read on each CPU too?

Also, just to remind you since you seem to be debugging something:
user space programs (such as intel_reg_dumper or anything else) and
other Kernel modules (like vgacon and others) can also trigger these
errors, and we can't easily catch these cases.

Pinging Chris since he always has some ideas about this code.


> 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
>



-- 
Paulo Zanoni