xe_devcoredump.c

  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
 73static struct xe_device *coredump_to_xe(const struct xe_devcoredump *coredump)
 74{
 75	return container_of(coredump, struct xe_device, devcoredump);
 76}
 77
 78static struct xe_guc *exec_queue_to_guc(struct xe_exec_queue *q)
 79{
 80	return &q->gt->uc.guc;
 81}
 82
 83static ssize_t __xe_devcoredump_read(char *buffer, ssize_t count,
 84				     ssize_t start,
 85				     struct xe_devcoredump *coredump)
 86{
 87	struct xe_device *xe;
 88	struct xe_devcoredump_snapshot *ss;
 89	struct drm_printer p;
 90	struct drm_print_iterator iter;
 91	struct timespec64 ts;
 92	int i;
 93
 94	xe = coredump_to_xe(coredump);
 95	ss = &coredump->snapshot;
 96
 97	iter.data = buffer;
 98	iter.start = start;
 99	iter.remain = count;
100
101	p = drm_coredump_printer(&iter);
102
103	drm_puts(&p, "**** Xe Device Coredump ****\n");
104	drm_printf(&p, "Reason: %s\n", ss->reason);
105	drm_puts(&p, "kernel: " UTS_RELEASE "\n");
106	drm_puts(&p, "module: " KBUILD_MODNAME "\n");
107
108	ts = ktime_to_timespec64(ss->snapshot_time);
109	drm_printf(&p, "Snapshot time: %ptSp\n", &ts);
110	ts = ktime_to_timespec64(ss->boot_time);
111	drm_printf(&p, "Uptime: %ptSp\n", &ts);
112	drm_printf(&p, "Process: %s [%d]\n", ss->process_name, ss->pid);
113	xe_device_snapshot_print(xe, &p);
114
115	drm_printf(&p, "\n**** GT #%d ****\n", ss->gt->info.id);
116	drm_printf(&p, "\tTile: %d\n", ss->gt->tile->id);
117
118	drm_puts(&p, "\n**** GuC Log ****\n");
119	xe_guc_log_snapshot_print(ss->guc.log, &p);
120	drm_puts(&p, "\n**** GuC CT ****\n");
121	xe_guc_ct_snapshot_print(ss->guc.ct, &p);
122
123	drm_puts(&p, "\n**** Contexts ****\n");
124	xe_guc_exec_queue_snapshot_print(ss->ge, &p);
125
126	drm_puts(&p, "\n**** Job ****\n");
127	xe_sched_job_snapshot_print(ss->job, &p);
128
129	drm_puts(&p, "\n**** HW Engines ****\n");
130	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
131		if (ss->hwe[i])
132			xe_engine_snapshot_print(ss->hwe[i], &p);
133
134	drm_puts(&p, "\n**** VM state ****\n");
135	xe_vm_snapshot_print(ss->vm, &p);
136
137	return count - iter.remain;
138}
139
140static void xe_devcoredump_snapshot_free(struct xe_devcoredump_snapshot *ss)
141{
142	int i;
143
144	kfree(ss->reason);
145	ss->reason = NULL;
146
147	xe_guc_log_snapshot_free(ss->guc.log);
148	ss->guc.log = NULL;
149
150	xe_guc_ct_snapshot_free(ss->guc.ct);
151	ss->guc.ct = NULL;
152
153	xe_guc_capture_put_matched_nodes(&ss->gt->uc.guc);
154	ss->matched_node = NULL;
155
156	xe_guc_exec_queue_snapshot_free(ss->ge);
157	ss->ge = NULL;
158
159	xe_sched_job_snapshot_free(ss->job);
160	ss->job = NULL;
161
162	for (i = 0; i < XE_NUM_HW_ENGINES; i++)
163		if (ss->hwe[i]) {
164			xe_hw_engine_snapshot_free(ss->hwe[i]);
165			ss->hwe[i] = NULL;
166		}
167
168	xe_vm_snapshot_free(ss->vm);
169	ss->vm = NULL;
170}
171
172#define XE_DEVCOREDUMP_CHUNK_MAX	(SZ_512M + SZ_1G)
173
174/**
175 * xe_devcoredump_read() - Read data from the Xe device coredump snapshot
176 * @buffer: Destination buffer to copy the coredump data into
177 * @offset: Offset in the coredump data to start reading from
178 * @count: Number of bytes to read
179 * @data: Pointer to the xe_devcoredump structure
180 * @datalen: Length of the data (unused)
181 *
182 * Reads a chunk of the coredump snapshot data into the provided buffer.
183 * If the devcoredump is smaller than 1.5 GB (XE_DEVCOREDUMP_CHUNK_MAX),
184 * it is read directly from a pre-written buffer. For larger devcoredumps,
185 * the pre-written buffer must be periodically repopulated from the snapshot
186 * state due to kmalloc size limitations.
187 *
188 * Return: Number of bytes copied on success, or a negative error code on failure.
189 */
190static ssize_t xe_devcoredump_read(char *buffer, loff_t offset,
191				   size_t count, void *data, size_t datalen)
192{
193	struct xe_devcoredump *coredump = data;
194	struct xe_devcoredump_snapshot *ss;
195	ssize_t byte_copied = 0;
196	u32 chunk_offset;
197	ssize_t new_chunk_position;
198	bool pm_needed = false;
199	int ret = 0;
200
201	if (!coredump)
202		return -ENODEV;
203
204	ss = &coredump->snapshot;
205
206	/* Ensure delayed work is captured before continuing */
207	flush_work(&ss->work);
208
209	pm_needed = ss->read.size > XE_DEVCOREDUMP_CHUNK_MAX;
210	if (pm_needed)
211		xe_pm_runtime_get(gt_to_xe(ss->gt));
212
213	mutex_lock(&coredump->lock);
214
215	if (!ss->read.buffer) {
216		ret = -ENODEV;
217		goto unlock;
218	}
219
220	if (offset >= ss->read.size)
221		goto unlock;
222
223	new_chunk_position = div_u64_rem(offset,
224					 XE_DEVCOREDUMP_CHUNK_MAX,
225					 &chunk_offset);
226
227	if (offset >= ss->read.chunk_position + XE_DEVCOREDUMP_CHUNK_MAX ||
228	    offset < ss->read.chunk_position) {
229		ss->read.chunk_position = new_chunk_position *
230			XE_DEVCOREDUMP_CHUNK_MAX;
231
232		__xe_devcoredump_read(ss->read.buffer,
233				      XE_DEVCOREDUMP_CHUNK_MAX,
234				      ss->read.chunk_position, coredump);
235	}
236
237	byte_copied = count < ss->read.size - offset ? count :
238		ss->read.size - offset;
239	memcpy(buffer, ss->read.buffer + chunk_offset, byte_copied);
240
241unlock:
242	mutex_unlock(&coredump->lock);
243
244	if (pm_needed)
245		xe_pm_runtime_put(gt_to_xe(ss->gt));
246
247	return byte_copied ? byte_copied : ret;
248}
249
250static void xe_devcoredump_free(void *data)
251{
252	struct xe_devcoredump *coredump = data;
253
254	/* Our device is gone. Nothing to do... */
255	if (!data || !coredump_to_xe(coredump))
256		return;
257
258	cancel_work_sync(&coredump->snapshot.work);
259
260	mutex_lock(&coredump->lock);
261
262	xe_devcoredump_snapshot_free(&coredump->snapshot);
263	kvfree(coredump->snapshot.read.buffer);
264
265	/* To prevent stale data on next snapshot, clear everything */
266	memset(&coredump->snapshot, 0, sizeof(coredump->snapshot));
267	coredump->captured = false;
268	drm_info(&coredump_to_xe(coredump)->drm,
269		 "Xe device coredump has been deleted.\n");
270
271	mutex_unlock(&coredump->lock);
272}
273
274static void xe_devcoredump_deferred_snap_work(struct work_struct *work)
275{
276	struct xe_devcoredump_snapshot *ss = container_of(work, typeof(*ss), work);
277	struct xe_devcoredump *coredump = container_of(ss, typeof(*coredump), snapshot);
278	struct xe_device *xe = coredump_to_xe(coredump);
279	unsigned int fw_ref;
280
281	/*
282	 * NB: Despite passing a GFP_ flags parameter here, more allocations are done
283	 * internally using GFP_KERNEL explicitly. Hence this call must be in the worker
284	 * thread and not in the initial capture call.
285	 */
286	dev_coredumpm_timeout(gt_to_xe(ss->gt)->drm.dev, THIS_MODULE, coredump, 0, GFP_KERNEL,
287			      xe_devcoredump_read, xe_devcoredump_free,
288			      XE_COREDUMP_TIMEOUT_JIFFIES);
289
290	xe_pm_runtime_get(xe);
291
292	/* keep going if fw fails as we still want to save the memory and SW data */
293	fw_ref = xe_force_wake_get(gt_to_fw(ss->gt), XE_FORCEWAKE_ALL);
294	if (!xe_force_wake_ref_has_domain(fw_ref, XE_FORCEWAKE_ALL))
295		xe_gt_info(ss->gt, "failed to get forcewake for coredump capture\n");
296	xe_vm_snapshot_capture_delayed(ss->vm);
297	xe_guc_exec_queue_snapshot_capture_delayed(ss->ge);
298	xe_force_wake_put(gt_to_fw(ss->gt), fw_ref);
299
300	ss->read.chunk_position = 0;
301
302	/* Calculate devcoredump size */
303	ss->read.size = __xe_devcoredump_read(NULL, LONG_MAX, 0, coredump);
304
305	if (ss->read.size > XE_DEVCOREDUMP_CHUNK_MAX) {
306		ss->read.buffer = kvmalloc(XE_DEVCOREDUMP_CHUNK_MAX,
307					   GFP_USER);
308		if (!ss->read.buffer)
309			goto put_pm;
310
311		__xe_devcoredump_read(ss->read.buffer,
312				      XE_DEVCOREDUMP_CHUNK_MAX,
313				      0, coredump);
314	} else {
315		ss->read.buffer = kvmalloc(ss->read.size, GFP_USER);
316		if (!ss->read.buffer)
317			goto put_pm;
318
319		__xe_devcoredump_read(ss->read.buffer, ss->read.size, 0,
320				      coredump);
321		xe_devcoredump_snapshot_free(ss);
322	}
323
324put_pm:
325	xe_pm_runtime_put(xe);
326}
327
328static void devcoredump_snapshot(struct xe_devcoredump *coredump,
329				 struct xe_exec_queue *q,
330				 struct xe_sched_job *job)
331{
332	struct xe_devcoredump_snapshot *ss = &coredump->snapshot;
333	struct xe_guc *guc = exec_queue_to_guc(q);
334	const char *process_name = "no process";
335	unsigned int fw_ref;
336	bool cookie;
337
338	ss->snapshot_time = ktime_get_real();
339	ss->boot_time = ktime_get_boottime();
340
341	if (q->vm && q->vm->xef) {
342		process_name = q->vm->xef->process_name;
343		ss->pid = q->vm->xef->pid;
344	}
345
346	strscpy(ss->process_name, process_name);
347
348	ss->gt = q->gt;
349	INIT_WORK(&ss->work, xe_devcoredump_deferred_snap_work);
350
351	cookie = dma_fence_begin_signalling();
352
353	/* keep going if fw fails as we still want to save the memory and SW data */
354	fw_ref = xe_force_wake_get(gt_to_fw(q->gt), XE_FORCEWAKE_ALL);
355
356	ss->guc.log = xe_guc_log_snapshot_capture(&guc->log, true);
357	ss->guc.ct = xe_guc_ct_snapshot_capture(&guc->ct);
358	ss->ge = xe_guc_exec_queue_snapshot_capture(q);
359	if (job)
360		ss->job = xe_sched_job_snapshot_capture(job);
361	ss->vm = xe_vm_snapshot_capture(q->vm);
362
363	xe_engine_snapshot_capture_for_queue(q);
364
365	queue_work(system_unbound_wq, &ss->work);
366
367	xe_force_wake_put(gt_to_fw(q->gt), fw_ref);
368	dma_fence_end_signalling(cookie);
369}
370
371/**
372 * xe_devcoredump - Take the required snapshots and initialize coredump device.
373 * @q: The faulty xe_exec_queue, where the issue was detected.
374 * @job: The faulty xe_sched_job, where the issue was detected.
375 * @fmt: Printf format + args to describe the reason for the core dump
376 *
377 * This function should be called at the crash time within the serialized
378 * gt_reset. It is skipped if we still have the core dump device available
379 * with the information of the 'first' snapshot.
380 */
381__printf(3, 4)
382void xe_devcoredump(struct xe_exec_queue *q, struct xe_sched_job *job, const char *fmt, ...)
383{
384	struct xe_device *xe = gt_to_xe(q->gt);
385	struct xe_devcoredump *coredump = &xe->devcoredump;
386	va_list varg;
387
388	mutex_lock(&coredump->lock);
389
390	if (coredump->captured) {
391		drm_dbg(&xe->drm, "Multiple hangs are occurring, but only the first snapshot was taken\n");
392		mutex_unlock(&coredump->lock);
393		return;
394	}
395
396	coredump->captured = true;
397
398	va_start(varg, fmt);
399	coredump->snapshot.reason = kvasprintf(GFP_ATOMIC, fmt, varg);
400	va_end(varg);
401
402	devcoredump_snapshot(coredump, q, job);
403
404	drm_info(&xe->drm, "Xe device coredump has been created\n");
405	drm_info(&xe->drm, "Check your /sys/class/drm/card%d/device/devcoredump/data\n",
406		 xe->drm.primary->index);
407
408	mutex_unlock(&coredump->lock);
409}
410
411static void xe_driver_devcoredump_fini(void *arg)
412{
413	struct drm_device *drm = arg;
414
415	dev_coredump_put(drm->dev);
416}
417
418int xe_devcoredump_init(struct xe_device *xe)
419{
420	int err;
421
422	err = drmm_mutex_init(&xe->drm, &xe->devcoredump.lock);
423	if (err)
424		return err;
425
426	if (IS_ENABLED(CONFIG_LOCKDEP)) {
427		fs_reclaim_acquire(GFP_KERNEL);
428		might_lock(&xe->devcoredump.lock);
429		fs_reclaim_release(GFP_KERNEL);
430	}
431
432	return devm_add_action_or_reset(xe->drm.dev, xe_driver_devcoredump_fini, &xe->drm);
433}
434
435#endif
436
437/**
438 * xe_print_blob_ascii85 - print a BLOB to some useful location in ASCII85
439 *
440 * The output is split into multiple calls to drm_puts() because some print
441 * targets, e.g. dmesg, cannot handle arbitrarily long lines. These targets may
442 * add newlines, as is the case with dmesg: each drm_puts() call creates a
443 * separate line.
444 *
445 * There is also a scheduler yield call to prevent the 'task has been stuck for
446 * 120s' kernel hang check feature from firing when printing to a slow target
447 * such as dmesg over a serial port.
448 *
449 * @p: the printer object to output to
450 * @prefix: optional prefix to add to output string
451 * @suffix: optional suffix to add at the end. 0 disables it and is
452 *          not added to the output, which is useful when using multiple calls
453 *          to dump data to @p
454 * @blob: the Binary Large OBject to dump out
455 * @offset: offset in bytes to skip from the front of the BLOB, must be a multiple of sizeof(u32)
456 * @size: the size in bytes of the BLOB, must be a multiple of sizeof(u32)
457 */
458void xe_print_blob_ascii85(struct drm_printer *p, const char *prefix, char suffix,
459			   const void *blob, size_t offset, size_t size)
460{
461	const u32 *blob32 = (const u32 *)blob;
462	char buff[ASCII85_BUFSZ], *line_buff;
463	size_t line_pos = 0;
464
465#define DMESG_MAX_LINE_LEN	800
466	/* Always leave space for the suffix char and the \0 */
467#define MIN_SPACE		(ASCII85_BUFSZ + 2)	/* 85 + "<suffix>\0" */
468
469	if (size & 3)
470		drm_printf(p, "Size not word aligned: %zu", size);
471	if (offset & 3)
472		drm_printf(p, "Offset not word aligned: %zu", offset);
473
474	line_buff = kzalloc(DMESG_MAX_LINE_LEN, GFP_ATOMIC);
475	if (!line_buff) {
476		drm_printf(p, "Failed to allocate line buffer\n");
477		return;
478	}
479
480	blob32 += offset / sizeof(*blob32);
481	size /= sizeof(*blob32);
482
483	if (prefix) {
484		strscpy(line_buff, prefix, DMESG_MAX_LINE_LEN - MIN_SPACE - 2);
485		line_pos = strlen(line_buff);
486
487		line_buff[line_pos++] = ':';
488		line_buff[line_pos++] = ' ';
489	}
490
491	while (size--) {
492		u32 val = *(blob32++);
493
494		strscpy(line_buff + line_pos, ascii85_encode(val, buff),
495			DMESG_MAX_LINE_LEN - line_pos);
496		line_pos += strlen(line_buff + line_pos);
497
498		if ((line_pos + MIN_SPACE) >= DMESG_MAX_LINE_LEN) {
499			line_buff[line_pos++] = 0;
500
501			drm_puts(p, line_buff);
502
503			line_pos = 0;
504
505			/* Prevent 'stuck thread' time out errors */
506			cond_resched();
507		}
508	}
509
510	if (suffix)
511		line_buff[line_pos++] = suffix;
512
513	if (line_pos) {
514		line_buff[line_pos++] = 0;
515		drm_puts(p, line_buff);
516	}
517
518	kfree(line_buff);
519
520#undef MIN_SPACE
521#undef DMESG_MAX_LINE_LEN
522}