src/gallium/drivers/freedreno/freedreno_log.c

   1 /*
   2  * Copyright © 2020 Google, Inc.
   3  *
   4  * Permission is hereby granted, free of charge, to any person obtaining a
   5  * copy of this software and associated documentation files (the "Software"),
   6  * to deal in the Software without restriction, including without limitation
   7  * the rights to use, copy, modify, merge, publish, distribute, sublicense,
   8  * and/or sell copies of the Software, and to permit persons to whom the
   9  * Software is furnished to do so, subject to the following conditions:
  10  *
  11  * The above copyright notice and this permission notice (including the next
  12  * paragraph) shall be included in all copies or substantial portions of the
  13  * Software.
  14  *
  15  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
  16  * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
  17  * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.  IN NO EVENT SHALL
  18  * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
  19  * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
  20  * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
  21  * SOFTWARE.
  22  */
  23
  24 #include <inttypes.h>
  25 #include <stdarg.h>
  26
  27 #include "freedreno_log.h"
  28 #include "freedreno_batch.h"
  29 #include "freedreno_context.h"
  30
  31 #include "util/u_fifo.h"
  32
  33 /* A simple(ish) logging mechanism with timestamps recorded at the
  34  * corresponding point in the cmdstream.  The overall design is based
  35  * on fd_log_chunk's, which buffer up up to 'msgs_per_chunk' log msgs
  36  * and track an associated bo containing timestamps written from the
  37  * GPU.
  38  *
  39  * The fd_batch tracks a list of fd_log_chunk's.  When fd_log() is
  40  * called, msgs are pushed into the last (most recent) chunk until
  41  * it is full, at which point a new chunk is created.  And cmds are
  42  * inserted into the cmdstream to record the GPU timestamp that
  43  * corresponds with the log msg.
  44  *
  45  * When the batch is flushed, the list of log chunks is transferred
  46  * to the end of fd_context's list of chunks, and we attempt to pop
  47  * chunks from the from of the list if their timestamp bo is idle (ie.
  48  * the GPU has finished the batch that was writing the timestamps).
  49  *
  50  * NOTE: this is only appropriate for IB1 (ie. "gmem" level) cmdstream,
  51  * the IB2 (draw/binning) cmdstream can be executed multiple times,
  52  * which this mechanism is not designed to support.  Other existing
  53  * GL level queries (time-elapsed, amd-perfcntrs) are more appropriate
  54  * for profiling at that level.
  55  */
  56
  57 const unsigned bo_size = 0x1000;
  58 const unsigned msgs_per_chunk = bo_size / sizeof(uint64_t);
  59
  60 struct fd_log_chunk {
  61         struct list_head node;
  62
  63         unsigned num_msgs;
  64         struct util_fifo *msg_fifo;
  65
  66         /* list of recorded 64b timestamps */
  67         struct fd_bo *timestamps_bo;
  68
  69         bool eof;
  70 };
  71
  72 static struct fd_log_chunk *
  73 get_chunk(struct fd_batch *batch)
  74 {
  75         struct fd_log_chunk *chunk;
  76
  77         /* do we currently have a non-full chunk to append msgs to? */
  78         if (!list_is_empty(&batch->log_chunks)) {
  79                 chunk = list_last_entry(&batch->log_chunks,
  80                                 struct fd_log_chunk, node);
  81                 if (chunk->num_msgs < msgs_per_chunk)
  82                         return chunk;
  83         }
  84
  85         /* .. if not, then create a new one: */
  86         chunk = calloc(1, sizeof(*chunk));
  87         chunk->msg_fifo = u_fifo_create(msgs_per_chunk);
  88         chunk->timestamps_bo = fd_bo_new(batch->ctx->screen->dev, bo_size,
  89                         DRM_FREEDRENO_GEM_TYPE_KMEM, "timestamps");
  90
  91         list_addtail(&chunk->node, &batch->log_chunks);
  92
  93         return chunk;
  94 }
  95
  96 static void
  97 free_chunk(struct fd_log_chunk *chunk)
  98 {
  99         assert(chunk->msg_fifo->num == 0);
 100         u_fifo_destroy(chunk->msg_fifo);
 101         fd_bo_del(chunk->timestamps_bo);
 102         list_del(&chunk->node);
 103         free(chunk);
 104 }
 105
 106 static void
 107 process_chunk(struct fd_context *ctx, struct fd_log_chunk *chunk)
 108 {
 109         printf("+----- TS -----+ +----- NS -----+ +-- Δ --+  +----- MSG -----\n");
 110
 111         uint64_t *timestamps = fd_bo_map(chunk->timestamps_bo);
 112         uint64_t last_time_ns = 0;
 113         uint64_t first_time_ns = 0;
 114         unsigned n = 0;
 115         char *msg;
 116
 117         while (u_fifo_pop(chunk->msg_fifo, (void **)&msg)) {
 118                 uint64_t ts = timestamps[n++];
 119                 uint64_t ns = ctx->ts_to_ns(ts);
 120                 int32_t delta = last_time_ns ? ns - last_time_ns : 0;
 121
 122                 if (!first_time_ns)
 123                         first_time_ns = ns;
 124
 125                 last_time_ns = ns;
 126
 127                 printf("%016"PRIu64" %016"PRIu64" %+9d: %s\n", ts, ns, delta, msg);
 128                 free(msg);
 129
 130         }
 131
 132         printf("ELAPSED: %"PRIu64" ns\n", last_time_ns - first_time_ns);
 133
 134         if (chunk->eof)
 135                 printf("END OF FRAME %u\n", ctx->frame_nr++);
 136 }
 137
 138 void
 139 fd_log_process(struct fd_context *ctx, bool wait)
 140 {
 141         while (!list_is_empty(&ctx->log_chunks)) {
 142                 struct fd_log_chunk *chunk = list_first_entry(&ctx->log_chunks,
 143                                 struct fd_log_chunk, node);
 144
 145                 unsigned flags = DRM_FREEDRENO_PREP_READ;
 146                 if (!wait)
 147                         flags |= DRM_FREEDRENO_PREP_NOSYNC;
 148
 149                 int ret = fd_bo_cpu_prep(chunk->timestamps_bo, ctx->pipe, flags);
 150                 if (ret)
 151                         break;
 152
 153                 process_chunk(ctx, chunk);
 154                 free_chunk(chunk);
 155         }
 156 }
 157
 158 void
 159 fd_log_flush(struct fd_batch *batch)
 160 {
 161         /* transfer batch's log chunks to context: */
 162         list_splicetail(&batch->log_chunks, &batch->ctx->log_chunks);
 163         list_inithead(&batch->log_chunks);
 164 }
 165
 166 void
 167 _fd_log(struct fd_batch *batch, const char *fmt, ...)
 168 {
 169         struct fd_context *ctx = batch->ctx;
 170         struct fd_ringbuffer *ring = batch->nondraw ? batch->draw : batch->gmem;
 171         struct fd_log_chunk *chunk = get_chunk(batch);
 172         char *msg;
 173
 174         va_list ap;
 175         va_start(ap, fmt);
 176         if (vasprintf(&msg, fmt, ap) < 0)
 177                 return;
 178         va_end(ap);
 179
 180         u_fifo_add(chunk->msg_fifo, msg);
 181
 182         assert(ctx->record_timestamp);
 183         ctx->record_timestamp(ring, chunk->timestamps_bo,
 184                         chunk->num_msgs * sizeof(uint64_t));
 185
 186         chunk->num_msgs++;
 187 }
 188
 189 void fd_log_eof(struct fd_context *ctx)
 190 {
 191         if (!(fd_mesa_debug & FD_DBG_LOG))
 192                 return;
 193
 194         if (list_is_empty(&ctx->log_chunks)) {
 195                 printf("WARNING: no log chunks!\n");
 196                 return;
 197         }
 198
 199         struct fd_log_chunk *last_chunk = list_last_entry(&ctx->log_chunks,
 200                         struct fd_log_chunk, node);
 201         last_chunk->eof = true;
 202
 203         /* and process any chunks that are now idle/ready: */
 204         fd_log_process(ctx, false);
 205 }