drm/i915: Add stats for GuC log buffer flush interrupts
authorAkash Goel <akash.goel@intel.com>
Wed, 12 Oct 2016 16:24:36 +0000 (21:54 +0530)
committerTvrtko Ursulin <tvrtko.ursulin@intel.com>
Tue, 25 Oct 2016 08:34:23 +0000 (09:34 +0100)
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)

v3:
- Fix the printf field width for overflow counter, set it to 10 as per the
  max value of u32, which takes 10 digits in decimal form. (Tvrtko)

v4:
- Move the log buffer overflow handling to a new function for better
  readability. (Tvrtko)

Signed-off-by: Akash Goel <akash.goel@intel.com>
Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
drivers/gpu/drm/i915/i915_debugfs.c
drivers/gpu/drm/i915/i915_guc_submission.c
drivers/gpu/drm/i915/i915_irq.c
drivers/gpu/drm/i915/intel_guc.h

index c5716397da20fb71236630caab1270d3e4293089..e24f69cdc69b3900ba8ab37e408f19ce168cfb84 100644 (file)
@@ -2416,6 +2416,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_puts(m, "\nGuC logging stats:\n");
+
+       seq_printf(m, "\tISR:   flush count %10u, overflow count %10u\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 %10u\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 %10u\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)
@@ -2489,6 +2515,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;
index cafff7ca71c72df658a84a04b368796401e695f5..f2d71cadae99d25eea528f8bb4b577d815d180ad 100644 (file)
@@ -1016,6 +1016,29 @@ static void *guc_get_write_buffer(struct intel_guc *guc)
        return relay_reserve(guc->log.relay_chan, 0);
 }
 
+static bool
+guc_check_log_buf_overflow(struct intel_guc *guc,
+                          enum guc_log_buffer_type type, unsigned int full_cnt)
+{
+       unsigned int prev_full_cnt = guc->log.prev_overflow_count[type];
+       bool overflow = false;
+
+       if (full_cnt != prev_full_cnt) {
+               overflow = true;
+
+               guc->log.prev_overflow_count[type] = full_cnt;
+               guc->log.total_overflow_count[type] += full_cnt - prev_full_cnt;
+
+               if (full_cnt < prev_full_cnt) {
+                       /* buffer_full_cnt is a 4 bit counter */
+                       guc->log.total_overflow_count[type] += 16;
+               }
+               DRM_ERROR_RATELIMITED("GuC log buffer overflow\n");
+       }
+
+       return overflow;
+}
+
 static unsigned int guc_get_log_buffer_size(enum guc_log_buffer_type type)
 {
        switch (type) {
@@ -1036,7 +1059,7 @@ static void guc_read_update_log_buffer(struct intel_guc *guc)
 {
        struct guc_log_buffer_state *log_buf_state, *log_buf_snapshot_state;
        struct guc_log_buffer_state log_buf_state_local;
-       unsigned int buffer_size, write_offset;
+       unsigned int buffer_size, write_offset, full_cnt;
        enum guc_log_buffer_type type;
        void *src_data, *dst_data;
 
@@ -1062,6 +1085,11 @@ static void guc_read_update_log_buffer(struct intel_guc *guc)
                       sizeof(struct guc_log_buffer_state));
                buffer_size = guc_get_log_buffer_size(type);
                write_offset = log_buf_state_local.sampled_write_ptr;
+               full_cnt = log_buf_state_local.buffer_full_cnt;
+
+               /* Bookkeeping stuff */
+               guc->log.flush_count[type] += log_buf_state_local.flush_to_file;
+               guc_check_log_buf_overflow(guc, type, full_cnt);
 
                /* Update the state of shared log buffer */
                log_buf_state->read_ptr = write_offset;
@@ -1099,6 +1127,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 logs\n");
+               guc->log.capture_miss_count++;
        }
 }
 
index 253c22109c3fc99702779b48ac7ad0e1e58f849d..9111cfdf217a66b541179175c39b12a1d69f09d5 100644 (file)
@@ -1691,6 +1691,8 @@ static void gen9_guc_irq_handler(struct drm_i915_private *dev_priv, u32 gt_iir)
                        /* Handle flush interrupt in bottom half */
                        queue_work(dev_priv->guc.log.flush_wq,
                                   &dev_priv->guc.log.flush_work);
+
+                       dev_priv->guc.log.flush_interrupt_count++;
                } else {
                        /* Not clearing of unhandled event bits won't result in
                         * re-triggering of the interrupt.
index 907d13a71c238eaff796657bbe0707d3e392fffa..d034c9845a2269e8a607826e4d35aca0a6e92f1c 100644 (file)
@@ -130,6 +130,13 @@ struct intel_guc_log {
        struct workqueue_struct *flush_wq;
        struct work_struct flush_work;
        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 {