[PATCH 5/9] drm/i915: Engine busy time tracking

Tvrtko Ursulin
2017-11-13T08:57:40Z

Track total time requests have been executing on the hardware.

We add new kernel API to allow software tracking of time GPU
engines are spending executing requests.

Both per-engine and global API is added with the latter also
being exported for use by external users.

v2:
* Squashed with the internal API.
* Dropped static key.
* Made per-engine.
* Store time in monotonic ktime.

v3: Moved stats clearing to disable.

v4:
* Comments.
* Don't export the API just yet.

v5: Whitespace cleanup.

v6:
* Rename ref to active.
* Drop engine aggregate stats for now.
* Account initial busy period after enabling stats.

v7:
* Rebase.

v8:
* Move context in notification after the notifier. (Chris Wilson)

v9:

In cases where stats tracking is getting disabled while there is
an active context on an engine, add up the current value to the
total. This also implies we don't clear the total when tracking
is disabled any longer. There is no real need to do so because
we define the stats as relative while enabled, meaning
comparison between two samples while tracking is enabled is the
valid usage. However, when busy stats will later be plugged into
the perf PMU API, it is beneficial to not reset the total, since
the PMU core likes to do some counter disable/enable cycles on
startup, and while doing so during a single long context
executing on an engine we would lose some accuracy and so make
unit testing more difficult than needs to be.

v10:
* Fix accounting for preemption.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Reviewed-by: Chris Wilson <chris@chris-wilson.co.uk> (v8)
---
drivers/gpu/drm/i915/intel_engine_cs.c | 87 +++++++++++++++++++++++++++++++
drivers/gpu/drm/i915/intel_lrc.c | 3 ++
drivers/gpu/drm/i915/intel_ringbuffer.h | 92 +++++++++++++++++++++++++++++++++
3 files changed, 182 insertions(+)

diff --git a/drivers/gpu/drm/i915/intel_engine_cs.c b/drivers/gpu/drm/i915/intel_engine_cs.c
index e65127dceb39..64b28287d01b 100644
--- a/drivers/gpu/drm/i915/intel_engine_cs.c
+++ b/drivers/gpu/drm/i915/intel_engine_cs.c
@@ -245,6 +245,8 @@ intel_engine_setup(struct drm_i915_private *dev_priv,
/* Nothing to do here, execute in order of dependencies */
engine->schedule = NULL;

+ spin_lock_init(&engine->stats.lock);
+
ATOMIC_INIT_NOTIFIER_HEAD(&engine->context_status_notifier);

dev_priv->engine_class[info->class][info->instance] = engine;
@@ -1916,6 +1918,91 @@ intel_engine_lookup_user(struct drm_i915_private *i915, u8 class, u8 instance)
return i915->engine_class[class][instance];
}

+/**
+ * intel_enable_engine_stats() - Enable engine busy tracking on engine
+ * @engine: engine to enable stats collection
+ *
+ * Start collecting the engine busyness data for @engine.
+ *
+ * Returns 0 on success or a negative error code.
+ */
+int intel_enable_engine_stats(struct intel_engine_cs *engine)
+{
+ unsigned long flags;
+
+ if (!i915_modparams.enable_execlists)
+ return -ENODEV;
+
+ spin_lock_irqsave(&engine->stats.lock, flags);
+ if (engine->stats.enabled == ~0)
+ goto busy;
+ if (engine->stats.enabled++ == 0)
+ engine->stats.enabled_at = ktime_get();
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+
+ return 0;
+
+busy:
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+
+ return -EBUSY;
+}
+
+static ktime_t __intel_engine_get_busy_time(struct intel_engine_cs *engine)
+{
+ ktime_t total = engine->stats.total;
+
+ /*
+ * If the engine is executing something at the moment
+ * add it to the total.
+ */
+ if (engine->stats.active)
+ total = ktime_add(total,
+ ktime_sub(ktime_get(), engine->stats.start));
+
+ return total;
+}
+
+/**
+ * intel_engine_get_busy_time() - Return current accumulated engine busyness
+ * @engine: engine to report on
+ *
+ * Returns accumulated time @engine was busy since engine stats were enabled.
+ */
+ktime_t intel_engine_get_busy_time(struct intel_engine_cs *engine)
+{
+ ktime_t total;
+ unsigned long flags;
+
+ spin_lock_irqsave(&engine->stats.lock, flags);
+ total = __intel_engine_get_busy_time(engine);
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+
+ return total;
+}
+
+/**
+ * intel_disable_engine_stats() - Disable engine busy tracking on engine
+ * @engine: engine to disable stats collection
+ *
+ * Stops collecting the engine busyness data for @engine.
+ */
+void intel_disable_engine_stats(struct intel_engine_cs *engine)
+{
+ unsigned long flags;
+
+ if (!i915_modparams.enable_execlists)
+ return;
+
+ spin_lock_irqsave(&engine->stats.lock, flags);
+ WARN_ON_ONCE(engine->stats.enabled == 0);
+ if (--engine->stats.enabled == 0) {
+ engine->stats.total = __intel_engine_get_busy_time(engine);
+ engine->stats.active = 0;
+ }
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+}
+
#if IS_ENABLED(CONFIG_DRM_I915_SELFTEST)
#include "selftests/mock_engine.c"
#endif
diff --git a/drivers/gpu/drm/i915/intel_lrc.c b/drivers/gpu/drm/i915/intel_lrc.c
index c92be3b94c7a..62f8db42e5c4 100644
--- a/drivers/gpu/drm/i915/intel_lrc.c
+++ b/drivers/gpu/drm/i915/intel_lrc.c
@@ -416,11 +416,13 @@ static inline void
execlists_context_schedule_in(struct drm_i915_gem_request *rq)
{
execlists_context_status_change(rq, INTEL_CONTEXT_SCHEDULE_IN);
+ intel_engine_context_in(rq->engine);
}

