radeonsi: add an option for debugging VM faults
[mesa.git] / src / gallium / drivers / radeonsi / si_debug.c
1 /*
2 * Copyright 2015 Advanced Micro Devices, 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 * on the rights to use, copy, modify, merge, publish, distribute, sub
8 * license, and/or sell copies of the Software, and to permit persons to whom
9 * the 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 NON-INFRINGEMENT. IN NO EVENT SHALL
18 * THE AUTHOR(S) AND/OR THEIR SUPPLIERS BE LIABLE FOR ANY CLAIM,
19 * DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
20 * OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
21 * USE OR OTHER DEALINGS IN THE SOFTWARE.
22 *
23 * Authors:
24 * Marek Olšák <maraeo@gmail.com>
25 */
26
27 #include "si_pipe.h"
28 #include "si_shader.h"
29 #include "sid.h"
30 #include "sid_tables.h"
31 #include "ddebug/dd_util.h"
32
33
34 static void si_dump_shader(struct si_shader_selector *sel, const char *name,
35 FILE *f)
36 {
37 if (!sel || !sel->current)
38 return;
39
40 fprintf(f, "%s shader disassembly:\n", name);
41 si_dump_shader_key(sel->type, &sel->current->key, f);
42 fprintf(f, "%s\n\n", sel->current->binary.disasm_string);
43 }
44
45 /* Parsed IBs are difficult to read without colors. Use "less -R file" to
46 * read them, or use "aha -b -f file" to convert them to html.
47 */
48 #define COLOR_RESET "\033[0m"
49 #define COLOR_RED "\033[31m"
50 #define COLOR_GREEN "\033[1;32m"
51 #define COLOR_YELLOW "\033[1;33m"
52 #define COLOR_CYAN "\033[1;36m"
53
54 #define INDENT_PKT 8
55
56 static void print_spaces(FILE *f, unsigned num)
57 {
58 fprintf(f, "%*s", num, "");
59 }
60
61 static void print_value(FILE *file, uint32_t value, int bits)
62 {
63 /* Guess if it's int or float */
64 if (value <= (1 << 15))
65 fprintf(file, "%u\n", value);
66 else {
67 float f = uif(value);
68
69 if (fabs(f) < 100000 && f*10 == floor(f*10))
70 fprintf(file, "%.1ff\n", f);
71 else
72 /* Don't print more leading zeros than there are bits. */
73 fprintf(file, "0x%0*x\n", bits / 4, value);
74 }
75 }
76
77 static void print_named_value(FILE *file, const char *name, uint32_t value,
78 int bits)
79 {
80 print_spaces(file, INDENT_PKT);
81 fprintf(file, COLOR_YELLOW "%s" COLOR_RESET " <- ", name);
82 print_value(file, value, bits);
83 }
84
85 static void si_dump_reg(FILE *file, unsigned offset, uint32_t value,
86 uint32_t field_mask)
87 {
88 int r, f;
89
90 for (r = 0; r < ARRAY_SIZE(reg_table); r++) {
91 const struct si_reg *reg = &reg_table[r];
92
93 if (reg->offset == offset) {
94 bool first_field = true;
95
96 print_spaces(file, INDENT_PKT);
97 fprintf(file, COLOR_YELLOW "%s" COLOR_RESET " <- ",
98 reg->name);
99
100 if (!reg->num_fields) {
101 print_value(file, value, 32);
102 return;
103 }
104
105 for (f = 0; f < reg->num_fields; f++) {
106 const struct si_field *field = &reg->fields[f];
107 uint32_t val = (value & field->mask) >>
108 (ffs(field->mask) - 1);
109
110 if (!(field->mask & field_mask))
111 continue;
112
113 /* Indent the field. */
114 if (!first_field)
115 print_spaces(file,
116 INDENT_PKT + strlen(reg->name) + 4);
117
118 /* Print the field. */
119 fprintf(file, "%s = ", field->name);
120
121 if (val < field->num_values && field->values[val])
122 fprintf(file, "%s\n", field->values[val]);
123 else
124 print_value(file, val,
125 util_bitcount(field->mask));
126
127 first_field = false;
128 }
129 return;
130 }
131 }
132
133 fprintf(file, COLOR_YELLOW "0x%05x" COLOR_RESET " = 0x%08x", offset, value);
134 }
135
136 static void si_parse_set_reg_packet(FILE *f, uint32_t *ib, unsigned count,
137 unsigned reg_offset)
138 {
139 unsigned reg = (ib[1] << 2) + reg_offset;
140 int i;
141
142 for (i = 0; i < count; i++)
143 si_dump_reg(f, reg + i*4, ib[2+i], ~0);
144 }
145
146 static uint32_t *si_parse_packet3(FILE *f, uint32_t *ib, int *num_dw,
147 int trace_id)
148 {
149 unsigned count = PKT_COUNT_G(ib[0]);
150 unsigned op = PKT3_IT_OPCODE_G(ib[0]);
151 const char *predicate = PKT3_PREDICATE(ib[0]) ? "(predicate)" : "";
152 int i;
153
154 /* Print the name first. */
155 for (i = 0; i < ARRAY_SIZE(packet3_table); i++)
156 if (packet3_table[i].op == op)
157 break;
158
159 if (i < ARRAY_SIZE(packet3_table))
160 if (op == PKT3_SET_CONTEXT_REG ||
161 op == PKT3_SET_CONFIG_REG ||
162 op == PKT3_SET_UCONFIG_REG ||
163 op == PKT3_SET_SH_REG)
164 fprintf(f, COLOR_CYAN "%s%s" COLOR_CYAN ":\n",
165 packet3_table[i].name, predicate);
166 else
167 fprintf(f, COLOR_GREEN "%s%s" COLOR_RESET ":\n",
168 packet3_table[i].name, predicate);
169 else
170 fprintf(f, COLOR_RED "PKT3_UNKNOWN 0x%x%s" COLOR_RESET ":\n",
171 op, predicate);
172
173 /* Print the contents. */
174 switch (op) {
175 case PKT3_SET_CONTEXT_REG:
176 si_parse_set_reg_packet(f, ib, count, SI_CONTEXT_REG_OFFSET);
177 break;
178 case PKT3_SET_CONFIG_REG:
179 si_parse_set_reg_packet(f, ib, count, SI_CONFIG_REG_OFFSET);
180 break;
181 case PKT3_SET_UCONFIG_REG:
182 si_parse_set_reg_packet(f, ib, count, CIK_UCONFIG_REG_OFFSET);
183 break;
184 case PKT3_SET_SH_REG:
185 si_parse_set_reg_packet(f, ib, count, SI_SH_REG_OFFSET);
186 break;
187 case PKT3_DRAW_PREAMBLE:
188 si_dump_reg(f, R_030908_VGT_PRIMITIVE_TYPE, ib[1], ~0);
189 si_dump_reg(f, R_028AA8_IA_MULTI_VGT_PARAM, ib[2], ~0);
190 si_dump_reg(f, R_028B58_VGT_LS_HS_CONFIG, ib[3], ~0);
191 break;
192 case PKT3_ACQUIRE_MEM:
193 si_dump_reg(f, R_0301F0_CP_COHER_CNTL, ib[1], ~0);
194 si_dump_reg(f, R_0301F4_CP_COHER_SIZE, ib[2], ~0);
195 si_dump_reg(f, R_030230_CP_COHER_SIZE_HI, ib[3], ~0);
196 si_dump_reg(f, R_0301F8_CP_COHER_BASE, ib[4], ~0);
197 si_dump_reg(f, R_0301E4_CP_COHER_BASE_HI, ib[5], ~0);
198 print_named_value(f, "POLL_INTERVAL", ib[6], 16);
199 break;
200 case PKT3_SURFACE_SYNC:
201 si_dump_reg(f, R_0085F0_CP_COHER_CNTL, ib[1], ~0);
202 si_dump_reg(f, R_0085F4_CP_COHER_SIZE, ib[2], ~0);
203 si_dump_reg(f, R_0085F8_CP_COHER_BASE, ib[3], ~0);
204 print_named_value(f, "POLL_INTERVAL", ib[4], 16);
205 break;
206 case PKT3_EVENT_WRITE:
207 si_dump_reg(f, R_028A90_VGT_EVENT_INITIATOR, ib[1],
208 S_028A90_EVENT_TYPE(~0));
209 print_named_value(f, "EVENT_INDEX", (ib[1] >> 8) & 0xf, 4);
210 print_named_value(f, "INV_L2", (ib[1] >> 20) & 0x1, 1);
211 if (count > 0) {
212 print_named_value(f, "ADDRESS_LO", ib[2], 32);
213 print_named_value(f, "ADDRESS_HI", ib[3], 16);
214 }
215 break;
216 case PKT3_DRAW_INDEX_AUTO:
217 si_dump_reg(f, R_030930_VGT_NUM_INDICES, ib[1], ~0);
218 si_dump_reg(f, R_0287F0_VGT_DRAW_INITIATOR, ib[2], ~0);
219 break;
220 case PKT3_DRAW_INDEX_2:
221 si_dump_reg(f, R_028A78_VGT_DMA_MAX_SIZE, ib[1], ~0);
222 si_dump_reg(f, R_0287E8_VGT_DMA_BASE, ib[2], ~0);
223 si_dump_reg(f, R_0287E4_VGT_DMA_BASE_HI, ib[3], ~0);
224 si_dump_reg(f, R_030930_VGT_NUM_INDICES, ib[4], ~0);
225 si_dump_reg(f, R_0287F0_VGT_DRAW_INITIATOR, ib[5], ~0);
226 break;
227 case PKT3_INDEX_TYPE:
228 si_dump_reg(f, R_028A7C_VGT_DMA_INDEX_TYPE, ib[1], ~0);
229 break;
230 case PKT3_NUM_INSTANCES:
231 si_dump_reg(f, R_030934_VGT_NUM_INSTANCES, ib[1], ~0);
232 break;
233 case PKT3_WRITE_DATA:
234 si_dump_reg(f, R_370_CONTROL, ib[1], ~0);
235 si_dump_reg(f, R_371_DST_ADDR_LO, ib[2], ~0);
236 si_dump_reg(f, R_372_DST_ADDR_HI, ib[3], ~0);
237 for (i = 2; i < count; i++) {
238 print_spaces(f, INDENT_PKT);
239 fprintf(f, "0x%08x\n", ib[2+i]);
240 }
241 break;
242 case PKT3_CP_DMA:
243 si_dump_reg(f, R_410_CP_DMA_WORD0, ib[1], ~0);
244 si_dump_reg(f, R_411_CP_DMA_WORD1, ib[2], ~0);
245 si_dump_reg(f, R_412_CP_DMA_WORD2, ib[3], ~0);
246 si_dump_reg(f, R_413_CP_DMA_WORD3, ib[4], ~0);
247 si_dump_reg(f, R_414_COMMAND, ib[5], ~0);
248 break;
249 case PKT3_DMA_DATA:
250 si_dump_reg(f, R_500_DMA_DATA_WORD0, ib[1], ~0);
251 si_dump_reg(f, R_501_SRC_ADDR_LO, ib[2], ~0);
252 si_dump_reg(f, R_502_SRC_ADDR_HI, ib[3], ~0);
253 si_dump_reg(f, R_503_DST_ADDR_LO, ib[4], ~0);
254 si_dump_reg(f, R_504_DST_ADDR_HI, ib[5], ~0);
255 si_dump_reg(f, R_414_COMMAND, ib[6], ~0);
256 break;
257 case PKT3_NOP:
258 if (ib[0] == 0xffff1000) {
259 count = -1; /* One dword NOP. */
260 break;
261 } else if (count == 0 && SI_IS_TRACE_POINT(ib[1])) {
262 unsigned packet_id = SI_GET_TRACE_POINT_ID(ib[1]);
263
264 print_spaces(f, INDENT_PKT);
265 fprintf(f, COLOR_RED "Trace point ID: %u\n", packet_id);
266
267 if (trace_id == -1)
268 break; /* tracing was disabled */
269
270 print_spaces(f, INDENT_PKT);
271 if (packet_id < trace_id)
272 fprintf(f, COLOR_RED
273 "This trace point was reached by the CP."
274 COLOR_RESET "\n");
275 else if (packet_id == trace_id)
276 fprintf(f, COLOR_RED
277 "!!!!! This is the last trace point that "
278 "was reached by the CP !!!!!"
279 COLOR_RESET "\n");
280 else if (packet_id+1 == trace_id)
281 fprintf(f, COLOR_RED
282 "!!!!! This is the first trace point that "
283 "was NOT been reached by the CP !!!!!"
284 COLOR_RESET "\n");
285 else
286 fprintf(f, COLOR_RED
287 "!!!!! This trace point was NOT reached "
288 "by the CP !!!!!"
289 COLOR_RESET "\n");
290 break;
291 }
292 /* fall through, print all dwords */
293 default:
294 for (i = 0; i < count+1; i++) {
295 print_spaces(f, INDENT_PKT);
296 fprintf(f, "0x%08x\n", ib[1+i]);
297 }
298 }
299
300 ib += count + 2;
301 *num_dw -= count + 2;
302 return ib;
303 }
304
305 /**
306 * Parse and print an IB into a file.
307 *
308 * \param f file
309 * \param ib IB
310 * \param num_dw size of the IB
311 * \param chip_class chip class
312 * \param trace_id the last trace ID that is known to have been reached
313 * and executed by the CP, typically read from a buffer
314 */
315 static void si_parse_ib(FILE *f, uint32_t *ib, int num_dw, int trace_id)
316 {
317 fprintf(f, "------------------ IB begin ------------------\n");
318
319 while (num_dw > 0) {
320 unsigned type = PKT_TYPE_G(ib[0]);
321
322 switch (type) {
323 case 3:
324 ib = si_parse_packet3(f, ib, &num_dw, trace_id);
325 break;
326 case 2:
327 /* type-2 nop */
328 if (ib[0] == 0x80000000) {
329 fprintf(f, COLOR_GREEN "NOP (type 2)" COLOR_RESET "\n");
330 ib++;
331 break;
332 }
333 /* fall through */
334 default:
335 fprintf(f, "Unknown packet type %i\n", type);
336 return;
337 }
338 }
339
340 fprintf(f, "------------------- IB end -------------------\n");
341 if (num_dw < 0) {
342 printf("Packet ends after the end of IB.\n");
343 exit(0);
344 }
345 }
346
347 static void si_dump_mmapped_reg(struct si_context *sctx, FILE *f,
348 unsigned offset)
349 {
350 struct radeon_winsys *ws = sctx->b.ws;
351 uint32_t value;
352
353 if (ws->read_registers(ws, offset, 1, &value))
354 si_dump_reg(f, offset, value, ~0);
355 }
356
357 static void si_dump_debug_registers(struct si_context *sctx, FILE *f)
358 {
359 if (sctx->screen->b.info.drm_major == 2 &&
360 sctx->screen->b.info.drm_minor < 42)
361 return; /* no radeon support */
362
363 fprintf(f, "Memory-mapped registers:\n");
364 si_dump_mmapped_reg(sctx, f, R_008010_GRBM_STATUS);
365
366 /* No other registers can be read on DRM < 3.1.0. */
367 if (sctx->screen->b.info.drm_major < 3 ||
368 sctx->screen->b.info.drm_minor < 1) {
369 fprintf(f, "\n");
370 return;
371 }
372
373 si_dump_mmapped_reg(sctx, f, R_008008_GRBM_STATUS2);
374 si_dump_mmapped_reg(sctx, f, R_008014_GRBM_STATUS_SE0);
375 si_dump_mmapped_reg(sctx, f, R_008018_GRBM_STATUS_SE1);
376 si_dump_mmapped_reg(sctx, f, R_008038_GRBM_STATUS_SE2);
377 si_dump_mmapped_reg(sctx, f, R_00803C_GRBM_STATUS_SE3);
378 si_dump_mmapped_reg(sctx, f, R_00D034_SDMA0_STATUS_REG);
379 si_dump_mmapped_reg(sctx, f, R_00D834_SDMA1_STATUS_REG);
380 si_dump_mmapped_reg(sctx, f, R_000E50_SRBM_STATUS);
381 si_dump_mmapped_reg(sctx, f, R_000E4C_SRBM_STATUS2);
382 si_dump_mmapped_reg(sctx, f, R_000E54_SRBM_STATUS3);
383 si_dump_mmapped_reg(sctx, f, R_008680_CP_STAT);
384 si_dump_mmapped_reg(sctx, f, R_008674_CP_STALLED_STAT1);
385 si_dump_mmapped_reg(sctx, f, R_008678_CP_STALLED_STAT2);
386 si_dump_mmapped_reg(sctx, f, R_008670_CP_STALLED_STAT3);
387 si_dump_mmapped_reg(sctx, f, R_008210_CP_CPC_STATUS);
388 si_dump_mmapped_reg(sctx, f, R_008214_CP_CPC_BUSY_STAT);
389 si_dump_mmapped_reg(sctx, f, R_008218_CP_CPC_STALLED_STAT1);
390 si_dump_mmapped_reg(sctx, f, R_00821C_CP_CPF_STATUS);
391 si_dump_mmapped_reg(sctx, f, R_008220_CP_CPF_BUSY_STAT);
392 si_dump_mmapped_reg(sctx, f, R_008224_CP_CPF_STALLED_STAT1);
393 fprintf(f, "\n");
394 }
395
396 static void si_dump_last_ib(struct si_context *sctx, FILE *f)
397 {
398 int last_trace_id = -1;
399
400 if (!sctx->last_ib)
401 return;
402
403 if (sctx->last_trace_buf) {
404 /* We are expecting that the ddebug pipe has already
405 * waited for the context, so this buffer should be idle.
406 * If the GPU is hung, there is no point in waiting for it.
407 */
408 uint32_t *map = sctx->b.ws->buffer_map(sctx->last_trace_buf->cs_buf,
409 NULL,
410 PIPE_TRANSFER_UNSYNCHRONIZED |
411 PIPE_TRANSFER_READ);
412 if (map)
413 last_trace_id = *map;
414 }
415
416 si_parse_ib(f, sctx->last_ib, sctx->last_ib_dw_size,
417 last_trace_id);
418 free(sctx->last_ib); /* dump only once */
419 sctx->last_ib = NULL;
420 r600_resource_reference(&sctx->last_trace_buf, NULL);
421 }
422
423 static void si_dump_debug_state(struct pipe_context *ctx, FILE *f,
424 unsigned flags)
425 {
426 struct si_context *sctx = (struct si_context*)ctx;
427
428 if (flags & PIPE_DEBUG_DEVICE_IS_HUNG)
429 si_dump_debug_registers(sctx, f);
430
431 si_dump_shader(sctx->vs_shader, "Vertex", f);
432 si_dump_shader(sctx->tcs_shader, "Tessellation control", f);
433 si_dump_shader(sctx->tes_shader, "Tessellation evaluation", f);
434 si_dump_shader(sctx->gs_shader, "Geometry", f);
435 si_dump_shader(sctx->ps_shader, "Fragment", f);
436
437 si_dump_last_ib(sctx, f);
438
439 fprintf(f, "Done.\n");
440 }
441
442 static bool si_vm_fault_occured(struct si_context *sctx, uint32_t *out_addr)
443 {
444 char line[2000];
445 unsigned sec, usec;
446 int progress = 0;
447 uint64_t timestamp = 0;
448 bool fault = false;
449
450 FILE *p = popen("dmesg", "r");
451 if (!p)
452 return false;
453
454 while (fgets(line, sizeof(line), p)) {
455 char *msg, len;
456
457 /* Get the timestamp. */
458 if (sscanf(line, "[%u.%u]", &sec, &usec) != 2) {
459 assert(0);
460 continue;
461 }
462 timestamp = sec * 1000000llu + usec;
463
464 /* If just updating the timestamp. */
465 if (!out_addr)
466 continue;
467
468 /* Process messages only if the timestamp is newer. */
469 if (timestamp <= sctx->dmesg_timestamp)
470 continue;
471
472 /* Only process the first VM fault. */
473 if (fault)
474 continue;
475
476 /* Remove trailing \n */
477 len = strlen(line);
478 if (len && line[len-1] == '\n')
479 line[len-1] = 0;
480
481 /* Get the message part. */
482 msg = strchr(line, ']');
483 if (!msg) {
484 assert(0);
485 continue;
486 }
487 msg++;
488
489 switch (progress) {
490 case 0:
491 if (strstr(msg, "GPU fault detected:"))
492 progress = 1;
493 break;
494 case 1:
495 msg = strstr(msg, "VM_CONTEXT1_PROTECTION_FAULT_ADDR");
496 if (msg) {
497 msg = strstr(msg, "0x");
498 if (msg) {
499 msg += 2;
500 if (sscanf(msg, "%X", out_addr) == 1)
501 fault = true;
502 }
503 }
504 progress = 0;
505 break;
506 default:
507 progress = 0;
508 }
509 }
510 pclose(p);
511
512 if (timestamp > sctx->dmesg_timestamp)
513 sctx->dmesg_timestamp = timestamp;
514 return fault;
515 }
516
517 void si_check_vm_faults(struct si_context *sctx)
518 {
519 struct pipe_screen *screen = sctx->b.b.screen;
520 FILE *f;
521 uint32_t addr;
522
523 /* Use conservative timeout 800ms, after which we won't wait any
524 * longer and assume the GPU is hung.
525 */
526 screen->fence_finish(screen, sctx->last_gfx_fence, 800*1000*1000);
527
528 if (!si_vm_fault_occured(sctx, &addr))
529 return;
530
531 f = dd_get_debug_file();
532 if (!f)
533 return;
534
535 fprintf(f, "VM fault report.\n\n");
536 fprintf(f, "Driver vendor: %s\n", screen->get_vendor(screen));
537 fprintf(f, "Device vendor: %s\n", screen->get_device_vendor(screen));
538 fprintf(f, "Device name: %s\n\n", screen->get_name(screen));
539 fprintf(f, "Failing VM page: 0x%08x\n\n", addr);
540
541 si_dump_last_ib(sctx, f);
542 fclose(f);
543
544 fprintf(stderr, "Detected a VM fault, exiting...\n");
545 exit(0);
546 }
547
548 void si_init_debug_functions(struct si_context *sctx)
549 {
550 sctx->b.b.dump_debug_state = si_dump_debug_state;
551
552 /* Set the initial dmesg timestamp for this context, so that
553 * only new messages will be checked for VM faults.
554 */
555 if (sctx->screen->b.debug_flags & DBG_CHECK_VM)
556 si_vm_fault_occured(sctx, NULL);
557 }