xref: /linux/drivers/gpu/drm/xe/xe_devcoredump.c (revision 7ee983c850b40043ac4751836fbd9a2b4d0c5937)
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  * Xe uses dev_coredump infrastructure for exposing the crash errors in a
34  * standardized way. Once a crash occurs, devcoredump exposes a temporary
35  * node under ``/sys/class/devcoredump/devcd<m>/``. The same node is also
36  * accessible in ``/sys/class/drm/card<n>/device/devcoredump/``. The
37  * ``failing_device`` symlink points to the device that crashed and created the
38  * coredump.
39  *
40  * The following characteristics are observed by xe when creating a device
41  * coredump:
42  *
43  * **Snapshot at hang**:
44  *   The 'data' file contains a snapshot of the HW and driver states at the time
45  *   the hang happened. Due to the driver recovering from resets/crashes, it may
46  *   not correspond to the state of the system when the file is read by
47  *   userspace.
48  *
49  * **Coredump release**:
50  *   After a coredump is generated, it stays in kernel memory until released by
51  *   userspace by writing anything to it, or after an internal timer expires. The
52  *   exact timeout may vary and should not be relied upon. Example to release
53  *   a coredump:
54  *
55  *   .. code-block:: shell
56  *
57  *	$ > /sys/class/drm/card0/device/devcoredump/data
58  *
59  * **First failure only**:
60  *   In general, the first hang is the most critical one since the following
61  *   hangs can be a consequence of the initial hang. For this reason a snapshot
62  *   is taken only for the first failure. Until the devcoredump is released by
63  *   userspace or kernel, all subsequent hangs do not override the snapshot nor
64  *   create new ones. Devcoredump has a delayed work queue that will eventually
65  *   delete the file node and free all the dump information.
66  */
67 
68 #ifdef CONFIG_DEV_COREDUMP
69 
70 /* 1 hour timeout */
71 #define XE_COREDUMP_TIMEOUT_JIFFIES (60 * 60 * HZ)
72 
coredump_to_xe(const struct xe_devcoredump * coredump)73 static struct xe_device *coredump_to_xe(const struct xe_devcoredump *coredump)
74 {
75 	return container_of(coredump, struct xe_device, devcoredump);
76 }
77 
exec_queue_to_guc(struct xe_exec_queue * q)78 static struct xe_guc *exec_queue_to_guc(struct xe_exec_queue *q)
79 {
80 	return &q->gt->uc.guc;
81 }
82 
__xe_devcoredump_read(char * buffer,size_t count,struct xe_devcoredump * coredump)83 static ssize_t __xe_devcoredump_read(char *buffer, size_t count,
84 				     struct xe_devcoredump *coredump)
85 {
86 	struct xe_device *xe;
87 	struct xe_devcoredump_snapshot *ss;
88 	struct drm_printer p;
89 	struct drm_print_iterator iter;
90 	struct timespec64 ts;
91 	int i;
92 
93 	xe = coredump_to_xe(coredump);
94 	ss = &coredump->snapshot;
95 
96 	iter.data = buffer;
97 	iter.start = 0;
98 	iter.remain = count;
99 
100 	p = drm_coredump_printer(&iter);
101 
102 	drm_puts(&p, "**** Xe Device Coredump ****\n");
103 	drm_printf(&p, "Reason: %s\n", ss->reason);
104 	drm_puts(&p, "kernel: " UTS_RELEASE "\n");
105 	drm_puts(&p, "module: " KBUILD_MODNAME "\n");
106 
107 	ts = ktime_to_timespec64(ss->snapshot_time);
108 	drm_printf(&p, "Snapshot time: %lld.%09ld\n", ts.tv_sec, ts.tv_nsec);
109 	ts = ktime_to_timespec64(ss->boot_time);
110 	drm_printf(&p, "Uptime: %lld.%09ld\n", ts.tv_sec, ts.tv_nsec);
111 	drm_printf(&p, "Process: %s [%d]\n", ss->process_name, ss->pid);
112 	xe_device_snapshot_print(xe, &p);
113 
114 	drm_printf(&p, "\n**** GT #%d ****\n", ss->gt->info.id);
115 	drm_printf(&p, "\tTile: %d\n", ss->gt->tile->id);
116 
117 	drm_puts(&p, "\n**** GuC Log ****\n");
118 	xe_guc_log_snapshot_print(ss->guc.log, &p);
119 	drm_puts(&p, "\n**** GuC CT ****\n");
120 	xe_guc_ct_snapshot_print(ss->guc.ct, &p);
121 
122 	drm_puts(&p, "\n**** Contexts ****\n");
123 	xe_guc_exec_queue_snapshot_print(ss->ge, &p);
124 
125 	drm_puts(&p, "\n**** Job ****\n");
126 	xe_sched_job_snapshot_print(ss->job, &p);
127 
128 	drm_puts(&p, "\n**** HW Engines ****\n");
129 	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
130 		if (ss->hwe[i])
131 			xe_engine_snapshot_print(ss->hwe[i], &p);
132 
133 	drm_puts(&p, "\n**** VM state ****\n");
134 	xe_vm_snapshot_print(ss->vm, &p);
135 
136 	return count - iter.remain;
137 }
138 
xe_devcoredump_snapshot_free(struct xe_devcoredump_snapshot * ss)139 static void xe_devcoredump_snapshot_free(struct xe_devcoredump_snapshot *ss)
140 {
141 	int i;
142 
143 	kfree(ss->reason);
144 	ss->reason = NULL;
145 
146 	xe_guc_log_snapshot_free(ss->guc.log);
147 	ss->guc.log = NULL;
148 
149 	xe_guc_ct_snapshot_free(ss->guc.ct);
150 	ss->guc.ct = NULL;
151 
152 	xe_guc_capture_put_matched_nodes(&ss->gt->uc.guc);
153 	ss->matched_node = NULL;
154 
155 	xe_guc_exec_queue_snapshot_free(ss->ge);
156 	ss->ge = NULL;
157 
158 	xe_sched_job_snapshot_free(ss->job);
159 	ss->job = NULL;
160 
161 	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
162 		if (ss->hwe[i]) {
163 			xe_hw_engine_snapshot_free(ss->hwe[i]);
164 			ss->hwe[i] = NULL;
165 		}
166 
167 	xe_vm_snapshot_free(ss->vm);
168 	ss->vm = NULL;
169 }
170 
xe_devcoredump_read(char * buffer,loff_t offset,size_t count,void * data,size_t datalen)171 static ssize_t xe_devcoredump_read(char *buffer, loff_t offset,
172 				   size_t count, void *data, size_t datalen)
173 {
174 	struct xe_devcoredump *coredump = data;
175 	struct xe_devcoredump_snapshot *ss;
176 	ssize_t byte_copied;
177 
178 	if (!coredump)
179 		return -ENODEV;
180 
181 	ss = &coredump->snapshot;
182 
183 	/* Ensure delayed work is captured before continuing */
184 	flush_work(&ss->work);
185 
186 	mutex_lock(&coredump->lock);
187 
188 	if (!ss->read.buffer) {
189 		mutex_unlock(&coredump->lock);
190 		return -ENODEV;
191 	}
192 
193 	if (offset >= ss->read.size) {
194 		mutex_unlock(&coredump->lock);
195 		return 0;
196 	}
197 
198 	byte_copied = count < ss->read.size - offset ? count :
199 		ss->read.size - offset;
200 	memcpy(buffer, ss->read.buffer + offset, byte_copied);
201 
202 	mutex_unlock(&coredump->lock);
203 
204 	return byte_copied;
205 }
206 
xe_devcoredump_free(void * data)207 static void xe_devcoredump_free(void *data)
208 {
209 	struct xe_devcoredump *coredump = data;
210 
211 	/* Our device is gone. Nothing to do... */
212 	if (!data || !coredump_to_xe(coredump))
213 		return;
214 
215 	cancel_work_sync(&coredump->snapshot.work);
216 
217 	mutex_lock(&coredump->lock);
218 
219 	xe_devcoredump_snapshot_free(&coredump->snapshot);
220 	kvfree(coredump->snapshot.read.buffer);
221 
222 	/* To prevent stale data on next snapshot, clear everything */
223 	memset(&coredump->snapshot, 0, sizeof(coredump->snapshot));
224 	coredump->captured = false;
225 	drm_info(&coredump_to_xe(coredump)->drm,
226 		 "Xe device coredump has been deleted.\n");
227 
228 	mutex_unlock(&coredump->lock);
229 }
230 
xe_devcoredump_deferred_snap_work(struct work_struct * work)231 static void xe_devcoredump_deferred_snap_work(struct work_struct *work)
232 {
233 	struct xe_devcoredump_snapshot *ss = container_of(work, typeof(*ss), work);
234 	struct xe_devcoredump *coredump = container_of(ss, typeof(*coredump), snapshot);
235 	struct xe_device *xe = coredump_to_xe(coredump);
236 	unsigned int fw_ref;
237 
238 	/*
239 	 * NB: Despite passing a GFP_ flags parameter here, more allocations are done
240 	 * internally using GFP_KERNEL expliictly. Hence this call must be in the worker
241 	 * thread and not in the initial capture call.
242 	 */
243 	dev_coredumpm_timeout(gt_to_xe(ss->gt)->drm.dev, THIS_MODULE, coredump, 0, GFP_KERNEL,
244 			      xe_devcoredump_read, xe_devcoredump_free,
245 			      XE_COREDUMP_TIMEOUT_JIFFIES);
246 
247 	xe_pm_runtime_get(xe);
248 
249 	/* keep going if fw fails as we still want to save the memory and SW data */
250 	fw_ref = xe_force_wake_get(gt_to_fw(ss->gt), XE_FORCEWAKE_ALL);
251 	if (!xe_force_wake_ref_has_domain(fw_ref, XE_FORCEWAKE_ALL))
252 		xe_gt_info(ss->gt, "failed to get forcewake for coredump capture\n");
253 	xe_vm_snapshot_capture_delayed(ss->vm);
254 	xe_guc_exec_queue_snapshot_capture_delayed(ss->ge);
255 	xe_force_wake_put(gt_to_fw(ss->gt), fw_ref);
256 
257 	xe_pm_runtime_put(xe);
258 
259 	/* Calculate devcoredump size */
260 	ss->read.size = __xe_devcoredump_read(NULL, INT_MAX, coredump);
261 
262 	ss->read.buffer = kvmalloc(ss->read.size, GFP_USER);
263 	if (!ss->read.buffer)
264 		return;
265 
266 	__xe_devcoredump_read(ss->read.buffer, ss->read.size, coredump);
267 	xe_devcoredump_snapshot_free(ss);
268 }
269 
devcoredump_snapshot(struct xe_devcoredump * coredump,struct xe_exec_queue * q,struct xe_sched_job * job)270 static void devcoredump_snapshot(struct xe_devcoredump *coredump,
271 				 struct xe_exec_queue *q,
272 				 struct xe_sched_job *job)
273 {
274 	struct xe_devcoredump_snapshot *ss = &coredump->snapshot;
275 	struct xe_guc *guc = exec_queue_to_guc(q);
276 	u32 adj_logical_mask = q->logical_mask;
277 	u32 width_mask = (0x1 << q->width) - 1;
278 	const char *process_name = "no process";
279 
280 	unsigned int fw_ref;
281 	bool cookie;
282 	int i;
283 
284 	ss->snapshot_time = ktime_get_real();
285 	ss->boot_time = ktime_get_boottime();
286 
287 	if (q->vm && q->vm->xef) {
288 		process_name = q->vm->xef->process_name;
289 		ss->pid = q->vm->xef->pid;
290 	}
291 
292 	strscpy(ss->process_name, process_name);
293 
294 	ss->gt = q->gt;
295 	INIT_WORK(&ss->work, xe_devcoredump_deferred_snap_work);
296 
297 	cookie = dma_fence_begin_signalling();
298 	for (i = 0; q->width > 1 && i < XE_HW_ENGINE_MAX_INSTANCE;) {
299 		if (adj_logical_mask & BIT(i)) {
300 			adj_logical_mask |= width_mask << i;
301 			i += q->width;
302 		} else {
303 			++i;
304 		}
305 	}
306 
307 	/* keep going if fw fails as we still want to save the memory and SW data */
308 	fw_ref = xe_force_wake_get(gt_to_fw(q->gt), XE_FORCEWAKE_ALL);
309 
310 	ss->guc.log = xe_guc_log_snapshot_capture(&guc->log, true);
311 	ss->guc.ct = xe_guc_ct_snapshot_capture(&guc->ct);
312 	ss->ge = xe_guc_exec_queue_snapshot_capture(q);
313 	if (job)
314 		ss->job = xe_sched_job_snapshot_capture(job);
315 	ss->vm = xe_vm_snapshot_capture(q->vm);
316 
317 	xe_engine_snapshot_capture_for_queue(q);
318 
319 	queue_work(system_unbound_wq, &ss->work);
320 
321 	xe_force_wake_put(gt_to_fw(q->gt), fw_ref);
322 	dma_fence_end_signalling(cookie);
323 }
324 
325 /**
326  * xe_devcoredump - Take the required snapshots and initialize coredump device.
327  * @q: The faulty xe_exec_queue, where the issue was detected.
328  * @job: The faulty xe_sched_job, where the issue was detected.
329  * @fmt: Printf format + args to describe the reason for the core dump
330  *
331  * This function should be called at the crash time within the serialized
332  * gt_reset. It is skipped if we still have the core dump device available
333  * with the information of the 'first' snapshot.
334  */
335 __printf(3, 4)
xe_devcoredump(struct xe_exec_queue * q,struct xe_sched_job * job,const char * fmt,...)336 void xe_devcoredump(struct xe_exec_queue *q, struct xe_sched_job *job, const char *fmt, ...)
337 {
338 	struct xe_device *xe = gt_to_xe(q->gt);
339 	struct xe_devcoredump *coredump = &xe->devcoredump;
340 	va_list varg;
341 
342 	mutex_lock(&coredump->lock);
343 
344 	if (coredump->captured) {
345 		drm_dbg(&xe->drm, "Multiple hangs are occurring, but only the first snapshot was taken\n");
346 		mutex_unlock(&coredump->lock);
347 		return;
348 	}
349 
350 	coredump->captured = true;
351 
352 	va_start(varg, fmt);
353 	coredump->snapshot.reason = kvasprintf(GFP_ATOMIC, fmt, varg);
354 	va_end(varg);
355 
356 	devcoredump_snapshot(coredump, q, job);
357 
358 	drm_info(&xe->drm, "Xe device coredump has been created\n");
359 	drm_info(&xe->drm, "Check your /sys/class/drm/card%d/device/devcoredump/data\n",
360 		 xe->drm.primary->index);
361 
362 	mutex_unlock(&coredump->lock);
363 }
364 
xe_driver_devcoredump_fini(void * arg)365 static void xe_driver_devcoredump_fini(void *arg)
366 {
367 	struct drm_device *drm = arg;
368 
369 	dev_coredump_put(drm->dev);
370 }
371 
xe_devcoredump_init(struct xe_device * xe)372 int xe_devcoredump_init(struct xe_device *xe)
373 {
374 	int err;
375 
376 	err = drmm_mutex_init(&xe->drm, &xe->devcoredump.lock);
377 	if (err)
378 		return err;
379 
380 	if (IS_ENABLED(CONFIG_LOCKDEP)) {
381 		fs_reclaim_acquire(GFP_KERNEL);
382 		might_lock(&xe->devcoredump.lock);
383 		fs_reclaim_release(GFP_KERNEL);
384 	}
385 
386 	return devm_add_action_or_reset(xe->drm.dev, xe_driver_devcoredump_fini, &xe->drm);
387 }
388 
389 #endif
390 
391 /**
392  * xe_print_blob_ascii85 - print a BLOB to some useful location in ASCII85
393  *
394  * The output is split into multiple calls to drm_puts() because some print
395  * targets, e.g. dmesg, cannot handle arbitrarily long lines. These targets may
396  * add newlines, as is the case with dmesg: each drm_puts() call creates a
397  * separate line.
398  *
399  * There is also a scheduler yield call to prevent the 'task has been stuck for
400  * 120s' kernel hang check feature from firing when printing to a slow target
401  * such as dmesg over a serial port.
402  *
403  * @p: the printer object to output to
404  * @prefix: optional prefix to add to output string
405  * @suffix: optional suffix to add at the end. 0 disables it and is
406  *          not added to the output, which is useful when using multiple calls
407  *          to dump data to @p
408  * @blob: the Binary Large OBject to dump out
409  * @offset: offset in bytes to skip from the front of the BLOB, must be a multiple of sizeof(u32)
410  * @size: the size in bytes of the BLOB, must be a multiple of sizeof(u32)
411  */
xe_print_blob_ascii85(struct drm_printer * p,const char * prefix,char suffix,const void * blob,size_t offset,size_t size)412 void xe_print_blob_ascii85(struct drm_printer *p, const char *prefix, char suffix,
413 			   const void *blob, size_t offset, size_t size)
414 {
415 	const u32 *blob32 = (const u32 *)blob;
416 	char buff[ASCII85_BUFSZ], *line_buff;
417 	size_t line_pos = 0;
418 
419 #define DMESG_MAX_LINE_LEN	800
420 	/* Always leave space for the suffix char and the \0 */
421 #define MIN_SPACE		(ASCII85_BUFSZ + 2)	/* 85 + "<suffix>\0" */
422 
423 	if (size & 3)
424 		drm_printf(p, "Size not word aligned: %zu", size);
425 	if (offset & 3)
426 		drm_printf(p, "Offset not word aligned: %zu", size);
427 
428 	line_buff = kzalloc(DMESG_MAX_LINE_LEN, GFP_KERNEL);
429 	if (IS_ERR_OR_NULL(line_buff)) {
430 		drm_printf(p, "Failed to allocate line buffer: %pe", line_buff);
431 		return;
432 	}
433 
434 	blob32 += offset / sizeof(*blob32);
435 	size /= sizeof(*blob32);
436 
437 	if (prefix) {
438 		strscpy(line_buff, prefix, DMESG_MAX_LINE_LEN - MIN_SPACE - 2);
439 		line_pos = strlen(line_buff);
440 
441 		line_buff[line_pos++] = ':';
442 		line_buff[line_pos++] = ' ';
443 	}
444 
445 	while (size--) {
446 		u32 val = *(blob32++);
447 
448 		strscpy(line_buff + line_pos, ascii85_encode(val, buff),
449 			DMESG_MAX_LINE_LEN - line_pos);
450 		line_pos += strlen(line_buff + line_pos);
451 
452 		if ((line_pos + MIN_SPACE) >= DMESG_MAX_LINE_LEN) {
453 			line_buff[line_pos++] = 0;
454 
455 			drm_puts(p, line_buff);
456 
457 			line_pos = 0;
458 
459 			/* Prevent 'stuck thread' time out errors */
460 			cond_resched();
461 		}
462 	}
463 
464 	if (suffix)
465 		line_buff[line_pos++] = suffix;
466 
467 	if (line_pos) {
468 		line_buff[line_pos++] = 0;
469 		drm_puts(p, line_buff);
470 	}
471 
472 	kfree(line_buff);
473 
474 #undef MIN_SPACE
475 #undef DMESG_MAX_LINE_LEN
476 }
477