| Message ID | 1424410412-24910-1-git-send-email-benjamin.widawsky@intel.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
2015-02-20 3:33 GMT-02:00 Ben Widawsky <benjamin.widawsky@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@gmail.com> > Signed-off-by: Ben Widawsky <ben@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 >
On Fri, Feb 20, 2015 at 09:55:09AM -0200, Paulo Zanoni wrote: > 2015-02-20 3:33 GMT-02:00 Ben Widawsky <benjamin.widawsky@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. In this case it is probably better to look at the automatic oneshot mmio_debug patch. -Chris
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); } }
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@gmail.com> Signed-off-by: Ben Widawsky <ben@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(-)