drm/msm/gpu: Add trace events for tracking GPU submissions

Add trace events to track the progress of a GPU submission
msm_gpu_submit occurs at the beginning of the submissions,
msm_gpu_submit_flush happens when the submission is put on
the ringbuffer and msm_submit_flush_retired is sent when
the operation is retired.

To make it easier to track the operations a unique sequence
number is assigned to each submission and displayed in each
event output so a human or a script can easily associate
the events related to a specific submission.

Signed-off-by: Jordan Crouse <[e-mail]>
Signed-off-by: Rob Clark <[e-mail]>

drivers/gpu/drm/msm/Makefile

···
 	msm_perf.o \
 	msm_rd.o \
 	msm_ringbuffer.o \
-	msm_submitqueue.o
+	msm_submitqueue.o \
+	msm_gpu_tracepoints.o
 
 msm-$(CONFIG_DEBUG_FS) += adreno/a5xx_debugfs.o \
 			  disp/dpu1/dpu_dbg.o

drivers/gpu/drm/msm/adreno/a6xx_gpu.c

···
 
 #include "msm_gem.h"
 #include "msm_mmu.h"
+#include "msm_gpu_trace.h"
 #include "a6xx_gpu.h"
 #include "a6xx_gmu.xml.h"
 
···
 {
 	unsigned int index = submit->seqno % MSM_GPU_SUBMIT_STATS_COUNT;
 	struct msm_drm_private *priv = gpu->dev->dev_private;
+	struct adreno_gpu *adreno_gpu = to_adreno_gpu(gpu);
+	struct a6xx_gpu *a6xx_gpu = to_a6xx_gpu(adreno_gpu);
 	struct msm_ringbuffer *ring = submit->ring;
 	unsigned int i;
 
···
 	OUT_RING(ring, lower_32_bits(rbmemptr(ring, fence)));
 	OUT_RING(ring, upper_32_bits(rbmemptr(ring, fence)));
 	OUT_RING(ring, submit->seqno);
+
+	trace_msm_gpu_submit_flush(submit,
+		gmu_read64(&a6xx_gpu->gmu, REG_A6XX_GMU_ALWAYS_ON_COUNTER_L,
+			REG_A6XX_GMU_ALWAYS_ON_COUNTER_H));
 
 	a6xx_flush(gpu, ring);
 }

drivers/gpu/drm/msm/msm_gem.h

···
 	struct msm_ringbuffer *ring;
 	unsigned int nr_cmds;
 	unsigned int nr_bos;
