xref: /linux/drivers/gpu/drm/xe/xe_devcoredump.c (revision 6a34dfa15d6edf7e78b8118d862d2db0889cf669)
1 // SPDX-License-Identifier: MIT
2 /*
3  * Copyright © 2023 Intel Corporation
4  */
5 
6 #include "xe_devcoredump.h"
7 #include "xe_devcoredump_types.h"
8 
9 #include <linux/ascii85.h>
10 #include <linux/devcoredump.h>
11 #include <generated/utsrelease.h>
12 
13 #include <drm/drm_managed.h>
14 
15 #include "xe_device.h"
16 #include "xe_exec_queue.h"
17 #include "xe_force_wake.h"
18 #include "xe_gt.h"
19 #include "xe_gt_printk.h"
20 #include "xe_guc_capture.h"
21 #include "xe_guc_ct.h"
22 #include "xe_guc_log.h"
23 #include "xe_guc_submit.h"
24 #include "xe_hw_engine.h"
25 #include "xe_module.h"
26 #include "xe_pm.h"
27 #include "xe_sched_job.h"
28 #include "xe_vm.h"
29 
30 /**
31  * DOC: Xe device coredump
32  *
33  * Devices overview:
34  * Xe uses dev_coredump infrastructure for exposing the crash errors in a
35  * standardized way.
36  * devcoredump exposes a temporary device under /sys/class/devcoredump/
37  * which is linked with our card device directly.
38  * The core dump can be accessed either from
39  * /sys/class/drm/card<n>/device/devcoredump/ or from
40  * /sys/class/devcoredump/devcd<m> where
41  * /sys/class/devcoredump/devcd<m>/failing_device is a link to
42  * /sys/class/drm/card<n>/device/.
43  *
44  * Snapshot at hang:
45  * The 'data' file is printed with a drm_printer pointer at devcoredump read
46  * time. For this reason, we need to take snapshots from when the hang has
47  * happened, and not only when the user is reading the file. Otherwise the
48  * information is outdated since the resets might have happened in between.
49  *
50  * 'First' failure snapshot:
51  * In general, the first hang is the most critical one since the following hangs
52  * can be a consequence of the initial hang. For this reason we only take the
53  * snapshot of the 'first' failure and ignore subsequent calls of this function,
54  * at least while the coredump device is alive. Dev_coredump has a delayed work
55  * queue that will eventually delete the device and free all the dump
56  * information.
57  */
58 
59 #ifdef CONFIG_DEV_COREDUMP
60 
61 /* 1 hour timeout */
62 #define XE_COREDUMP_TIMEOUT_JIFFIES (60 * 60 * HZ)
63 
64 static struct xe_device *coredump_to_xe(const struct xe_devcoredump *coredump)
65 {
66 	return container_of(coredump, struct xe_device, devcoredump);
67 }
68 
69 static struct xe_guc *exec_queue_to_guc(struct xe_exec_queue *q)
70 {
71 	return &q->gt->uc.guc;
72 }
73 
74 static ssize_t __xe_devcoredump_read(char *buffer, size_t count,
75 				     struct xe_devcoredump *coredump)
76 {
77 	struct xe_device *xe;
78 	struct xe_devcoredump_snapshot *ss;
79 	struct drm_printer p;
80 	struct drm_print_iterator iter;
81 	struct timespec64 ts;
82 	int i;
83 
84 	xe = coredump_to_xe(coredump);
85 	ss = &coredump->snapshot;
86 
87 	iter.data = buffer;
88 	iter.start = 0;
89 	iter.remain = count;
90 
91 	p = drm_coredump_printer(&iter);
92 
93 	drm_puts(&p, "**** Xe Device Coredump ****\n");
94 	drm_puts(&p, "kernel: " UTS_RELEASE "\n");
95 	drm_puts(&p, "module: " KBUILD_MODNAME "\n");
96 
97 	ts = ktime_to_timespec64(ss->snapshot_time);
98 	drm_printf(&p, "Snapshot time: %lld.%09ld\n", ts.tv_sec, ts.tv_nsec);
99 	ts = ktime_to_timespec64(ss->boot_time);
100 	drm_printf(&p, "Uptime: %lld.%09ld\n", ts.tv_sec, ts.tv_nsec);
101 	drm_printf(&p, "Process: %s\n", ss->process_name);
102 	xe_device_snapshot_print(xe, &p);
103 
104 	drm_printf(&p, "\n**** GT #%d ****\n", ss->gt->info.id);
105 	drm_printf(&p, "\tTile: %d\n", ss->gt->tile->id);
106 
107 	drm_puts(&p, "\n**** GuC Log ****\n");
108 	xe_guc_log_snapshot_print(ss->guc.log, &p);
109 	drm_puts(&p, "\n**** GuC CT ****\n");
110 	xe_guc_ct_snapshot_print(ss->guc.ct, &p);
111 
112 	drm_puts(&p, "\n**** Contexts ****\n");
113 	xe_guc_exec_queue_snapshot_print(ss->ge, &p);
114 
115 	drm_puts(&p, "\n**** Job ****\n");
116 	xe_sched_job_snapshot_print(ss->job, &p);
117 
118 	drm_puts(&p, "\n**** HW Engines ****\n");
119 	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
120 		if (ss->hwe[i])
121 			xe_engine_snapshot_print(ss->hwe[i], &p);
122 
123 	drm_puts(&p, "\n**** VM state ****\n");
124 	xe_vm_snapshot_print(ss->vm, &p);
125 
126 	return count - iter.remain;
127 }
128 
129 static void xe_devcoredump_snapshot_free(struct xe_devcoredump_snapshot *ss)
130 {
131 	int i;
132 
133 	xe_guc_log_snapshot_free(ss->guc.log);
134 	ss->guc.log = NULL;
135 
136 	xe_guc_ct_snapshot_free(ss->guc.ct);
137 	ss->guc.ct = NULL;
138 
139 	xe_guc_capture_put_matched_nodes(&ss->gt->uc.guc);
140 	ss->matched_node = NULL;
141 
142 	xe_guc_exec_queue_snapshot_free(ss->ge);
143 	ss->ge = NULL;
144 
145 	xe_sched_job_snapshot_free(ss->job);
146 	ss->job = NULL;
147 
148 	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
149 		if (ss->hwe[i]) {
150 			xe_hw_engine_snapshot_free(ss->hwe[i]);
151 			ss->hwe[i] = NULL;
152 		}
153 
154 	xe_vm_snapshot_free(ss->vm);
155 	ss->vm = NULL;
156 }
157 
158 static void xe_devcoredump_deferred_snap_work(struct work_struct *work)
159 {
160 	struct xe_devcoredump_snapshot *ss = container_of(work, typeof(*ss), work);
161 	struct xe_devcoredump *coredump = container_of(ss, typeof(*coredump), snapshot);
162 	struct xe_device *xe = coredump_to_xe(coredump);
163 	unsigned int fw_ref;
164 
165 	xe_pm_runtime_get(xe);
166 
167 	/* keep going if fw fails as we still want to save the memory and SW data */
168 	fw_ref = xe_force_wake_get(gt_to_fw(ss->gt), XE_FORCEWAKE_ALL);
169 	if (!xe_force_wake_ref_has_domain(fw_ref, XE_FORCEWAKE_ALL))
170 		xe_gt_info(ss->gt, "failed to get forcewake for coredump capture\n");
171 	xe_vm_snapshot_capture_delayed(ss->vm);
172 	xe_guc_exec_queue_snapshot_capture_delayed(ss->ge);
173 	xe_force_wake_put(gt_to_fw(ss->gt), fw_ref);
174 
175 	xe_pm_runtime_put(xe);
176 
177 	/* Calculate devcoredump size */
178 	ss->read.size = __xe_devcoredump_read(NULL, INT_MAX, coredump);
179 
180 	ss->read.buffer = kvmalloc(ss->read.size, GFP_USER);
181 	if (!ss->read.buffer)
182 		return;
183 
184 	__xe_devcoredump_read(ss->read.buffer, ss->read.size, coredump);
185 	xe_devcoredump_snapshot_free(ss);
186 }
187 
188 static ssize_t xe_devcoredump_read(char *buffer, loff_t offset,
189 				   size_t count, void *data, size_t datalen)
190 {
191 	struct xe_devcoredump *coredump = data;
192 	struct xe_devcoredump_snapshot *ss;
193 	ssize_t byte_copied;
194 
195 	if (!coredump)
196 		return -ENODEV;
197 
198 	ss = &coredump->snapshot;
199 
200 	/* Ensure delayed work is captured before continuing */
201 	flush_work(&ss->work);
202 
203 	if (!ss->read.buffer)
204 		return -ENODEV;
205 
206 	if (offset >= ss->read.size)
207 		return 0;
208 
209 	byte_copied = count < ss->read.size - offset ? count :
210 		ss->read.size - offset;
211 	memcpy(buffer, ss->read.buffer + offset, byte_copied);
212 
213 	return byte_copied;
214 }
215 
216 static void xe_devcoredump_free(void *data)
217 {
218 	struct xe_devcoredump *coredump = data;
219 
220 	/* Our device is gone. Nothing to do... */
221 	if (!data || !coredump_to_xe(coredump))
222 		return;
223 
224 	cancel_work_sync(&coredump->snapshot.work);
225 
226 	xe_devcoredump_snapshot_free(&coredump->snapshot);
227 	kvfree(coredump->snapshot.read.buffer);
228 
229 	/* To prevent stale data on next snapshot, clear everything */
230 	memset(&coredump->snapshot, 0, sizeof(coredump->snapshot));
231 	coredump->captured = false;
232 	coredump->job = NULL;
233 	drm_info(&coredump_to_xe(coredump)->drm,
234 		 "Xe device coredump has been deleted.\n");
235 }
236 
237 static void devcoredump_snapshot(struct xe_devcoredump *coredump,
238 				 struct xe_sched_job *job)
239 {
240 	struct xe_devcoredump_snapshot *ss = &coredump->snapshot;
241 	struct xe_exec_queue *q = job->q;
242 	struct xe_guc *guc = exec_queue_to_guc(q);
243 	u32 adj_logical_mask = q->logical_mask;
244 	u32 width_mask = (0x1 << q->width) - 1;
245 	const char *process_name = "no process";
246 
247 	unsigned int fw_ref;
248 	bool cookie;
249 	int i;
250 
251 	ss->snapshot_time = ktime_get_real();
252 	ss->boot_time = ktime_get_boottime();
253 
254 	if (q->vm && q->vm->xef)
255 		process_name = q->vm->xef->process_name;
256 	strscpy(ss->process_name, process_name);
257 
258 	ss->gt = q->gt;
259 	coredump->job = job;
260 	INIT_WORK(&ss->work, xe_devcoredump_deferred_snap_work);
261 
262 	cookie = dma_fence_begin_signalling();
263 	for (i = 0; q->width > 1 && i < XE_HW_ENGINE_MAX_INSTANCE;) {
264 		if (adj_logical_mask & BIT(i)) {
265 			adj_logical_mask |= width_mask << i;
266 			i += q->width;
267 		} else {
268 			++i;
269 		}
270 	}
271 
272 	/* keep going if fw fails as we still want to save the memory and SW data */
273 	fw_ref = xe_force_wake_get(gt_to_fw(q->gt), XE_FORCEWAKE_ALL);
274 
275 	ss->guc.log = xe_guc_log_snapshot_capture(&guc->log, true);
276 	ss->guc.ct = xe_guc_ct_snapshot_capture(&guc->ct);
277 	ss->ge = xe_guc_exec_queue_snapshot_capture(q);
278 	ss->job = xe_sched_job_snapshot_capture(job);
279 	ss->vm = xe_vm_snapshot_capture(q->vm);
280 
281 	xe_engine_snapshot_capture_for_job(job);
282 
283 	queue_work(system_unbound_wq, &ss->work);
284 
285 	xe_force_wake_put(gt_to_fw(q->gt), fw_ref);
286 	dma_fence_end_signalling(cookie);
287 }
288 
289 /**
290  * xe_devcoredump - Take the required snapshots and initialize coredump device.
291  * @job: The faulty xe_sched_job, where the issue was detected.
292  *
293  * This function should be called at the crash time within the serialized
294  * gt_reset. It is skipped if we still have the core dump device available
295  * with the information of the 'first' snapshot.
296  */
297 void xe_devcoredump(struct xe_sched_job *job)
298 {
299 	struct xe_device *xe = gt_to_xe(job->q->gt);
300 	struct xe_devcoredump *coredump = &xe->devcoredump;
301 
302 	if (coredump->captured) {
303 		drm_dbg(&xe->drm, "Multiple hangs are occurring, but only the first snapshot was taken\n");
304 		return;
305 	}
306 
307 	coredump->captured = true;
308 	devcoredump_snapshot(coredump, job);
309 
310 	drm_info(&xe->drm, "Xe device coredump has been created\n");
311 	drm_info(&xe->drm, "Check your /sys/class/drm/card%d/device/devcoredump/data\n",
312 		 xe->drm.primary->index);
313 
314 	dev_coredumpm_timeout(xe->drm.dev, THIS_MODULE, coredump, 0, GFP_KERNEL,
315 			      xe_devcoredump_read, xe_devcoredump_free,
316 			      XE_COREDUMP_TIMEOUT_JIFFIES);
317 }
318 
319 static void xe_driver_devcoredump_fini(void *arg)
320 {
321 	struct drm_device *drm = arg;
322 
323 	dev_coredump_put(drm->dev);
324 }
325 
326 int xe_devcoredump_init(struct xe_device *xe)
327 {
328 	return devm_add_action_or_reset(xe->drm.dev, xe_driver_devcoredump_fini, &xe->drm);
329 }
330 
331 #endif
332 
333 /**
334  * xe_print_blob_ascii85 - print a BLOB to some useful location in ASCII85
335  *
336  * The output is split to multiple lines because some print targets, e.g. dmesg
337  * cannot handle arbitrarily long lines. Note also that printing to dmesg in
338  * piece-meal fashion is not possible, each separate call to drm_puts() has a
339  * line-feed automatically added! Therefore, the entire output line must be
340  * constructed in a local buffer first, then printed in one atomic output call.
341  *
342  * There is also a scheduler yield call to prevent the 'task has been stuck for
343  * 120s' kernel hang check feature from firing when printing to a slow target
344  * such as dmesg over a serial port.
345  *
346  * TODO: Add compression prior to the ASCII85 encoding to shrink huge buffers down.
347  *
348  * @p: the printer object to output to
349  * @prefix: optional prefix to add to output string
350  * @blob: the Binary Large OBject to dump out
351  * @offset: offset in bytes to skip from the front of the BLOB, must be a multiple of sizeof(u32)
352  * @size: the size in bytes of the BLOB, must be a multiple of sizeof(u32)
353  */
354 void xe_print_blob_ascii85(struct drm_printer *p, const char *prefix,
355 			   const void *blob, size_t offset, size_t size)
356 {
357 	const u32 *blob32 = (const u32 *)blob;
358 	char buff[ASCII85_BUFSZ], *line_buff;
359 	size_t line_pos = 0;
360 
361 #define DMESG_MAX_LINE_LEN	800
362 #define MIN_SPACE		(ASCII85_BUFSZ + 2)		/* 85 + "\n\0" */
363 
364 	if (size & 3)
365 		drm_printf(p, "Size not word aligned: %zu", size);
366 	if (offset & 3)
367 		drm_printf(p, "Offset not word aligned: %zu", size);
368 
369 	line_buff = kzalloc(DMESG_MAX_LINE_LEN, GFP_KERNEL);
370 	if (IS_ERR_OR_NULL(line_buff)) {
371 		drm_printf(p, "Failed to allocate line buffer: %pe", line_buff);
372 		return;
373 	}
374 
375 	blob32 += offset / sizeof(*blob32);
376 	size /= sizeof(*blob32);
377 
378 	if (prefix) {
379 		strscpy(line_buff, prefix, DMESG_MAX_LINE_LEN - MIN_SPACE - 2);
380 		line_pos = strlen(line_buff);
381 
382 		line_buff[line_pos++] = ':';
383 		line_buff[line_pos++] = ' ';
384 	}
385 
386 	while (size--) {
387 		u32 val = *(blob32++);
388 
389 		strscpy(line_buff + line_pos, ascii85_encode(val, buff),
390 			DMESG_MAX_LINE_LEN - line_pos);
391 		line_pos += strlen(line_buff + line_pos);
392 
393 		if ((line_pos + MIN_SPACE) >= DMESG_MAX_LINE_LEN) {
394 			line_buff[line_pos++] = '\n';
395 			line_buff[line_pos++] = 0;
396 
397 			drm_puts(p, line_buff);
398 
399 			line_pos = 0;
400 
401 			/* Prevent 'stuck thread' time out errors */
402 			cond_resched();
403 		}
404 	}
405 
406 	if (line_pos) {
407 		line_buff[line_pos++] = '\n';
408 		line_buff[line_pos++] = 0;
409 
410 		drm_puts(p, line_buff);
411 	}
412 
413 	kfree(line_buff);
414 
415 #undef MIN_SPACE
416 #undef DMESG_MAX_LINE_LEN
417 }
418