drm/msm/gpu: Add trace events for tracking GPU submissions
authorJordan Crouse <jcrouse@codeaurora.org>
Fri, 2 Nov 2018 15:25:21 +0000 (09:25 -0600)
committerRob Clark <robdclark@gmail.com>
Tue, 11 Dec 2018 18:05:28 +0000 (13:05 -0500)
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 <jcrouse@codeaurora.org>
Signed-off-by: Rob Clark <robdclark@gmail.com>
drivers/gpu/drm/msm/Makefile
drivers/gpu/drm/msm/adreno/a6xx_gpu.c
drivers/gpu/drm/msm/msm_gem.h
drivers/gpu/drm/msm/msm_gem_submit.c
drivers/gpu/drm/msm/msm_gpu.c
drivers/gpu/drm/msm/msm_gpu_trace.h [new file with mode: 0644]
drivers/gpu/drm/msm/msm_gpu_tracepoints.c [new file with mode: 0644]

index 19ab521d4c3ad10cc368b8227b44b7bad5b328f6..5de2d8f0a7e5b3243a7a3a410a2416f28f250ded 100644 (file)
@@ -90,7 +90,8 @@ msm-y := \
        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
index cf66edfb5246d0dd6dcc2c3849a2305d5d9e5349..e0a918e8e96913d6e879147fa370a55575163ffb 100644 (file)
@@ -4,6 +4,7 @@
 
 #include "msm_gem.h"
 #include "msm_mmu.h"
+#include "msm_gpu_trace.h"
 #include "a6xx_gpu.h"
 #include "a6xx_gmu.xml.h"
 
@@ -81,6 +82,8 @@ static void a6xx_submit(struct msm_gpu *gpu, struct msm_gem_submit *submit,
 {
        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;
 
@@ -138,6 +141,10 @@ static void a6xx_submit(struct msm_gpu *gpu, struct msm_gem_submit *submit,
        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);
 }
 
index c5d9bd3e47a8d20100f4c29da961aba368fb8752..ddaf8663dc9520ea6753acb902cda6dc2393c0a6 100644 (file)
@@ -150,6 +150,7 @@ struct msm_gem_submit {
        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 */
index a90aedd6883a8692bc68d5353b17049e4f1a3faf..e31be7417f944a0693f07ff27c42cb655bccc713 100644 (file)
@@ -20,6 +20,7 @@
 #include "msm_drv.h"
 #include "msm_gpu.h"
 #include "msm_gem.h"
+#include "msm_gpu_trace.h"
 
 /*
  * Cmdstream submission:
@@ -48,7 +49,6 @@ static struct msm_gem_submit *submit_create(struct drm_device *dev,
        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];
@@ -406,6 +406,7 @@ static void submit_cleanup(struct msm_gem_submit *submit)
 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;
@@ -416,9 +417,9 @@ int msm_ioctl_gem_submit(struct drm_device *dev, void *data,
        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;
 
@@ -441,7 +442,12 @@ int msm_ioctl_gem_submit(struct drm_device *dev, void *data,
        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);
@@ -478,6 +484,9 @@ int msm_ioctl_gem_submit(struct drm_device *dev, void *data,
                goto out_unlock;
        }
 
+       submit->pid = pid;
+       submit->ident = submitid;
+
        if (args->flags & MSM_SUBMIT_SUDO)
                submit->in_rb = true;
 
index c3351ec880ef198624da9430cc34fcb9fa5aafb5..d63fa2a361936dfaa3543819d3df885ae333be36 100644 (file)
@@ -19,6 +19,7 @@
 #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>
@@ -659,10 +660,28 @@ out:
  * 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;
                /* move to inactive: */
@@ -690,7 +709,7 @@ static void retire_submits(struct msm_gpu *gpu)
 
                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);
                }
        }
 }
diff --git a/drivers/gpu/drm/msm/msm_gpu_trace.h b/drivers/gpu/drm/msm/msm_gpu_trace.h
new file mode 100644 (file)
index 0000000..1155118
--- /dev/null
@@ -0,0 +1,90 @@
+/* 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>
diff --git a/drivers/gpu/drm/msm/msm_gpu_tracepoints.c b/drivers/gpu/drm/msm/msm_gpu_tracepoints.c
new file mode 100644 (file)
index 0000000..72c074f
--- /dev/null
@@ -0,0 +1,6 @@
+// SPDX-License-Identifier: GPL-2.0
+#include "msm_gem.h"
+#include "msm_ringbuffer.h"
+
+#define CREATE_TRACE_POINTS
+#include "msm_gpu_trace.h"