+	u32 ident;	   /* A "identifier" for the submit for logging */
 	struct {
 		uint32_t type;
 		uint32_t size;  /* in dwords */

drivers/gpu/drm/msm/msm_gem_submit.c

···
 #include "msm_drv.h"
 #include "msm_gpu.h"
 #include "msm_gem.h"
+#include "msm_gpu_trace.h"
 
 /*
  * Cmdstream submission:
···
 	submit->dev = dev;
 	submit->gpu = gpu;
 	submit->fence = NULL;
-	submit->pid = get_pid(task_pid(current));
 	submit->cmd = (void *)&submit->bos[nr_bos];
 	submit->queue = queue;
 	submit->ring = gpu->rb[queue->prio];
···
 int msm_ioctl_gem_submit(struct drm_device *dev, void *data,
 		struct drm_file *file)
 {
+	static atomic_t ident = ATOMIC_INIT(0);
 	struct msm_drm_private *priv = dev->dev_private;
 	struct drm_msm_gem_submit *args = data;
 	struct msm_file_private *ctx = file->driver_priv;
···
 	struct msm_gpu_submitqueue *queue;
 	struct msm_ringbuffer *ring;
 	int out_fence_fd = -1;
+	struct pid *pid = get_pid(task_pid(current));
 	unsigned i;
-	int ret;
-
+	int ret, submitid;
 	if (!gpu)
 		return -ENXIO;
 
···
 	if (!queue)
 		return -ENOENT;
 
+	/* Get a unique identifier for the submission for logging purposes */
+	submitid = atomic_inc_return(&ident) - 1;
+
 	ring = gpu->rb[queue->prio];
+	trace_msm_gpu_submit(pid_nr(pid), ring->id, submitid,
+		args->nr_bos, args->nr_cmds);
 
 	if (args->flags & MSM_SUBMIT_FENCE_FD_IN) {
 		in_fence = sync_file_get_fence(args->fence_fd);
···
 		ret = -ENOMEM;
 		goto out_unlock;
 	}
+
+	submit->pid = pid;
+	submit->ident = submitid;
 
 	if (args->flags & MSM_SUBMIT_SUDO)
 		submit->in_rb = true;

drivers/gpu/drm/msm/msm_gpu.c

···
 #include "msm_gem.h"
 #include "msm_mmu.h"
 #include "msm_fence.h"
+#include "msm_gpu_trace.h"
 
 #include <generated/utsrelease.h>
 #include <linux/string_helpers.h>
···
  * Cmdstream submission/retirement:
  */
 
-static void retire_submit(struct msm_gpu *gpu, struct msm_gem_submit *submit)
+static void retire_submit(struct msm_gpu *gpu, struct msm_ringbuffer *ring,
+		struct msm_gem_submit *submit)
 {
+	int index = submit->seqno % MSM_GPU_SUBMIT_STATS_COUNT;
+	volatile struct msm_gpu_submit_stats *stats;
+	u64 elapsed, clock = 0;
 	int i;
+
+	stats = &ring->memptrs->stats[index];
+	/* Convert 19.2Mhz alwayson ticks to nanoseconds for elapsed time */
+	elapsed = (stats->alwayson_end - stats->alwayson_start) * 10000;
+	do_div(elapsed, 192);
+
+	/* Calculate the clock frequency from the number of CP cycles */
+	if (elapsed) {
+		clock = (stats->cpcycles_end - stats->cpcycles_start) * 1000;
+		do_div(clock, elapsed);
+	}
+
+	trace_msm_gpu_submit_retired(submit, elapsed, clock,
+		stats->alwayson_start, stats->alwayson_end);
 
 	for (i = 0; i < submit->nr_bos; i++) {
 		struct msm_gem_object *msm_obj = submit->bos[i].obj;
···
 
 		list_for_each_entry_safe(submit, tmp, &ring->submits, node) {
 			if (dma_fence_is_signaled(submit->fence))
-				retire_submit(gpu, submit);
+				retire_submit(gpu, ring, submit);
 		}
 	}
 }

drivers/gpu/drm/msm/msm_gpu_trace.h

···
+/* SPDX-License-Identifier: GPL-2.0 */
+#if !defined(_MSM_GPU_TRACE_H_) || defined(TRACE_HEADER_MULTI_READ)
+#define _MSM_GPU_TRACE_H_
+
+#include <linux/tracepoint.h>
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM drm_msm
+#define TRACE_INCLUDE_FILE msm_gpu_trace
+
+TRACE_EVENT(msm_gpu_submit,
+	    TP_PROTO(pid_t pid, u32 ringid, u32 id, u32 nr_bos, u32 nr_cmds),
+	    TP_ARGS(pid, ringid, id, nr_bos, nr_cmds),
+	    TP_STRUCT__entry(
+		    __field(pid_t, pid)
+		    __field(u32, id)
+		    __field(u32, ringid)
+		    __field(u32, nr_cmds)
+		    __field(u32, nr_bos)
+		    ),
+	    TP_fast_assign(
+		    __entry->pid = pid;
+		    __entry->id = id;
+		    __entry->ringid = ringid;
+		    __entry->nr_bos = nr_bos;
+		    __entry->nr_cmds = nr_cmds
+		    ),
+	    TP_printk("id=%d pid=%d ring=%d bos=%d cmds=%d",
+		    __entry->id, __entry->pid, __entry->ringid,
+		    __entry->nr_bos, __entry->nr_cmds)
+);
+
+TRACE_EVENT(msm_gpu_submit_flush,
+	    TP_PROTO(struct msm_gem_submit *submit, u64 ticks),
+	    TP_ARGS(submit, ticks),
+	    TP_STRUCT__entry(
+		    __field(pid_t, pid)
+		    __field(u32, id)
+		    __field(u32, ringid)
+		    __field(u32, seqno)
+		    __field(u64, ticks)
+		    ),
+	    TP_fast_assign(
+		    __entry->pid = pid_nr(submit->pid);
+		    __entry->id = submit->ident;
+		    __entry->ringid = submit->ring->id;
+		    __entry->seqno = submit->seqno;
+		    __entry->ticks = ticks;
+		    ),
+	    TP_printk("id=%d pid=%d ring=%d:%d ticks=%lld",
+		    __entry->id, __entry->pid, __entry->ringid, __entry->seqno,
+		    __entry->ticks)
+);
+
+
+TRACE_EVENT(msm_gpu_submit_retired,
+	    TP_PROTO(struct msm_gem_submit *submit, u64 elapsed, u64 clock,
+		    u64 start, u64 end),
+	    TP_ARGS(submit, elapsed, clock, start, end),
+	    TP_STRUCT__entry(
+		    __field(pid_t, pid)
+		    __field(u32, id)
+		    __field(u32, ringid)
+		    __field(u32, seqno)
+		    __field(u64, elapsed)
+		    __field(u64, clock)
+		    __field(u64, start_ticks)
+		    __field(u64, end_ticks)
+		    ),
+	    TP_fast_assign(
+		    __entry->pid = pid_nr(submit->pid);
+		    __entry->id = submit->ident;
+		    __entry->ringid = submit->ring->id;
+		    __entry->seqno = submit->seqno;
+		    __entry->elapsed = elapsed;
+		    __entry->clock = clock;
+		    __entry->start_ticks = start;
+		    __entry->end_ticks = end;
+		    ),
+	    TP_printk("id=%d pid=%d ring=%d:%d elapsed=%lld ns mhz=%lld start=%lld end=%lld",
+		    __entry->id, __entry->pid, __entry->ringid, __entry->seqno,
+		    __entry->elapsed, __entry->clock,
+		    __entry->start_ticks, __entry->end_ticks)
+);
+
+#endif
+
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH ../../drivers/gpu/drm/msm
+#include <trace/define_trace.h>

drivers/gpu/drm/msm/msm_gpu_tracepoints.c

···
+// SPDX-License-Identifier: GPL-2.0
+#include "msm_gem.h"
+#include "msm_ringbuffer.h"
+
+#define CREATE_TRACE_POINTS
+#include "msm_gpu_trace.h"