[PATCH v5 29/35] drm/i915: Added scheduler statistic reporting to debugfs

[John.C.Harrison@Intel.com]

From: John Harrison <John.C.Harrison@Intel.com>

It is useful for know what the scheduler is doing for both debugging
and performance analysis purposes. This change adds a bunch of
counters and such that keep track of various scheduler operations
(batches submitted, completed, flush requests, etc.). The data can
then be read in userland via the debugfs mechanism.

v2: Updated to match changes to scheduler implementation.

v3: Updated for changes to kill code and flush code.

v4: Removed the fence/sync code as that will be part of a separate
patch series. Wrapped a long line to keep the style checker happy.

v5: Updated to remove forward declarations and white space. Added
documentation. [Joonas Lahtinen]

Used lighter weight spinlocks.

For: VIZ-1587
Signed-off-by: John Harrison <John.C.Harrison@Intel.com>
Cc: Joonas Lahtinen <joonas.lahtinen@linux.intel.com>
---
 drivers/gpu/drm/i915/i915_debugfs.c        | 73 ++++++++++++++++++++++++++++
 drivers/gpu/drm/i915/i915_gem_execbuffer.c |  3 ++
 drivers/gpu/drm/i915/i915_scheduler.c      | 78 ++++++++++++++++++++++++++++--
 drivers/gpu/drm/i915/i915_scheduler.h      | 31 ++++++++++++
 4 files changed, 180 insertions(+), 5 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_debugfs.c b/drivers/gpu/drm/i915/i915_debugfs.c
index 7d01c07..2c8b00f 100644
--- a/drivers/gpu/drm/i915/i915_debugfs.c
+++ b/drivers/gpu/drm/i915/i915_debugfs.c
@@ -3595,6 +3595,78 @@ static int i915_drrs_status(struct seq_file *m, void *unused)
 	return 0;
 }
 
