From 2ed9dfbe6f77f0f3fa1f5b2802536fa496410144 Mon Sep 17 00:00:00 2001
From: Rob Clark <robdclark@chromium.org>
Date: Wed, 24 Feb 2021 11:21:01 -0800
Subject: [PATCH] freedreno: Add macro for duration based warns

Add a macro to do a perf_debug() if a block of code takes longer than a
specified amount of time.

Signed-off-by: Rob Clark <robdclark@chromium.org>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/9264>
---
 .../drivers/freedreno/freedreno_resource.c    | 10 +++----
 .../drivers/freedreno/freedreno_util.h        | 29 +++++++++++++++++++
 .../drivers/freedreno/ir3/ir3_gallium.c       | 12 ++++++--
 3 files changed, 43 insertions(+), 8 deletions(-)

diff --git a/src/gallium/drivers/freedreno/freedreno_resource.c b/src/gallium/drivers/freedreno/freedreno_resource.c
index 225ccd4132b..9043d3687d1 100644
--- a/src/gallium/drivers/freedreno/freedreno_resource.c
+++ b/src/gallium/drivers/freedreno/freedreno_resource.c
@@ -184,13 +184,11 @@ __fd_resource_wait(struct fd_context *ctx, struct fd_resource *rsc,
 	if (op & DRM_FREEDRENO_PREP_NOSYNC)
 		return fd_bo_cpu_prep(rsc->bo, ctx->pipe, op);
 
-	int64_t elapsed = -os_time_get_nano();
-	int ret = fd_bo_cpu_prep(rsc->bo, ctx->pipe, op);
+	int ret;
 
-	elapsed += os_time_get_nano();
-	if (elapsed > 10000) /* 0.01ms */ {
-		perf_debug_ctx(ctx, "%s: a busy \"%"PRSC_FMT"\" BO stalled and took %.03f ms.\n",
-				func, PRSC_ARGS(&rsc->base), (double)elapsed / 1000000.0);
+	perf_time_ctx(ctx, 10000, "%s: a busy \"%"PRSC_FMT"\" BO stalled",
+				func, PRSC_ARGS(&rsc->base)) {
+		ret = fd_bo_cpu_prep(rsc->bo, ctx->pipe, op);
 	}
 
 	return ret;
diff --git a/src/gallium/drivers/freedreno/freedreno_util.h b/src/gallium/drivers/freedreno/freedreno_util.h
index c56d6ee41f4..d7b5c9a082b 100644
--- a/src/gallium/drivers/freedreno/freedreno_util.h
+++ b/src/gallium/drivers/freedreno/freedreno_util.h
@@ -113,6 +113,35 @@ extern bool fd_binning_enabled;
 
 #define perf_debug(...) perf_debug_ctx(NULL, __VA_ARGS__)
 
+#define perf_time_ctx(ctx, limit_ns, fmt, ...) for( \
+		struct __perf_time_state __s = { \
+				.t = -__perf_get_time(ctx), \
+		}; \
+		!__s.done; \
+		({ \
+			__s.t += __perf_get_time(ctx); \
+			__s.done = true; \
+			if (__s.t > (limit_ns)) { \
+				perf_debug_ctx(ctx, fmt " (%.03f ms)", ##__VA_ARGS__, (double)__s.t / 1000000.0); \
+			} \
+		}))
+
+#define perf_time(limit_ns, fmt, ...) perf_time_ctx(NULL, limit_ns, fmt, ##__VA_ARGS__)
+
+struct __perf_time_state {
+	int64_t t;
+	bool done;
+};
+
+/* static inline would be nice here, except 'struct fd_context' is not
+ * defined yet:
+ */
+#define __perf_get_time(ctx) \
+	((FD_DBG(PERF) || \
+		({ struct fd_context *__c = (ctx); \
+			unlikely(__c && __c->debug.debug_message); })) ? \
+		os_time_get_nano() : 0)
+
 struct fd_context;
 
 /**
diff --git a/src/gallium/drivers/freedreno/ir3/ir3_gallium.c b/src/gallium/drivers/freedreno/ir3/ir3_gallium.c
index 696e7a52a69..a01c1cfee7e 100644
--- a/src/gallium/drivers/freedreno/ir3/ir3_gallium.c
+++ b/src/gallium/drivers/freedreno/ir3/ir3_gallium.c
@@ -423,8 +423,16 @@ ir3_get_shader(struct ir3_shader_state *hwcso)
 {
 	if (!hwcso)
 		return NULL;
-	util_queue_fence_wait(&hwcso->ready);
-	return hwcso->shader;
+
+	struct ir3_shader *shader = hwcso->shader;
+	perf_time(1000, "waited for %s:%s:%s variants",
+			_mesa_shader_stage_to_abbrev(shader->type),
+			shader->nir->info.name, shader->nir->info.label) {
+		/* wait for initial variants to compile: */
+		util_queue_fence_wait(&hwcso->ready);
+	}
+
+	return shader;
 }
 
 struct shader_info *