xref: /openbmc/linux/sound/soc/sof/debug.c (revision b830f94f)
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 	int err;
132 #endif
133 	size_t size;
134 	char *string;
135 	int ret;
136 
137 	string = kzalloc(count, GFP_KERNEL);
138 	if (!string)
139 		return -ENOMEM;
140 
141 	size = simple_write_to_buffer(string, count, ppos, buffer, count);
142 	ret = size;
143 
144 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
145 	/*
146 	 * write op is only supported for ipc_flood_count or
147 	 * ipc_flood_duration_ms debugfs entries atm.
148 	 * ipc_flood_count floods the DSP with the number of IPC's specified.
149 	 * ipc_duration_ms test floods the DSP for the time specified
150 	 * in the debugfs entry.
151 	 */
152 	if (strcmp(dfse->dfsentry->d_name.name, "ipc_flood_count") &&
153 	    strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms"))
154 		return -EINVAL;
155 
156 	if (!strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms"))
157 		flood_duration_test = true;
158 
159 	/* test completion criterion */
160 	if (flood_duration_test)
161 		ret = kstrtoul(string, 0, &ipc_duration_ms);
162 	else
163 		ret = kstrtoul(string, 0, &ipc_count);
164 	if (ret < 0)
165 		goto out;
166 
167 	/* limit max duration/ipc count for flood test */
168 	if (flood_duration_test) {
169 		if (!ipc_duration_ms) {
170 			ret = size;
171 			goto out;
172 		}
173 
174 		/* find the minimum. min() is not used to avoid warnings */
175 		if (ipc_duration_ms > MAX_IPC_FLOOD_DURATION_MS)
176 			ipc_duration_ms = MAX_IPC_FLOOD_DURATION_MS;
177 	} else {
178 		if (!ipc_count) {
179 			ret = size;
180 			goto out;
181 		}
182 
183 		/* find the minimum. min() is not used to avoid warnings */
184 		if (ipc_count > MAX_IPC_FLOOD_COUNT)
185 			ipc_count = MAX_IPC_FLOOD_COUNT;
186 	}
187 
188 	ret = pm_runtime_get_sync(sdev->dev);
189 	if (ret < 0) {
190 		dev_err_ratelimited(sdev->dev,
191 				    "error: debugfs write failed to resume %d\n",
192 				    ret);
193 		pm_runtime_put_noidle(sdev->dev);
194 		goto out;
195 	}
196 
197 	/* flood test */
198 	ret = sof_debug_ipc_flood_test(sdev, dfse, flood_duration_test,
199 				       ipc_duration_ms, ipc_count);
200 
201 	pm_runtime_mark_last_busy(sdev->dev);
202 	err = pm_runtime_put_autosuspend(sdev->dev);
203 	if (err < 0)
204 		dev_err_ratelimited(sdev->dev,
205 				    "error: debugfs write failed to idle %d\n",
206 				    err);
207 
208 	/* return size if test is successful */
209 	if (ret >= 0)
210 		ret = size;
211 out:
212 #endif
213 	kfree(string);
214 	return ret;
215 }
216 
217 static ssize_t sof_dfsentry_read(struct file *file, char __user *buffer,
218 				 size_t count, loff_t *ppos)
219 {
220 	struct snd_sof_dfsentry *dfse = file->private_data;
221 	struct snd_sof_dev *sdev = dfse->sdev;
222 	loff_t pos = *ppos;
223 	size_t size_ret;
224 	int skip = 0;
225 	int size;
226 	u8 *buf;
227 
228 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
229 	if ((!strcmp(dfse->dfsentry->d_name.name, "ipc_flood_count") ||
230 	     !strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms")) &&
231 	    dfse->cache_buf) {
232 		if (*ppos)
233 			return 0;
234 
235 		count = strlen(dfse->cache_buf);
236 		size_ret = copy_to_user(buffer, dfse->cache_buf, count);
237 		if (size_ret)
238 			return -EFAULT;
239 
240 		*ppos += count;
241 		return count;
242 	}
243 #endif
244 	size = dfse->size;
245 
246 	/* validate position & count */
247 	if (pos < 0)
248 		return -EINVAL;
249 	if (pos >= size || !count)
250 		return 0;
251 	/* find the minimum. min() is not used since it adds sparse warnings */
252 	if (count > size - pos)
253 		count = size - pos;
254 
255 	/* align io read start to u32 multiple */
256 	pos = ALIGN_DOWN(pos, 4);
257 
258 	/* intermediate buffer size must be u32 multiple */
259 	size = ALIGN(count, 4);
260 
261 	/* if start position is unaligned, read extra u32 */
262 	if (unlikely(pos != *ppos)) {
263 		skip = *ppos - pos;
264 		if (pos + size + 4 < dfse->size)
265 			size += 4;
266 	}
267 
268 	buf = kzalloc(size, GFP_KERNEL);
269 	if (!buf)
270 		return -ENOMEM;
271 
272 	if (dfse->type == SOF_DFSENTRY_TYPE_IOMEM) {
273 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE)
274 		/*
275 		 * If the DSP is active: copy from IO.
276 		 * If the DSP is suspended:
277 		 *	- Copy from IO if the memory is always accessible.
278 		 *	- Otherwise, copy from cached buffer.
279 		 */
280 		if (pm_runtime_active(sdev->dev) ||
281 		    dfse->access_type == SOF_DEBUGFS_ACCESS_ALWAYS) {
282 			memcpy_fromio(buf, dfse->io_mem + pos, size);
283 		} else {
284 			dev_info(sdev->dev,
285 				 "Copying cached debugfs data\n");
286 			memcpy(buf, dfse->cache_buf + pos, size);
287 		}
288 #else
289 		/* if the DSP is in D3 */
290 		if (!pm_runtime_active(sdev->dev) &&
291 		    dfse->access_type == SOF_DEBUGFS_ACCESS_D0_ONLY) {
292 			dev_err(sdev->dev,
293 				"error: debugfs entry %s cannot be read in DSP D3\n",
294 				dfse->dfsentry->d_name.name);
295 			kfree(buf);
296 			return -EINVAL;
297 		}
298 
299 		memcpy_fromio(buf, dfse->io_mem + pos, size);
300 #endif
301 	} else {
302 		memcpy(buf, ((u8 *)(dfse->buf) + pos), size);
303 	}
304 
305 	/* copy to userspace */
306 	size_ret = copy_to_user(buffer, buf + skip, count);
307 
308 	kfree(buf);
309 
310 	/* update count & position if copy succeeded */
311 	if (size_ret)
312 		return -EFAULT;
313 
314 	*ppos = pos + count;
315 
316 	return count;
317 }
318 
319 static const struct file_operations sof_dfs_fops = {
320 	.open = simple_open,
321 	.read = sof_dfsentry_read,
322 	.llseek = default_llseek,
323 	.write = sof_dfsentry_write,
324 };
325 
326 /* create FS entry for debug files that can expose DSP memories, registers */
327 int snd_sof_debugfs_io_item(struct snd_sof_dev *sdev,
328 			    void __iomem *base, size_t size,
329 			    const char *name,
330 			    enum sof_debugfs_access_type access_type)
331 {
332 	struct snd_sof_dfsentry *dfse;
333 
334 	if (!sdev)
335 		return -EINVAL;
336 
337 	dfse = devm_kzalloc(sdev->dev, sizeof(*dfse), GFP_KERNEL);
338 	if (!dfse)
339 		return -ENOMEM;
340 
341 	dfse->type = SOF_DFSENTRY_TYPE_IOMEM;
342 	dfse->io_mem = base;
343 	dfse->size = size;
344 	dfse->sdev = sdev;
345 	dfse->access_type = access_type;
346 
347 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE)
348 	/*
349 	 * allocate cache buffer that will be used to save the mem window
350 	 * contents prior to suspend
351 	 */
352 	if (access_type == SOF_DEBUGFS_ACCESS_D0_ONLY) {
353 		dfse->cache_buf = devm_kzalloc(sdev->dev, size, GFP_KERNEL);
354 		if (!dfse->cache_buf)
355 			return -ENOMEM;
356 	}
357 #endif
358 
359 	dfse->dfsentry = debugfs_create_file(name, 0444, sdev->debugfs_root,
360 					     dfse, &sof_dfs_fops);
361 	if (!dfse->dfsentry) {
362 		/* can't rely on debugfs, only log error and keep going */
363 		dev_err(sdev->dev, "error: cannot create debugfs entry %s\n",
364 			name);
365 	} else {
366 		/* add to dfsentry list */
367 		list_add(&dfse->list, &sdev->dfsentry_list);
368 
369 	}
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 	dfse->dfsentry = debugfs_create_file(name, mode, sdev->debugfs_root,
406 					     dfse, &sof_dfs_fops);
407 	if (!dfse->dfsentry) {
408 		/* can't rely on debugfs, only log error and keep going */
409 		dev_err(sdev->dev, "error: cannot create debugfs entry %s\n",
410 			name);
411 	} else {
412 		/* add to dfsentry list */
413 		list_add(&dfse->list, &sdev->dfsentry_list);
414 	}
415 
416 	return 0;
417 }
418 EXPORT_SYMBOL_GPL(snd_sof_debugfs_buf_item);
419 
420 int snd_sof_dbg_init(struct snd_sof_dev *sdev)
421 {
422 	const struct snd_sof_dsp_ops *ops = sof_ops(sdev);
423 	const struct snd_sof_debugfs_map *map;
424 	int i;
425 	int err;
426 
427 	/* use "sof" as top level debugFS dir */
428 	sdev->debugfs_root = debugfs_create_dir("sof", NULL);
429 	if (IS_ERR_OR_NULL(sdev->debugfs_root)) {
430 		dev_err(sdev->dev, "error: failed to create debugfs directory\n");
431 		return 0;
432 	}
433 
434 	/* init dfsentry list */
435 	INIT_LIST_HEAD(&sdev->dfsentry_list);
436 
437 	/* create debugFS files for platform specific MMIO/DSP memories */
438 	for (i = 0; i < ops->debug_map_count; i++) {
439 		map = &ops->debug_map[i];
440 
441 		err = snd_sof_debugfs_io_item(sdev, sdev->bar[map->bar] +
442 					      map->offset, map->size,
443 					      map->name, map->access_type);
444 		/* errors are only due to memory allocation, not debugfs */
445 		if (err < 0)
446 			return err;
447 	}
448 
449 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)
450 	/* create read-write ipc_flood_count debugfs entry */
451 	err = snd_sof_debugfs_buf_item(sdev, NULL, 0,
452 				       "ipc_flood_count", 0666);
453 
454 	/* errors are only due to memory allocation, not debugfs */
455 	if (err < 0)
456 		return err;
457 
458 	/* create read-write ipc_flood_duration_ms debugfs entry */
459 	err = snd_sof_debugfs_buf_item(sdev, NULL, 0,
460 				       "ipc_flood_duration_ms", 0666);
461 
462 	/* errors are only due to memory allocation, not debugfs */
463 	if (err < 0)
464 		return err;
465 #endif
466 
467 	return 0;
468 }
469 EXPORT_SYMBOL_GPL(snd_sof_dbg_init);
470 
471 void snd_sof_free_debug(struct snd_sof_dev *sdev)
472 {
473 	debugfs_remove_recursive(sdev->debugfs_root);
474 }
475 EXPORT_SYMBOL_GPL(snd_sof_free_debug);
476