2 * Copyright © 2020 Google, Inc.
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:
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
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
27 #include "freedreno_log.h"
28 #include "freedreno_batch.h"
29 #include "freedreno_context.h"
31 #include "util/u_fifo.h"
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
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.
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).
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.
59 msgs_per_chunk
= bo_size
/ sizeof(uint64_t),
63 struct list_head node
;
66 struct util_fifo
*msg_fifo
;
68 /* list of recorded 64b timestamps */
69 struct fd_bo
*timestamps_bo
;
71 bool last
; /* this chunk is last in submit */
72 bool eof
; /* this chunk is last in frame */
76 static struct fd_log_chunk
*
77 get_chunk(struct fd_batch
*batch
)
79 struct fd_log_chunk
*chunk
;
81 /* do we currently have a non-full chunk to append msgs to? */
82 if (!list_is_empty(&batch
->log_chunks
)) {
83 chunk
= list_last_entry(&batch
->log_chunks
,
84 struct fd_log_chunk
, node
);
85 if (chunk
->num_msgs
< msgs_per_chunk
)
87 /* we need to expand to add another chunk to the batch, so
88 * the current one is no longer the last one of the batch:
93 /* .. if not, then create a new one: */
94 chunk
= calloc(1, sizeof(*chunk
));
95 chunk
->msg_fifo
= u_fifo_create(msgs_per_chunk
);
96 chunk
->timestamps_bo
= fd_bo_new(batch
->ctx
->screen
->dev
, bo_size
,
97 DRM_FREEDRENO_GEM_TYPE_KMEM
, "timestamps");
100 list_addtail(&chunk
->node
, &batch
->log_chunks
);
106 free_chunk(struct fd_log_chunk
*chunk
)
108 assert(chunk
->msg_fifo
->num
== 0);
109 u_fifo_destroy(chunk
->msg_fifo
);
110 fd_bo_del(chunk
->timestamps_bo
);
111 list_del(&chunk
->node
);
115 /* state to accumulate time across N chunks associated with a single batch: */
117 uint64_t last_time_ns
;
118 uint64_t first_time_ns
;
122 process_chunk(struct fd_context
*ctx
, struct fd_log_chunk
*chunk
, struct times
*t
)
124 /* For first chunk of batch, accumulated times will be zerod: */
125 if (!t
->last_time_ns
) {
126 fprintf(ctx
->log_out
,
127 "+----- TS -----+ +----- NS -----+ +-- Δ --+ +----- MSG -----\n");
130 uint64_t *timestamps
= fd_bo_map(chunk
->timestamps_bo
);
134 while (u_fifo_pop(chunk
->msg_fifo
, (void **)&msg
)) {
135 uint64_t ts
= timestamps
[n
++];
136 uint64_t ns
= ctx
->ts_to_ns(ts
);
139 if (!t
->first_time_ns
)
140 t
->first_time_ns
= ns
;
143 delta
= t
->last_time_ns
? ns
- t
->last_time_ns
: 0;
144 t
->last_time_ns
= ns
;
146 /* we skipped recording the timestamp, so it should be
147 * the same as last msg:
149 ns
= t
->last_time_ns
;
153 fprintf(ctx
->log_out
, "%016"PRIu64
" %016"PRIu64
" %+9d: %s\n",
160 fprintf(ctx
->log_out
, "ELAPSED: %"PRIu64
" ns\n",
161 t
->last_time_ns
- t
->first_time_ns
);
162 memset(t
, 0, sizeof(*t
));
166 fprintf(ctx
->log_out
, "END OF FRAME %u\n", ctx
->frame_nr
++);
170 fd_log_process(struct fd_context
*ctx
, bool wait
)
172 struct times times
= {0};
174 while (!list_is_empty(&ctx
->log_chunks
)) {
175 struct fd_log_chunk
*chunk
= list_first_entry(&ctx
->log_chunks
,
176 struct fd_log_chunk
, node
);
178 unsigned flags
= DRM_FREEDRENO_PREP_READ
;
180 flags
|= DRM_FREEDRENO_PREP_NOSYNC
;
182 int ret
= fd_bo_cpu_prep(chunk
->timestamps_bo
, ctx
->pipe
, flags
);
186 process_chunk(ctx
, chunk
, ×
);
190 /* We expect that the last processed chunk was the last in it's
191 * batch, which should reset the times:
193 if (times
.last_time_ns
) {
194 fprintf(ctx
->log_out
, "WARNING: last processed chunk not last in batch?");
197 fflush(ctx
->log_out
);
201 fd_log_flush(struct fd_batch
*batch
)
203 /* transfer batch's log chunks to context: */
204 list_splicetail(&batch
->log_chunks
, &batch
->ctx
->log_chunks
);
205 list_inithead(&batch
->log_chunks
);
209 _fd_log(struct fd_batch
*batch
, const char *fmt
, ...)
211 struct fd_context
*ctx
= batch
->ctx
;
212 struct fd_ringbuffer
*ring
= batch
->nondraw
? batch
->draw
: batch
->gmem
;
213 struct fd_log_chunk
*chunk
= get_chunk(batch
);
218 if (vasprintf(&msg
, fmt
, ap
) < 0) {
224 u_fifo_add(chunk
->msg_fifo
, msg
);
226 assert(ctx
->record_timestamp
);
228 /* If nothing else has been emitted to the ring since the last log msg,
229 * skip emitting another timestamp.
231 if (ring
->cur
== chunk
->ring_cur
) {
232 uint64_t *ts
= fd_bo_map(chunk
->timestamps_bo
);
233 /* zero signifies an invalid timestamp to process_chunk(), so it
234 * will use the last valid timestamp for this msg instead.
236 ts
[chunk
->num_msgs
] = 0;
238 ctx
->record_timestamp(ring
, chunk
->timestamps_bo
,
239 chunk
->num_msgs
* sizeof(uint64_t));
243 chunk
->ring_cur
= ring
->cur
;
246 void fd_log_eof(struct fd_context
*ctx
)
248 if (!(fd_mesa_debug
& FD_DBG_LOG
))
251 if (list_is_empty(&ctx
->log_chunks
)) {
252 fprintf(ctx
->log_out
, "WARNING: no log chunks!\n");
256 struct fd_log_chunk
*last_chunk
= list_last_entry(&ctx
->log_chunks
,
257 struct fd_log_chunk
, node
);
258 last_chunk
->eof
= true;
260 /* and process any chunks that are now idle/ready: */
261 fd_log_process(ctx
, false);