static inline void
execlists_context_schedule_out(struct drm_i915_gem_request *rq)
{
+ intel_engine_context_out(rq->engine);
execlists_context_status_change(rq, INTEL_CONTEXT_SCHEDULE_OUT);
}

@@ -725,6 +727,7 @@ execlists_cancel_port_requests(struct intel_engine_execlists * const execlists)
struct drm_i915_gem_request *rq = port_request(port);

GEM_BUG_ON(!execlists->active);
+ intel_engine_context_out(rq->engine);
execlists_context_status_change(rq, INTEL_CONTEXT_SCHEDULE_PREEMPTED);
i915_gem_request_put(rq);

diff --git a/drivers/gpu/drm/i915/intel_ringbuffer.h b/drivers/gpu/drm/i915/intel_ringbuffer.h
index b71d9ea5227f..5b5e2bd9b25d 100644
--- a/drivers/gpu/drm/i915/intel_ringbuffer.h
+++ b/drivers/gpu/drm/i915/intel_ringbuffer.h
@@ -560,6 +560,38 @@ struct intel_engine_cs {
* certain bits to encode the command length in the header).
*/
u32 (*get_cmd_length_mask)(u32 cmd_header);
+
+ struct {
+ /**
+ * @lock: Lock protecting the below fields.
+ */
+ spinlock_t lock;
+ /**
+ * @enabled: Reference count indicating number of listeners.
+ */
+ unsigned int enabled;
+ /**
+ * @active: Number of contexts currently scheduled in.
+ */
+ unsigned int active;
+ /**
+ * @enabled_at: Timestamp when busy stats were enabled.
+ */
+ ktime_t enabled_at;
+ /**
+ * @start: Timestamp of the last idle to active transition.
+ *
+ * Idle is defined as active == 0, active is active > 0.
+ */
+ ktime_t start;
+ /**
+ * @total: Total time this engine was busy.
+ *
+ * Accumulated time not counting the most recent block in cases
+ * where engine is currently busy (active > 0).
+ */
+ ktime_t total;
+ } stats;
};

static inline void
@@ -964,4 +996,64 @@ void intel_engine_dump(struct intel_engine_cs *engine, struct drm_printer *p);
struct intel_engine_cs *
intel_engine_lookup_user(struct drm_i915_private *i915, u8 class, u8 instance);

+static inline void intel_engine_context_in(struct intel_engine_cs *engine)
+{
+ unsigned long flags;
+
+ if (READ_ONCE(engine->stats.enabled) == 0)
+ return;
+
+ spin_lock_irqsave(&engine->stats.lock, flags);
+
+ if (engine->stats.enabled > 0) {
+ if (engine->stats.active++ == 0)
+ engine->stats.start = ktime_get();
+ GEM_BUG_ON(engine->stats.active == 0);
+ }
+
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+}
+
+static inline void intel_engine_context_out(struct intel_engine_cs *engine)
+{
+ unsigned long flags;
+
+ if (READ_ONCE(engine->stats.enabled) == 0)
+ return;
+
+ spin_lock_irqsave(&engine->stats.lock, flags);
+
+ if (engine->stats.enabled > 0) {
+ ktime_t last;
+
+ if (engine->stats.active && --engine->stats.active == 0) {
+ /*
+ * Decrement the active context count and in case GPU
+ * is now idle add up to the running total.
+ */
+ last = ktime_sub(ktime_get(), engine->stats.start);
+
+ engine->stats.total = ktime_add(engine->stats.total,
+ last);
+ } else if (engine->stats.active == 0) {
+ /*
+ * After turning on engine stats, context out might be
+ * the first event in which case we account from the
+ * time stats gathering was turned on.
+ */
+ last = ktime_sub(ktime_get(), engine->stats.enabled_at);
+
+ engine->stats.total = ktime_add(engine->stats.total,
+ last);
+ }
+ }
+
+ spin_unlock_irqrestore(&engine->stats.lock, flags);
+}
+
+int intel_enable_engine_stats(struct intel_engine_cs *engine);
+void intel_disable_engine_stats(struct intel_engine_cs *engine);
+
+ktime_t intel_engine_get_busy_time(struct intel_engine_cs *engine);
+
#endif /* _INTEL_RINGBUFFER_H_ */