+static int i915_scheduler_info(struct seq_file *m, void *unused)
+{
+	struct drm_info_node *node = (struct drm_info_node *) m->private;
+	struct drm_device *dev = node->minor->dev;
+	struct drm_i915_private *dev_priv = dev->dev_private;
+	struct i915_scheduler   *scheduler = dev_priv->scheduler;
+	struct i915_scheduler_stats *stats = scheduler->stats;
+	struct i915_scheduler_stats_nodes node_stats[I915_NUM_RINGS];
+	struct intel_engine_cs *ring;
+	char   str[50 * (I915_NUM_RINGS + 1)], name[50], *ptr;
+	int ret, i, r;
+
+	ret = mutex_lock_interruptible(&dev->mode_config.mutex);
+	if (ret)
+		return ret;
+
+#define PRINT_VAR(name, fmt, var)					\
+	do {								\
+		sprintf(str, "%-22s", name);				\
+		ptr = str + strlen(str);				\
+		for_each_ring(ring, dev_priv, r) {			\
+			sprintf(ptr, " %10" fmt, var);			\
+			ptr += strlen(ptr);				\
+		}							\
+		seq_printf(m, "%s\n", str);				\
+	} while (0)
+
+	PRINT_VAR("Ring name:",             "s", dev_priv->ring[r].name);
+	PRINT_VAR("  Ring seqno",           "d", ring->get_seqno(ring, false));
+	seq_putc(m, '\n');
+
+	seq_puts(m, "Batch submissions:\n");
+	PRINT_VAR("  Queued",               "u", stats[r].queued);
+	PRINT_VAR("  Submitted",            "u", stats[r].submitted);
+	PRINT_VAR("  Completed",            "u", stats[r].completed);
+	PRINT_VAR("  Expired",              "u", stats[r].expired);
+	seq_putc(m, '\n');
+
+	seq_puts(m, "Flush counts:\n");
+	PRINT_VAR("  By object",            "u", stats[r].flush_obj);
+	PRINT_VAR("  By request",           "u", stats[r].flush_req);
+	PRINT_VAR("  By stamp",             "u", stats[r].flush_stamp);
+	PRINT_VAR("  Blanket",              "u", stats[r].flush_all);
+	PRINT_VAR("  Entries bumped",       "u", stats[r].flush_bump);
+	PRINT_VAR("  Entries submitted",    "u", stats[r].flush_submit);
+	seq_putc(m, '\n');
+
+	seq_puts(m, "Miscellaneous:\n");
+	PRINT_VAR("  ExecEarly retry",      "u", stats[r].exec_early);
+	PRINT_VAR("  ExecFinal requeue",    "u", stats[r].exec_again);
+	PRINT_VAR("  ExecFinal killed",     "u", stats[r].exec_dead);
+	PRINT_VAR("  Hung flying",          "u", stats[r].kill_flying);
+	PRINT_VAR("  Hung queued",          "u", stats[r].kill_queued);
+	seq_putc(m, '\n');
+
+	seq_puts(m, "Queue contents:\n");
+	for_each_ring(ring, dev_priv, i)
+		i915_scheduler_query_stats(ring, node_stats + ring->id);
+
+	for (i = 0; i < (i915_sqs_MAX + 1); i++) {
+		sprintf(name, "  %s", i915_scheduler_queue_status_str(i));
+		PRINT_VAR(name, "d", node_stats[r].counts[i]);
+	}
+	seq_putc(m, '\n');
+
+#undef PRINT_VAR
+
+	mutex_unlock(&dev->mode_config.mutex);
+
+	return 0;
+}
+
 struct pipe_crc_info {
 	const char *name;
 	struct drm_device *dev;
@@ -5565,6 +5637,7 @@ static const struct drm_info_list i915_debugfs_list[] = {
 	{"i915_semaphore_status", i915_semaphore_status, 0},
 	{"i915_shared_dplls_info", i915_shared_dplls_info, 0},
 	{"i915_dp_mst_info", i915_dp_mst_info, 0},
+	{"i915_scheduler_info", i915_scheduler_info, 0},
 	{"i915_wa_registers", i915_wa_registers, 0},
 	{"i915_ddb_info", i915_ddb_info, 0},
 	{"i915_sseu_status", i915_sseu_status, 0},
diff --git a/drivers/gpu/drm/i915/i915_gem_execbuffer.c b/drivers/gpu/drm/i915/i915_gem_execbuffer.c
index 83ce94d..a42a13e 100644
--- a/drivers/gpu/drm/i915/i915_gem_execbuffer.c
+++ b/drivers/gpu/drm/i915/i915_gem_execbuffer.c
@@ -1789,6 +1789,9 @@ pre_mutex_err:
 	/* intel_gpu_busy should also get a ref, so it will free when the device
 	 * is really idle. */
 	intel_runtime_pm_put(dev_priv);
+
+	dev_priv->scheduler->stats[ring->id].exec_early++;
+
 	return ret;
 }
 
diff --git a/drivers/gpu/drm/i915/i915_scheduler.c b/drivers/gpu/drm/i915/i915_scheduler.c
index d0eed52..0068d03 100644
--- a/drivers/gpu/drm/i915/i915_scheduler.c
+++ b/drivers/gpu/drm/i915/i915_scheduler.c
@@ -105,6 +105,9 @@ const char *i915_scheduler_queue_status_str(
 	case i915_sqs_dead:
 	return "Dead";
 
+	case i915_sqs_MAX:
+	return "Invalid";
+
 	default:
 	break;
 	}
@@ -208,13 +211,17 @@ static void i915_scheduler_node_requeue(struct i915_scheduler_queue_entry *node)
  * Give up on a node completely. For example, because it is causing the
  * ring to hang or is using some resource that no longer exists.
  */
-static void i915_scheduler_node_kill(struct i915_scheduler_queue_entry *node)
+static void i915_scheduler_node_kill(struct i915_scheduler *scheduler,
+				     struct i915_scheduler_queue_entry *node)
 {
 	WARN_ON(!node);
 	WARN_ON(I915_SQS_IS_COMPLETE(node));
 
-	if (I915_SQS_IS_FLYING(node))
+	if (I915_SQS_IS_FLYING(node)) {
 		trace_i915_scheduler_unfly(node->params.ring, node);
+		scheduler->stats[node->params.ring->id].kill_flying++;
+	} else
+		scheduler->stats[node->params.ring->id].kill_queued++;
 
 	node->status = i915_sqs_dead;
 	trace_i915_scheduler_node_state_change(node->params.ring, node);
@@ -469,6 +476,8 @@ static int i915_scheduler_submit(struct intel_engine_cs *ring)
 		 */
 		i915_scheduler_node_fly(node);
 
+		scheduler->stats[ring->id].submitted++;
+
 		spin_unlock_irq(&scheduler->lock);
 		ret = dev_priv->gt.execbuf_final(&node->params);
 		spin_lock_irq(&scheduler->lock);
@@ -492,7 +501,8 @@ static int i915_scheduler_submit(struct intel_engine_cs *ring)
 			case ENOENT:
 				/* Fatal errors. Kill the node. */
 				requeue = false;
-				i915_scheduler_node_kill(node);
+				scheduler->stats[ring->id].exec_dead++;
+				i915_scheduler_node_kill(scheduler, node);
 			break;
 
 			case EAGAIN:
@@ -502,6 +512,7 @@ static int i915_scheduler_submit(struct intel_engine_cs *ring)
 			case ERESTARTSYS:
 			case EINTR:
 				/* Supposedly recoverable errors. */
+				scheduler->stats[ring->id].exec_again++;
 			break;
 
 			default:
@@ -510,6 +521,7 @@ static int i915_scheduler_submit(struct intel_engine_cs *ring)
 				 * for the best.
 				 */
 				MISSING_CASE(-ret);
+				scheduler->stats[ring->id].exec_again++;
 			break;
 			}
 
@@ -669,12 +681,15 @@ static int i915_scheduler_queue_execbuffer_bypass(struct i915_scheduler_queue_en
 	struct i915_scheduler *scheduler = dev_priv->scheduler;
 	int ret;
 
+	scheduler->stats[qe->params.ring->id].queued++;
+
 	trace_i915_scheduler_queue(qe->params.ring, qe);
 
 	intel_ring_reserved_space_cancel(qe->params.request->ringbuf);
 
 	scheduler->flags[qe->params.ring->id] |= i915_sf_submitting;
 	ret = dev_priv->gt.execbuf_final(&qe->params);
+	scheduler->stats[qe->params.ring->id].submitted++;
 	scheduler->flags[qe->params.ring->id] &= ~i915_sf_submitting;
 
 	/*
@@ -687,6 +702,8 @@ static int i915_scheduler_queue_execbuffer_bypass(struct i915_scheduler_queue_en
 	/* Need to release any resources held by the node: */
 	i915_scheduler_clean_node(qe);
 
+	scheduler->stats[qe->params.ring->id].expired++;
+
 	return 0;
 }
 
@@ -795,6 +812,8 @@ int i915_scheduler_queue_execbuffer(struct i915_scheduler_queue_entry *qe)
 	not_flying = i915_scheduler_count_flying(scheduler, ring) <
 						 scheduler->min_flying;
 
+	scheduler->stats[ring->id].queued++;
+
 	trace_i915_scheduler_queue(ring, node);
 	trace_i915_scheduler_node_state_change(ring, node);
 
@@ -837,10 +856,13 @@ bool i915_scheduler_notify_request(struct drm_i915_gem_request *req)
 	WARN_ON(!I915_SQS_IS_FLYING(node));
 
 	/* Node was in flight so mark it as complete. */
-	if (req->cancelled)
+	if (req->cancelled) {
 		node->status = i915_sqs_dead;
-	else
+		scheduler->stats[req->ring->id].kill_flying++;
+	} else {
 		node->status = i915_sqs_complete;
+		scheduler->stats[req->ring->id].completed++;
+	}
 
 	trace_i915_scheduler_node_state_change(req->ring, node);
 
@@ -1031,6 +1053,7 @@ static bool i915_scheduler_remove(struct i915_scheduler *scheduler,
 
 		list_del(&node->link);
 		list_add(&node->link, remove);
+		scheduler->stats[ring->id].expired++;
 
 		/* Strip the dependency info while the mutex is still locked */
 		i915_scheduler_remove_dependent(scheduler, node);
@@ -1322,6 +1345,44 @@ int i915_scheduler_dump_all(struct drm_device *dev, const char *msg)
 	return ret;
 }
 
+/**
+ * i915_scheduler_query_stats - return various scheduler statistics
+ * @ring: Ring to report on
+ * @stats: Stats structure to be filled in
+ * For various reasons (debugging, performance analysis, curiosity) it is
+ * useful to see statistics about what the scheduler is doing. This function
+ * returns the stats that have been gathered in a data structure. The
+ * expectation is that this will be returned to the user via debugfs.
+ */
+int i915_scheduler_query_stats(struct intel_engine_cs *ring,
+			       struct i915_scheduler_stats_nodes *stats)
+{
+	struct drm_i915_private *dev_priv = ring->dev->dev_private;
+	struct i915_scheduler *scheduler = dev_priv->scheduler;
+	struct i915_scheduler_queue_entry *node;
+
+	memset(stats, 0x00, sizeof(*stats));
+
+	spin_lock_irq(&scheduler->lock);
+
+	list_for_each_entry(node, &scheduler->node_queue[ring->id], link) {
+		if (node->status >= i915_sqs_MAX) {
+			DRM_DEBUG_DRIVER("Invalid node state: %d! [uniq = %d, seqno = %d]\n",
+					 node->status, node->params.request->uniq,
+					 node->params.request->seqno);
+
+			stats->counts[i915_sqs_MAX]++;
+			continue;
+		}
+
+		stats->counts[node->status]++;
+	}
+
+	spin_unlock_irq(&scheduler->lock);
+
+	return 0;
+}
+
 static int i915_scheduler_submit_max_priority(struct intel_engine_cs *ring,
 					      bool is_locked)
 {
@@ -1402,6 +1463,7 @@ int i915_scheduler_flush_stamp(struct intel_engine_cs *ring,
 	}
 
 	spin_lock_irq(&scheduler->lock);
+	scheduler->stats[ring->id].flush_stamp++;
 	i915_scheduler_priority_bump_clear(scheduler);
 	list_for_each_entry(node, &scheduler->node_queue[ring->id], link) {
 		if (!I915_SQS_IS_QUEUED(node))
@@ -1412,12 +1474,15 @@ int i915_scheduler_flush_stamp(struct intel_engine_cs *ring,
 
 		flush_count = i915_scheduler_priority_bump(scheduler,
 					node, scheduler->priority_level_max);
+		scheduler->stats[ring->id].flush_bump += flush_count;
 	}
 	spin_unlock_irq(&scheduler->lock);
 
 	if (flush_count) {
 		DRM_DEBUG_DRIVER("<%s> Bumped %d entries\n", ring->name, flush_count);
 		flush_count = i915_scheduler_submit_max_priority(ring, is_locked);
+		if (flush_count > 0)
+			scheduler->stats[ring->id].flush_submit += flush_count;
 	}
 
 	return flush_count;
@@ -1453,6 +1518,8 @@ int i915_scheduler_flush(struct intel_engine_cs *ring, bool is_locked)
 
 	WARN_ON(is_locked && (scheduler->flags[ring->id] & i915_sf_submitting));
 
+	scheduler->stats[ring->id].flush_all++;
+
 	do {
 		found = false;
 		spin_lock_irq(&scheduler->lock);
@@ -1470,6 +1537,7 @@ int i915_scheduler_flush(struct intel_engine_cs *ring, bool is_locked)
 				ret = i915_scheduler_submit(ring);
 			else
 				ret = i915_scheduler_submit_unlocked(ring);
+			scheduler->stats[ring->id].flush_submit++;
 			if (ret < 0)
 				return ret;
 
diff --git a/drivers/gpu/drm/i915/i915_scheduler.h b/drivers/gpu/drm/i915/i915_scheduler.h
index a071ebb..065f2a3 100644
--- a/drivers/gpu/drm/i915/i915_scheduler.h
+++ b/drivers/gpu/drm/i915/i915_scheduler.h
@@ -70,6 +70,32 @@ struct i915_scheduler_queue_entry {
 };
 const char *i915_qe_state_str(struct i915_scheduler_queue_entry *node);
 
+struct i915_scheduler_stats_nodes {
+	uint32_t	counts[i915_sqs_MAX + 1];
+};
+
+struct i915_scheduler_stats {
+	/* Batch buffer counts: */
+	uint32_t            queued;
+	uint32_t            submitted;
+	uint32_t            completed;
+	uint32_t            expired;
+
+	/* Other stuff: */
+	uint32_t            flush_obj;
+	uint32_t            flush_req;
+	uint32_t            flush_stamp;
+	uint32_t            flush_all;
+	uint32_t            flush_bump;
+	uint32_t            flush_submit;
+
+	uint32_t            exec_early;
+	uint32_t            exec_again;
+	uint32_t            exec_dead;
+	uint32_t            kill_flying;
+	uint32_t            kill_queued;
+};
+
 struct i915_scheduler {
 	struct list_head    node_queue[I915_NUM_RINGS];
 	uint32_t            flags[I915_NUM_RINGS];
@@ -82,6 +108,9 @@ struct i915_scheduler {
 	int32_t             priority_level_preempt;
 	uint32_t            min_flying;
 	uint32_t            file_queue_max;
+
+	/* Statistics: */
+	struct i915_scheduler_stats     stats[I915_NUM_RINGS];
 };
 
 /* Flag bits for i915_scheduler::flags */
@@ -116,6 +145,8 @@ int i915_scheduler_dump(struct intel_engine_cs *ring,
 int i915_scheduler_dump_all(struct drm_device *dev, const char *msg);
 bool i915_scheduler_is_request_tracked(struct drm_i915_gem_request *req,
 				       bool *completed, bool *busy);
+int i915_scheduler_query_stats(struct intel_engine_cs *ring,
+			       struct i915_scheduler_stats_nodes *stats);
 bool i915_scheduler_file_queue_is_full(struct drm_file *file);
 
 #endif  /* _I915_SCHEDULER_H_ */
-- 
1.9.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx