Message ID | 1470983123-22127-11-git-send-email-akash.goel@intel.com (mailing list archive) |
---|---|
State | New, archived |
Headers | show |
On 12/08/16 07:25, akash.goel@intel.com wrote: > From: Akash Goel <akash.goel@intel.com> > > GuC firmware sends an interrupt to flush the log buffer when it > becomes half full. GuC firmware also tracks how many times the > buffer overflowed. > It would be useful to maintain a statistics of how many flush > interrupts were received and for which type of log buffer, > along with the overflow count of each buffer type. > Augmented i915_log_info debugfs to report back these statistics. > > v2: > - Update the logic to detect multiple overflows between the 2 > flush interrupts and also log a message for overflow (Tvrtko) > - Track the number of times there was no free sub buffer to capture > the GuC log buffer. (Tvrtko) > > Signed-off-by: Akash Goel <akash.goel@intel.com> > --- > drivers/gpu/drm/i915/i915_debugfs.c | 28 ++++++++++++++++++++++++++++ > drivers/gpu/drm/i915/i915_guc_submission.c | 19 +++++++++++++++++++ > drivers/gpu/drm/i915/i915_irq.c | 2 ++ > drivers/gpu/drm/i915/intel_guc.h | 7 +++++++ > 4 files changed, 56 insertions(+) > > diff --git a/drivers/gpu/drm/i915/i915_debugfs.c b/drivers/gpu/drm/i915/i915_debugfs.c > index 51b59d5..14e0dcf 100644 > --- a/drivers/gpu/drm/i915/i915_debugfs.c > +++ b/drivers/gpu/drm/i915/i915_debugfs.c > @@ -2539,6 +2539,32 @@ static int i915_guc_load_status_info(struct seq_file *m, void *data) > return 0; > } > > +static void i915_guc_log_info(struct seq_file *m, > + struct drm_i915_private *dev_priv) > +{ > + struct intel_guc *guc = &dev_priv->guc; > + > + seq_printf(m, "\nGuC logging stats:\n"); > + > + seq_printf(m, "\tISR: flush count %10u, overflow count %8u\n", > + guc->log.flush_count[GUC_ISR_LOG_BUFFER], > + guc->log.total_overflow_count[GUC_ISR_LOG_BUFFER]); > + > + seq_printf(m, "\tDPC: flush count %10u, overflow count %8u\n", > + guc->log.flush_count[GUC_DPC_LOG_BUFFER], > + guc->log.total_overflow_count[GUC_DPC_LOG_BUFFER]); > + > + seq_printf(m, "\tCRASH: flush count %10u, overflow count %8u\n", > + guc->log.flush_count[GUC_CRASH_DUMP_LOG_BUFFER], > + guc->log.total_overflow_count[GUC_CRASH_DUMP_LOG_BUFFER]); Why is the width for overflow only 8 chars and not 10 like for flush since both are u32? > + > + seq_printf(m, "\tTotal flush interrupt count: %u\n", > + guc->log.flush_interrupt_count); > + > + seq_printf(m, "\tCapture miss count: %u\n", > + guc->log.capture_miss_count); > +} > + > static void i915_guc_client_info(struct seq_file *m, > struct drm_i915_private *dev_priv, > struct i915_guc_client *client) > @@ -2613,6 +2639,8 @@ static int i915_guc_info(struct seq_file *m, void *data) > seq_printf(m, "\nGuC execbuf client @ %p:\n", guc.execbuf_client); > i915_guc_client_info(m, dev_priv, &client); > > + i915_guc_log_info(m, dev_priv); > + > /* Add more as required ... */ > > return 0; > diff --git a/drivers/gpu/drm/i915/i915_guc_submission.c b/drivers/gpu/drm/i915/i915_guc_submission.c > index cb9672b..1ca1866 100644 > --- a/drivers/gpu/drm/i915/i915_guc_submission.c > +++ b/drivers/gpu/drm/i915/i915_guc_submission.c > @@ -913,6 +913,24 @@ static void guc_read_update_log_buffer(struct intel_guc *guc) > sizeof(struct guc_log_buffer_state)); > buffer_size = log_buffer_state_local.size; > > + guc->log.flush_count[i] += log_buffer_state_local.flush_to_file; > + if (log_buffer_state_local.buffer_full_cnt != > + guc->log.prev_overflow_count[i]) { > + guc->log.total_overflow_count[i] += > + (log_buffer_state_local.buffer_full_cnt - > + guc->log.prev_overflow_count[i]); > + > + if (log_buffer_state_local.buffer_full_cnt < > + guc->log.prev_overflow_count[i]) { > + /* buffer_full_cnt is a 4 bit counter */ > + guc->log.total_overflow_count[i] += 16; > + } > + > + guc->log.prev_overflow_count[i] = > + log_buffer_state_local.buffer_full_cnt; > + DRM_ERROR_RATELIMITED("GuC log buffer overflow\n"); > + } > + > if (log_buffer_snapshot_state) { > /* First copy the state structure in local buffer */ > memcpy(log_buffer_snapshot_state, &log_buffer_state_local, > @@ -953,6 +971,7 @@ static void guc_read_update_log_buffer(struct intel_guc *guc) > * getting consumed by User at a slow rate. > */ > DRM_ERROR_RATELIMITED("no sub-buffer to capture log buffer\n"); > + guc->log.capture_miss_count++; > } > } > > diff --git a/drivers/gpu/drm/i915/i915_irq.c b/drivers/gpu/drm/i915/i915_irq.c > index d4d6f0a..b08d1d2 100644 > --- a/drivers/gpu/drm/i915/i915_irq.c > +++ b/drivers/gpu/drm/i915/i915_irq.c > @@ -1705,6 +1705,8 @@ static void gen9_guc_irq_handler(struct drm_i915_private *dev_priv, u32 gt_iir) > /* Handle flush interrupt event in bottom half */ > queue_work(dev_priv->guc.log.wq, > &dev_priv->guc.events_work); > + > + dev_priv->guc.log.flush_interrupt_count++; > } > } > } > diff --git a/drivers/gpu/drm/i915/intel_guc.h b/drivers/gpu/drm/i915/intel_guc.h > index e4ec8d8..ed87e98 100644 > --- a/drivers/gpu/drm/i915/intel_guc.h > +++ b/drivers/gpu/drm/i915/intel_guc.h > @@ -127,6 +127,13 @@ struct intel_guc_log { > struct workqueue_struct *wq; > void *buf_addr; > struct rchan *relay_chan; > + > + /* logging related stats */ > + u32 capture_miss_count; > + u32 flush_interrupt_count; > + u32 prev_overflow_count[GUC_MAX_LOG_BUFFER]; > + u32 total_overflow_count[GUC_MAX_LOG_BUFFER]; > + u32 flush_count[GUC_MAX_LOG_BUFFER]; > }; > > struct intel_guc { > Either if the formatting widths above are fine or you adjust them: Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com> Regards, Tvrtko
On 8/12/2016 7:56 PM, Tvrtko Ursulin wrote: > > On 12/08/16 07:25, akash.goel@intel.com wrote: >> From: Akash Goel <akash.goel@intel.com> >> >> GuC firmware sends an interrupt to flush the log buffer when it >> becomes half full. GuC firmware also tracks how many times the >> buffer overflowed. >> It would be useful to maintain a statistics of how many flush >> interrupts were received and for which type of log buffer, >> along with the overflow count of each buffer type. >> Augmented i915_log_info debugfs to report back these statistics. >> >> v2: >> - Update the logic to detect multiple overflows between the 2 >> flush interrupts and also log a message for overflow (Tvrtko) >> - Track the number of times there was no free sub buffer to capture >> the GuC log buffer. (Tvrtko) >> >> Signed-off-by: Akash Goel <akash.goel@intel.com> >> --- >> drivers/gpu/drm/i915/i915_debugfs.c | 28 >> ++++++++++++++++++++++++++++ >> drivers/gpu/drm/i915/i915_guc_submission.c | 19 +++++++++++++++++++ >> drivers/gpu/drm/i915/i915_irq.c | 2 ++ >> drivers/gpu/drm/i915/intel_guc.h | 7 +++++++ >> 4 files changed, 56 insertions(+) >> >> diff --git a/drivers/gpu/drm/i915/i915_debugfs.c >> b/drivers/gpu/drm/i915/i915_debugfs.c >> index 51b59d5..14e0dcf 100644 >> --- a/drivers/gpu/drm/i915/i915_debugfs.c >> +++ b/drivers/gpu/drm/i915/i915_debugfs.c >> @@ -2539,6 +2539,32 @@ static int i915_guc_load_status_info(struct >> seq_file *m, void *data) >> return 0; >> } >> >> +static void i915_guc_log_info(struct seq_file *m, >> + struct drm_i915_private *dev_priv) >> +{ >> + struct intel_guc *guc = &dev_priv->guc; >> + >> + seq_printf(m, "\nGuC logging stats:\n"); >> + >> + seq_printf(m, "\tISR: flush count %10u, overflow count %8u\n", >> + guc->log.flush_count[GUC_ISR_LOG_BUFFER], >> + guc->log.total_overflow_count[GUC_ISR_LOG_BUFFER]); >> + >> + seq_printf(m, "\tDPC: flush count %10u, overflow count %8u\n", >> + guc->log.flush_count[GUC_DPC_LOG_BUFFER], >> + guc->log.total_overflow_count[GUC_DPC_LOG_BUFFER]); >> + >> + seq_printf(m, "\tCRASH: flush count %10u, overflow count %8u\n", >> + guc->log.flush_count[GUC_CRASH_DUMP_LOG_BUFFER], >> + guc->log.total_overflow_count[GUC_CRASH_DUMP_LOG_BUFFER]); > > Why is the width for overflow only 8 chars and not 10 like for flush > since both are u32? Looks to be a discrepancy. I will check. Both should be 10 as per the max value of u32, which takes 10 digits in decimal form. > >> + >> + seq_printf(m, "\tTotal flush interrupt count: %u\n", >> + guc->log.flush_interrupt_count); >> + >> + seq_printf(m, "\tCapture miss count: %u\n", >> + guc->log.capture_miss_count); >> +} >> + >> static void i915_guc_client_info(struct seq_file *m, >> struct drm_i915_private *dev_priv, >> struct i915_guc_client *client) >> @@ -2613,6 +2639,8 @@ static int i915_guc_info(struct seq_file *m, >> void *data) >> seq_printf(m, "\nGuC execbuf client @ %p:\n", guc.execbuf_client); >> i915_guc_client_info(m, dev_priv, &client); >> >> + i915_guc_log_info(m, dev_priv); >> + >> /* Add more as required ... */ >> >> return 0; >> diff --git a/drivers/gpu/drm/i915/i915_guc_submission.c >> b/drivers/gpu/drm/i915/i915_guc_submission.c >> index cb9672b..1ca1866 100644 >> --- a/drivers/gpu/drm/i915/i915_guc_submission.c >> +++ b/drivers/gpu/drm/i915/i915_guc_submission.c >> @@ -913,6 +913,24 @@ static void guc_read_update_log_buffer(struct >> intel_guc *guc) >> sizeof(struct guc_log_buffer_state)); >> buffer_size = log_buffer_state_local.size; >> >> + guc->log.flush_count[i] += log_buffer_state_local.flush_to_file; >> + if (log_buffer_state_local.buffer_full_cnt != >> + guc->log.prev_overflow_count[i]) { >> + guc->log.total_overflow_count[i] += >> + (log_buffer_state_local.buffer_full_cnt - >> + guc->log.prev_overflow_count[i]); >> + >> + if (log_buffer_state_local.buffer_full_cnt < >> + guc->log.prev_overflow_count[i]) { >> + /* buffer_full_cnt is a 4 bit counter */ >> + guc->log.total_overflow_count[i] += 16; >> + } >> + >> + guc->log.prev_overflow_count[i] = >> + log_buffer_state_local.buffer_full_cnt; >> + DRM_ERROR_RATELIMITED("GuC log buffer overflow\n"); >> + } >> + >> if (log_buffer_snapshot_state) { >> /* First copy the state structure in local buffer */ >> memcpy(log_buffer_snapshot_state, &log_buffer_state_local, >> @@ -953,6 +971,7 @@ static void guc_read_update_log_buffer(struct >> intel_guc *guc) >> * getting consumed by User at a slow rate. >> */ >> DRM_ERROR_RATELIMITED("no sub-buffer to capture log buffer\n"); >> + guc->log.capture_miss_count++; >> } >> } >> >> diff --git a/drivers/gpu/drm/i915/i915_irq.c >> b/drivers/gpu/drm/i915/i915_irq.c >> index d4d6f0a..b08d1d2 100644 >> --- a/drivers/gpu/drm/i915/i915_irq.c >> +++ b/drivers/gpu/drm/i915/i915_irq.c >> @@ -1705,6 +1705,8 @@ static void gen9_guc_irq_handler(struct >> drm_i915_private *dev_priv, u32 gt_iir) >> /* Handle flush interrupt event in bottom half */ >> queue_work(dev_priv->guc.log.wq, >> &dev_priv->guc.events_work); >> + >> + dev_priv->guc.log.flush_interrupt_count++; >> } >> } >> } >> diff --git a/drivers/gpu/drm/i915/intel_guc.h >> b/drivers/gpu/drm/i915/intel_guc.h >> index e4ec8d8..ed87e98 100644 >> --- a/drivers/gpu/drm/i915/intel_guc.h >> +++ b/drivers/gpu/drm/i915/intel_guc.h >> @@ -127,6 +127,13 @@ struct intel_guc_log { >> struct workqueue_struct *wq; >> void *buf_addr; >> struct rchan *relay_chan; >> + >> + /* logging related stats */ >> + u32 capture_miss_count; >> + u32 flush_interrupt_count; >> + u32 prev_overflow_count[GUC_MAX_LOG_BUFFER]; >> + u32 total_overflow_count[GUC_MAX_LOG_BUFFER]; >> + u32 flush_count[GUC_MAX_LOG_BUFFER]; >> }; >> >> struct intel_guc { >> > > Either if the formatting widths above are fine or you adjust them: > > Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > > Regards, > > Tvrtko > >
diff --git a/drivers/gpu/drm/i915/i915_debugfs.c b/drivers/gpu/drm/i915/i915_debugfs.c index 51b59d5..14e0dcf 100644 --- a/drivers/gpu/drm/i915/i915_debugfs.c +++ b/drivers/gpu/drm/i915/i915_debugfs.c @@ -2539,6 +2539,32 @@ static int i915_guc_load_status_info(struct seq_file *m, void *data) return 0; } +static void i915_guc_log_info(struct seq_file *m, + struct drm_i915_private *dev_priv) +{ + struct intel_guc *guc = &dev_priv->guc; + + seq_printf(m, "\nGuC logging stats:\n"); + + seq_printf(m, "\tISR: flush count %10u, overflow count %8u\n", + guc->log.flush_count[GUC_ISR_LOG_BUFFER], + guc->log.total_overflow_count[GUC_ISR_LOG_BUFFER]); + + seq_printf(m, "\tDPC: flush count %10u, overflow count %8u\n", + guc->log.flush_count[GUC_DPC_LOG_BUFFER], + guc->log.total_overflow_count[GUC_DPC_LOG_BUFFER]); + + seq_printf(m, "\tCRASH: flush count %10u, overflow count %8u\n", + guc->log.flush_count[GUC_CRASH_DUMP_LOG_BUFFER], + guc->log.total_overflow_count[GUC_CRASH_DUMP_LOG_BUFFER]); + + seq_printf(m, "\tTotal flush interrupt count: %u\n", + guc->log.flush_interrupt_count); + + seq_printf(m, "\tCapture miss count: %u\n", + guc->log.capture_miss_count); +} + static void i915_guc_client_info(struct seq_file *m, struct drm_i915_private *dev_priv, struct i915_guc_client *client) @@ -2613,6 +2639,8 @@ static int i915_guc_info(struct seq_file *m, void *data) seq_printf(m, "\nGuC execbuf client @ %p:\n", guc.execbuf_client); i915_guc_client_info(m, dev_priv, &client); + i915_guc_log_info(m, dev_priv); + /* Add more as required ... */ return 0; diff --git a/drivers/gpu/drm/i915/i915_guc_submission.c b/drivers/gpu/drm/i915/i915_guc_submission.c index cb9672b..1ca1866 100644 --- a/drivers/gpu/drm/i915/i915_guc_submission.c +++ b/drivers/gpu/drm/i915/i915_guc_submission.c @@ -913,6 +913,24 @@ static void guc_read_update_log_buffer(struct intel_guc *guc) sizeof(struct guc_log_buffer_state)); buffer_size = log_buffer_state_local.size; + guc->log.flush_count[i] += log_buffer_state_local.flush_to_file; + if (log_buffer_state_local.buffer_full_cnt != + guc->log.prev_overflow_count[i]) { + guc->log.total_overflow_count[i] += + (log_buffer_state_local.buffer_full_cnt - + guc->log.prev_overflow_count[i]); + + if (log_buffer_state_local.buffer_full_cnt < + guc->log.prev_overflow_count[i]) { + /* buffer_full_cnt is a 4 bit counter */ + guc->log.total_overflow_count[i] += 16; + } + + guc->log.prev_overflow_count[i] = + log_buffer_state_local.buffer_full_cnt; + DRM_ERROR_RATELIMITED("GuC log buffer overflow\n"); + } + if (log_buffer_snapshot_state) { /* First copy the state structure in local buffer */ memcpy(log_buffer_snapshot_state, &log_buffer_state_local, @@ -953,6 +971,7 @@ static void guc_read_update_log_buffer(struct intel_guc *guc) * getting consumed by User at a slow rate. */ DRM_ERROR_RATELIMITED("no sub-buffer to capture log buffer\n"); + guc->log.capture_miss_count++; } } diff --git a/drivers/gpu/drm/i915/i915_irq.c b/drivers/gpu/drm/i915/i915_irq.c index d4d6f0a..b08d1d2 100644 --- a/drivers/gpu/drm/i915/i915_irq.c +++ b/drivers/gpu/drm/i915/i915_irq.c @@ -1705,6 +1705,8 @@ static void gen9_guc_irq_handler(struct drm_i915_private *dev_priv, u32 gt_iir) /* Handle flush interrupt event in bottom half */ queue_work(dev_priv->guc.log.wq, &dev_priv->guc.events_work); + + dev_priv->guc.log.flush_interrupt_count++; } } } diff --git a/drivers/gpu/drm/i915/intel_guc.h b/drivers/gpu/drm/i915/intel_guc.h index e4ec8d8..ed87e98 100644 --- a/drivers/gpu/drm/i915/intel_guc.h +++ b/drivers/gpu/drm/i915/intel_guc.h @@ -127,6 +127,13 @@ struct intel_guc_log { struct workqueue_struct *wq; void *buf_addr; struct rchan *relay_chan; + + /* logging related stats */ + u32 capture_miss_count; + u32 flush_interrupt_count; + u32 prev_overflow_count[GUC_MAX_LOG_BUFFER]; + u32 total_overflow_count[GUC_MAX_LOG_BUFFER]; + u32 flush_count[GUC_MAX_LOG_BUFFER]; }; struct intel_guc {