diff mbox

[10/20] drm/i915: Add stats for GuC log buffer flush interrupts

Message ID 1470983123-22127-11-git-send-email-akash.goel@intel.com (mailing list archive)
State New, archived
Headers show

Commit Message

akash.goel@intel.com Aug. 12, 2016, 6:25 a.m. UTC
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(+)

Comments

Tvrtko Ursulin Aug. 12, 2016, 2:26 p.m. UTC | #1
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
akash.goel@intel.com Aug. 12, 2016, 2:56 p.m. UTC | #2
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 mbox

Patch

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 {