xref: /linux/sound/soc/sof/debug.c (revision 4eb7ae7a301d3586c3351e81d5c3cfe2304a1a6a)
1 // SPDX-License-Identifier: (GPL-2.0 OR BSD-3-Clause)
2 //
3 // This file is provided under a dual BSD/GPLv2 license.  When using or
4 // redistributing this file, you may do so under either license.
5 //
6 // Copyright(c) 2018 Intel Corporation. All rights reserved.
7 //
8 // Author: Liam Girdwood <liam.r.girdwood@linux.intel.com>
9 //
10 // Generic debug routines used to export DSP MMIO and memories to userspace
11 // for firmware debugging.
12 //
13 
14 #include <linux/debugfs.h>
15 #include <linux/io.h>
16 #include <linux/pm_runtime.h>
17 #include "sof-priv.h"
18 #include "ops.h"
19 
20 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
21 #define MAX_IPC_FLOOD_DURATION_MS 1000
22 #define MAX_IPC_FLOOD_COUNT 10000
23 #define IPC_FLOOD_TEST_RESULT_LEN 512
24 
25 static int sof_debug_ipc_flood_test(struct snd_sof_dev *sdev,
26 				    struct snd_sof_dfsentry *dfse,
27 				    bool flood_duration_test,
28 				    unsigned long ipc_duration_ms,
29 				    unsigned long ipc_count)
30 {
31 	struct sof_ipc_cmd_hdr hdr;
32 	struct sof_ipc_reply reply;
33 	u64 min_response_time = U64_MAX;
34 	ktime_t start, end, test_end;
35 	u64 avg_response_time = 0;
36 	u64 max_response_time = 0;
37 	u64 ipc_response_time;
38 	int i = 0;
39 	int ret;
40 
41 	/* configure test IPC */
42 	hdr.cmd = SOF_IPC_GLB_TEST_MSG | SOF_IPC_TEST_IPC_FLOOD;
43 	hdr.size = sizeof(hdr);
44 
45 	/* set test end time for duration flood test */
46 	if (flood_duration_test)
47 		test_end = ktime_get_ns() + ipc_duration_ms * NSEC_PER_MSEC;
48 
49 	/* send test IPC's */
50 	while (1) {
51 		start = ktime_get();
52 		ret = sof_ipc_tx_message(sdev->ipc, hdr.cmd, &hdr, hdr.size,
53 					 &reply, sizeof(reply));
54 		end = ktime_get();
55 
56 		if (ret < 0)
57 			break;
58 
59 		/* compute min and max response times */
60 		ipc_response_time = ktime_to_ns(ktime_sub(end, start));
61 		min_response_time = min(min_response_time, ipc_response_time);
62 		max_response_time = max(max_response_time, ipc_response_time);
63 
64 		/* sum up response times */
65 		avg_response_time += ipc_response_time;
66 		i++;
67 
68 		/* test complete? */
69 		if (flood_duration_test) {
70 			if (ktime_to_ns(end) >= test_end)
71 				break;
72 		} else {
73 			if (i == ipc_count)
74 				break;
75 		}
76 	}
77 
78 	if (ret < 0)
79 		dev_err(sdev->dev,
80 			"error: ipc flood test failed at %d iterations\n", i);
81 
82 	/* return if the first IPC fails */
83 	if (!i)
84 		return ret;
85 
86 	/* compute average response time */
87 	do_div(avg_response_time, i);
88 
89 	/* clear previous test output */
90 	memset(dfse->cache_buf, 0, IPC_FLOOD_TEST_RESULT_LEN);
91 
92 	if (flood_duration_test) {
93 		dev_dbg(sdev->dev, "IPC Flood test duration: %lums\n",
94 			ipc_duration_ms);
95 		snprintf(dfse->cache_buf, IPC_FLOOD_TEST_RESULT_LEN,
96 			 "IPC Flood test duration: %lums\n", ipc_duration_ms);
97 	}
98 
99 	dev_dbg(sdev->dev,
100 		"IPC Flood count: %d, Avg response time: %lluns\n",
101 		i, avg_response_time);
102 	dev_dbg(sdev->dev, "Max response time: %lluns\n",
103 		max_response_time);
104 	dev_dbg(sdev->dev, "Min response time: %lluns\n",
105 		min_response_time);
106 
107 	/* format output string */
108 	snprintf(dfse->cache_buf + strlen(dfse->cache_buf),
109 		 IPC_FLOOD_TEST_RESULT_LEN - strlen(dfse->cache_buf),
110 		 "IPC Flood count: %d\nAvg response time: %lluns\n",
111 		 i, avg_response_time);
112 
113 	snprintf(dfse->cache_buf + strlen(dfse->cache_buf),
114 		 IPC_FLOOD_TEST_RESULT_LEN - strlen(dfse->cache_buf),
115 		 "Max response time: %lluns\nMin response time: %lluns\n",
116 		 max_response_time, min_response_time);
117 
118 	return ret;
119 }
120 #endif
121 
122 static ssize_t sof_dfsentry_write(struct file *file, const char __user *buffer,
123 				  size_t count, loff_t *ppos)
124 {
125 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
126 	struct snd_sof_dfsentry *dfse = file->private_data;
127 	struct snd_sof_dev *sdev = dfse->sdev;
128 	unsigned long ipc_duration_ms = 0;
129 	bool flood_duration_test = false;
130 	unsigned long ipc_count = 0;
131 	struct dentry *dentry;
132 	int err;
133 #endif
134 	size_t size;
135 	char *string;
136 	int ret;
137 
138 	string = kzalloc(count, GFP_KERNEL);
139 	if (!string)
140 		return -ENOMEM;
141 
142 	size = simple_write_to_buffer(string, count, ppos, buffer, count);
143 	ret = size;
144 
145 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
146 	/*
147 	 * write op is only supported for ipc_flood_count or
148 	 * ipc_flood_duration_ms debugfs entries atm.
149 	 * ipc_flood_count floods the DSP with the number of IPC's specified.
150 	 * ipc_duration_ms test floods the DSP for the time specified
151 	 * in the debugfs entry.
152 	 */
153 	dentry = file->f_path.dentry;
154 	if (strcmp(dentry->d_name.name, "ipc_flood_count") &&
155 	    strcmp(dentry->d_name.name, "ipc_flood_duration_ms")) {
156 		ret = -EINVAL;
157 		goto out;
158 	}
159 
160 	if (!strcmp(dentry->d_name.name, "ipc_flood_duration_ms"))
161 		flood_duration_test = true;
162 
163 	/* test completion criterion */
164 	if (flood_duration_test)
165 		ret = kstrtoul(string, 0, &ipc_duration_ms);
166 	else
167 		ret = kstrtoul(string, 0, &ipc_count);
168 	if (ret < 0)
169 		goto out;
170 
171 	/* limit max duration/ipc count for flood test */
172 	if (flood_duration_test) {
173 		if (!ipc_duration_ms) {
174 			ret = size;
175 			goto out;
176 		}
177 
178 		/* find the minimum. min() is not used to avoid warnings */
179 		if (ipc_duration_ms > MAX_IPC_FLOOD_DURATION_MS)
180 			ipc_duration_ms = MAX_IPC_FLOOD_DURATION_MS;
181 	} else {
182 		if (!ipc_count) {
183 			ret = size;
184 			goto out;
185 		}
186 
187 		/* find the minimum. min() is not used to avoid warnings */
188 		if (ipc_count > MAX_IPC_FLOOD_COUNT)
189 			ipc_count = MAX_IPC_FLOOD_COUNT;
190 	}
191 
192 	ret = pm_runtime_get_sync(sdev->dev);
193 	if (ret < 0) {
194 		dev_err_ratelimited(sdev->dev,
195 				    "error: debugfs write failed to resume %d\n",
196 				    ret);
197 		pm_runtime_put_noidle(sdev->dev);
198 		goto out;
199 	}
200 
201 	/* flood test */
202 	ret = sof_debug_ipc_flood_test(sdev, dfse, flood_duration_test,
203 				       ipc_duration_ms, ipc_count);
204 
205 	pm_runtime_mark_last_busy(sdev->dev);
206 	err = pm_runtime_put_autosuspend(sdev->dev);
207 	if (err < 0)
208 		dev_err_ratelimited(sdev->dev,
209 				    "error: debugfs write failed to idle %d\n",
210 				    err);
211 
212 	/* return size if test is successful */
213 	if (ret >= 0)
214 		ret = size;
215 out:
216 #endif
217 	kfree(string);
218 	return ret;
219 }
220 
221 static ssize_t sof_dfsentry_read(struct file *file, char __user *buffer,
222 				 size_t count, loff_t *ppos)
223 {
224 	struct snd_sof_dfsentry *dfse = file->private_data;
225 	struct snd_sof_dev *sdev = dfse->sdev;
226 	loff_t pos = *ppos;
227 	size_t size_ret;
228 	int skip = 0;
229 	int size;
230 	u8 *buf;
231 
232 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
233 	struct dentry *dentry;
234 
235 	dentry = file->f_path.dentry;
236 	if ((!strcmp(dentry->d_name.name, "ipc_flood_count") ||
237 	     !strcmp(dentry->d_name.name, "ipc_flood_duration_ms")) &&
238 	    dfse->cache_buf) {
239 		if (*ppos)
240 			return 0;
241 
242 		count = strlen(dfse->cache_buf);
243 		size_ret = copy_to_user(buffer, dfse->cache_buf, count);
244 		if (size_ret)
245 			return -EFAULT;
246 
247 		*ppos += count;
248 		return count;
249 	}
250 #endif
251 	size = dfse->size;
252 
253 	/* validate position & count */
254 	if (pos < 0)
255 		return -EINVAL;
256 	if (pos >= size || !count)
257 		return 0;
258 	/* find the minimum. min() is not used since it adds sparse warnings */
259 	if (count > size - pos)
260 		count = size - pos;
261 
262 	/* align io read start to u32 multiple */
263 	pos = ALIGN_DOWN(pos, 4);
264 
265 	/* intermediate buffer size must be u32 multiple */
266 	size = ALIGN(count, 4);
267 
268 	/* if start position is unaligned, read extra u32 */
269 	if (unlikely(pos != *ppos)) {
270 		skip = *ppos - pos;
271 		if (pos + size + 4 < dfse->size)
272 			size += 4;
273 	}
274 
275 	buf = kzalloc(size, GFP_KERNEL);
276 	if (!buf)
277 		return -ENOMEM;
278 
279 	if (dfse->type == SOF_DFSENTRY_TYPE_IOMEM) {
280 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE)
281 		/*
282 		 * If the DSP is active: copy from IO.
283 		 * If the DSP is suspended:
284 		 *	- Copy from IO if the memory is always accessible.
285 		 *	- Otherwise, copy from cached buffer.
286 		 */
287 		if (pm_runtime_active(sdev->dev) ||
288 		    dfse->access_type == SOF_DEBUGFS_ACCESS_ALWAYS) {
289 			memcpy_fromio(buf, dfse->io_mem + pos, size);
290 		} else {
291 			dev_info(sdev->dev,
292 				 "Copying cached debugfs data\n");
293 			memcpy(buf, dfse->cache_buf + pos, size);
294 		}
295 #else
296 		/* if the DSP is in D3 */
297 		if (!pm_runtime_active(sdev->dev) &&
298 		    dfse->access_type == SOF_DEBUGFS_ACCESS_D0_ONLY) {
299 			dev_err(sdev->dev,
300 				"error: debugfs entry cannot be read in DSP D3\n");
301 			kfree(buf);
302 			return -EINVAL;
303 		}
304 
305 		memcpy_fromio(buf, dfse->io_mem + pos, size);
306 #endif
307 	} else {
308 		memcpy(buf, ((u8 *)(dfse->buf) + pos), size);
309 	}
310 
311 	/* copy to userspace */
312 	size_ret = copy_to_user(buffer, buf + skip, count);
313 
314 	kfree(buf);
315 
316 	/* update count & position if copy succeeded */
317 	if (size_ret)
318 		return -EFAULT;
319 
320 	*ppos = pos + count;
321 
322 	return count;
323 }
324 
325 static const struct file_operations sof_dfs_fops = {
326 	.open = simple_open,
327 	.read = sof_dfsentry_read,
328 	.llseek = default_llseek,
329 	.write = sof_dfsentry_write,
330 };
331 
332 /* create FS entry for debug files that can expose DSP memories, registers */
333 int snd_sof_debugfs_io_item(struct snd_sof_dev *sdev,
334 			    void __iomem *base, size_t size,
335 			    const char *name,
336 			    enum sof_debugfs_access_type access_type)
337 {
338 	struct snd_sof_dfsentry *dfse;
339 
340 	if (!sdev)
341 		return -EINVAL;
342 
343 	dfse = devm_kzalloc(sdev->dev, sizeof(*dfse), GFP_KERNEL);
344 	if (!dfse)
345 		return -ENOMEM;
346 
347 	dfse->type = SOF_DFSENTRY_TYPE_IOMEM;
348 	dfse->io_mem = base;
349 	dfse->size = size;
350 	dfse->sdev = sdev;
351 	dfse->access_type = access_type;
352 
353 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE)
354 	/*
355 	 * allocate cache buffer that will be used to save the mem window
356 	 * contents prior to suspend
357 	 */
358 	if (access_type == SOF_DEBUGFS_ACCESS_D0_ONLY) {
359 		dfse->cache_buf = devm_kzalloc(sdev->dev, size, GFP_KERNEL);
360 		if (!dfse->cache_buf)
361 			return -ENOMEM;
362 	}
363 #endif
364 
365 	debugfs_create_file(name, 0444, sdev->debugfs_root, dfse,
366 			    &sof_dfs_fops);
367 
368 	/* add to dfsentry list */
369 	list_add(&dfse->list, &sdev->dfsentry_list);
370 
371 	return 0;
372 }
373 EXPORT_SYMBOL_GPL(snd_sof_debugfs_io_item);
374 
375 /* create FS entry for debug files to expose kernel memory */
376 int snd_sof_debugfs_buf_item(struct snd_sof_dev *sdev,
377 			     void *base, size_t size,
378 			     const char *name, mode_t mode)
379 {
380 	struct snd_sof_dfsentry *dfse;
381 
382 	if (!sdev)
383 		return -EINVAL;
384 
385 	dfse = devm_kzalloc(sdev->dev, sizeof(*dfse), GFP_KERNEL);
386 	if (!dfse)
387 		return -ENOMEM;
388 
389 	dfse->type = SOF_DFSENTRY_TYPE_BUF;
390 	dfse->buf = base;
391 	dfse->size = size;
392 	dfse->sdev = sdev;
393 
394 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
395 	/*
396 	 * cache_buf is unused for SOF_DFSENTRY_TYPE_BUF debugfs entries.
397 	 * So, use it to save the results of the last IPC flood test.
398 	 */
399 	dfse->cache_buf = devm_kzalloc(sdev->dev, IPC_FLOOD_TEST_RESULT_LEN,
400 				       GFP_KERNEL);
401 	if (!dfse->cache_buf)
402 		return -ENOMEM;
403 #endif
404 
405 	debugfs_create_file(name, mode, sdev->debugfs_root, dfse,
406 			    &sof_dfs_fops);
407 	/* add to dfsentry list */
408 	list_add(&dfse->list, &sdev->dfsentry_list);
409 
410 	return 0;
411 }
412 EXPORT_SYMBOL_GPL(snd_sof_debugfs_buf_item);
413 
414 int snd_sof_dbg_init(struct snd_sof_dev *sdev)
415 {
416 	const struct snd_sof_dsp_ops *ops = sof_ops(sdev);
417 	const struct snd_sof_debugfs_map *map;
418 	int i;
419 	int err;
420 
421 	/* use "sof" as top level debugFS dir */
422 	sdev->debugfs_root = debugfs_create_dir("sof", NULL);
423 
424 	/* init dfsentry list */
425 	INIT_LIST_HEAD(&sdev->dfsentry_list);
426 
427 	/* create debugFS files for platform specific MMIO/DSP memories */
428 	for (i = 0; i < ops->debug_map_count; i++) {
429 		map = &ops->debug_map[i];
430 
431 		err = snd_sof_debugfs_io_item(sdev, sdev->bar[map->bar] +
432 					      map->offset, map->size,
433 					      map->name, map->access_type);
434 		/* errors are only due to memory allocation, not debugfs */
435 		if (err < 0)
436 			return err;
437 	}
438 
439 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
440 	/* create read-write ipc_flood_count debugfs entry */
441 	err = snd_sof_debugfs_buf_item(sdev, NULL, 0,
442 				       "ipc_flood_count", 0666);
443 
444 	/* errors are only due to memory allocation, not debugfs */
445 	if (err < 0)
446 		return err;
447 
448 	/* create read-write ipc_flood_duration_ms debugfs entry */
449 	err = snd_sof_debugfs_buf_item(sdev, NULL, 0,
450 				       "ipc_flood_duration_ms", 0666);
451 
452 	/* errors are only due to memory allocation, not debugfs */
453 	if (err < 0)
454 		return err;
455 #endif
456 
457 	return 0;
458 }
459 EXPORT_SYMBOL_GPL(snd_sof_dbg_init);
460 
461 void snd_sof_free_debug(struct snd_sof_dev *sdev)
462 {
463 	debugfs_remove_recursive(sdev->debugfs_root);
464 }
465 EXPORT_SYMBOL_GPL(snd_sof_free_debug);
466 
467 void snd_sof_handle_fw_exception(struct snd_sof_dev *sdev)
468 {
469 	if (IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_RETAIN_DSP_CONTEXT) ||
470 	    (sof_core_debug & SOF_DBG_RETAIN_CTX)) {
471 		/* should we prevent DSP entering D3 ? */
472 		dev_info(sdev->dev, "info: preventing DSP entering D3 state to preserve context\n");
473 		pm_runtime_get_noresume(sdev->dev);
474 	}
475 
476 	/* dump vital information to the logs */
477 	snd_sof_dsp_dbg_dump(sdev, SOF_DBG_REGS | SOF_DBG_MBOX);
478 	snd_sof_ipc_dump(sdev);
479 	snd_sof_trace_notify_for_error(sdev);
480 }
481 EXPORT_SYMBOL(snd_sof_handle_fw_exception);
482