xref: /openbmc/linux/sound/soc/sof/trace.c (revision c94b731d)
1 // SPDX-License-Identifier: (GPL-2.0-only 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 
11 #include <linux/debugfs.h>
12 #include <linux/sched/signal.h>
13 #include "sof-priv.h"
14 #include "ops.h"
15 
16 #define TRACE_FILTER_ELEMENTS_PER_ENTRY 4
17 #define TRACE_FILTER_MAX_CONFIG_STRING_LENGTH 1024
18 
19 static int trace_filter_append_elem(struct snd_sof_dev *sdev, uint32_t key, uint32_t value,
20 				    struct sof_ipc_trace_filter_elem *elem_list,
21 				    int capacity, int *counter)
22 {
23 	if (*counter >= capacity)
24 		return -ENOMEM;
25 
26 	elem_list[*counter].key = key;
27 	elem_list[*counter].value = value;
28 	++*counter;
29 
30 	return 0;
31 }
32 
33 static int trace_filter_parse_entry(struct snd_sof_dev *sdev, const char *line,
34 				    struct sof_ipc_trace_filter_elem *elem,
35 				    int capacity, int *counter)
36 {
37 	int len = strlen(line);
38 	int cnt = *counter;
39 	uint32_t uuid_id;
40 	int log_level;
41 	int pipe_id;
42 	int comp_id;
43 	int read;
44 	int ret;
45 
46 	/* ignore empty content */
47 	ret = sscanf(line, " %n", &read);
48 	if (!ret && read == len)
49 		return len;
50 
51 	ret = sscanf(line, " %d %x %d %d %n", &log_level, &uuid_id, &pipe_id, &comp_id, &read);
52 	if (ret != TRACE_FILTER_ELEMENTS_PER_ENTRY || read != len) {
53 		dev_err(sdev->dev, "error: invalid trace filter entry '%s'\n", line);
54 		return -EINVAL;
55 	}
56 
57 	if (uuid_id > 0) {
58 		ret = trace_filter_append_elem(sdev, SOF_IPC_TRACE_FILTER_ELEM_BY_UUID,
59 					       uuid_id, elem, capacity, &cnt);
60 		if (ret)
61 			return ret;
62 	}
63 	if (pipe_id >= 0) {
64 		ret = trace_filter_append_elem(sdev, SOF_IPC_TRACE_FILTER_ELEM_BY_PIPE,
65 					       pipe_id, elem, capacity, &cnt);
66 		if (ret)
67 			return ret;
68 	}
69 	if (comp_id >= 0) {
70 		ret = trace_filter_append_elem(sdev, SOF_IPC_TRACE_FILTER_ELEM_BY_COMP,
71 					       comp_id, elem, capacity, &cnt);
72 		if (ret)
73 			return ret;
74 	}
75 
76 	ret = trace_filter_append_elem(sdev, SOF_IPC_TRACE_FILTER_ELEM_SET_LEVEL |
77 				       SOF_IPC_TRACE_FILTER_ELEM_FIN,
78 				       log_level, elem, capacity, &cnt);
79 	if (ret)
80 		return ret;
81 
82 	/* update counter only when parsing whole entry passed */
83 	*counter = cnt;
84 
85 	return len;
86 }
87 
88 static int trace_filter_parse(struct snd_sof_dev *sdev, char *string,
89 			      int *out_elem_cnt,
90 			      struct sof_ipc_trace_filter_elem **out)
91 {
92 	static const char entry_delimiter[] = ";";
93 	char *entry = string;
94 	int capacity = 0;
95 	int entry_len;
96 	int cnt = 0;
97 
98 	/*
99 	 * Each entry contains at least 1, up to TRACE_FILTER_ELEMENTS_PER_ENTRY
100 	 * IPC elements, depending on content. Calculate IPC elements capacity
101 	 * for the input string where each element is set.
102 	 */
103 	while (entry) {
104 		capacity += TRACE_FILTER_ELEMENTS_PER_ENTRY;
105 		entry = strchr(entry + 1, entry_delimiter[0]);
106 	}
107 	*out = kmalloc(capacity * sizeof(**out), GFP_KERNEL);
108 	if (!*out)
109 		return -ENOMEM;
110 
111 	/* split input string by ';', and parse each entry separately in trace_filter_parse_entry */
112 	while ((entry = strsep(&string, entry_delimiter))) {
113 		entry_len = trace_filter_parse_entry(sdev, entry, *out, capacity, &cnt);
114 		if (entry_len < 0) {
115 			dev_err(sdev->dev, "error: %s failed for '%s', %d\n", __func__, entry,
116 				entry_len);
117 			return -EINVAL;
118 		}
119 	}
120 
121 	*out_elem_cnt = cnt;
122 
123 	return 0;
124 }
125 
126 static int sof_ipc_trace_update_filter(struct snd_sof_dev *sdev, int num_elems,
127 				       struct sof_ipc_trace_filter_elem *elems)
128 {
129 	struct sof_ipc_trace_filter *msg;
130 	struct sof_ipc_reply reply;
131 	size_t size;
132 	int ret;
133 
134 	size = struct_size(msg, elems, num_elems);
135 	if (size > SOF_IPC_MSG_MAX_SIZE)
136 		return -EINVAL;
137 
138 	msg = kmalloc(size, GFP_KERNEL);
139 	if (!msg)
140 		return -ENOMEM;
141 
142 	msg->hdr.size = size;
143 	msg->hdr.cmd = SOF_IPC_GLB_TRACE_MSG | SOF_IPC_TRACE_FILTER_UPDATE;
144 	msg->elem_cnt = num_elems;
145 	memcpy(&msg->elems[0], elems, num_elems * sizeof(*elems));
146 
147 	ret = pm_runtime_get_sync(sdev->dev);
148 	if (ret < 0 && ret != -EACCES) {
149 		pm_runtime_put_noidle(sdev->dev);
150 		dev_err(sdev->dev, "error: enabling device failed: %d\n", ret);
151 		goto error;
152 	}
153 	ret = sof_ipc_tx_message(sdev->ipc, msg->hdr.cmd, msg, msg->hdr.size,
154 				 &reply, sizeof(reply));
155 	pm_runtime_mark_last_busy(sdev->dev);
156 	pm_runtime_put_autosuspend(sdev->dev);
157 
158 error:
159 	kfree(msg);
160 	return ret ? ret : reply.error;
161 }
162 
163 static ssize_t sof_dfsentry_trace_filter_write(struct file *file, const char __user *from,
164 					       size_t count, loff_t *ppos)
165 {
166 	struct snd_sof_dfsentry *dfse = file->private_data;
167 	struct sof_ipc_trace_filter_elem *elems = NULL;
168 	struct snd_sof_dev *sdev = dfse->sdev;
169 	loff_t pos = 0;
170 	int num_elems;
171 	char *string;
172 	int ret;
173 
174 	if (count > TRACE_FILTER_MAX_CONFIG_STRING_LENGTH) {
175 		dev_err(sdev->dev, "%s too long input, %zu > %d\n", __func__, count,
176 			TRACE_FILTER_MAX_CONFIG_STRING_LENGTH);
177 		return -EINVAL;
178 	}
179 
180 	string = kmalloc(count + 1, GFP_KERNEL);
181 	if (!string)
182 		return -ENOMEM;
183 
184 	/* assert null termination */
185 	string[count] = 0;
186 	ret = simple_write_to_buffer(string, count, &pos, from, count);
187 	if (ret < 0)
188 		goto error;
189 
190 	ret = trace_filter_parse(sdev, string, &num_elems, &elems);
191 	if (ret < 0) {
192 		dev_err(sdev->dev, "error: fail in trace_filter_parse, %d\n", ret);
193 		goto error;
194 	}
195 
196 	if (num_elems) {
197 		ret = sof_ipc_trace_update_filter(sdev, num_elems, elems);
198 		if (ret < 0) {
199 			dev_err(sdev->dev, "error: fail in sof_ipc_trace_update_filter %d\n", ret);
200 			goto error;
201 		}
202 	}
203 	ret = count;
204 error:
205 	kfree(string);
206 	kfree(elems);
207 	return ret;
208 }
209 
210 static const struct file_operations sof_dfs_trace_filter_fops = {
211 	.open = simple_open,
212 	.write = sof_dfsentry_trace_filter_write,
213 	.llseek = default_llseek,
214 };
215 
216 static int trace_debugfs_filter_create(struct snd_sof_dev *sdev)
217 {
218 	struct snd_sof_dfsentry *dfse;
219 
220 	dfse = devm_kzalloc(sdev->dev, sizeof(*dfse), GFP_KERNEL);
221 	if (!dfse)
222 		return -ENOMEM;
223 
224 	dfse->sdev = sdev;
225 	dfse->type = SOF_DFSENTRY_TYPE_BUF;
226 
227 	debugfs_create_file("filter", 0200, sdev->debugfs_root, dfse,
228 			    &sof_dfs_trace_filter_fops);
229 	/* add to dfsentry list */
230 	list_add(&dfse->list, &sdev->dfsentry_list);
231 
232 	return 0;
233 }
234 
235 static size_t sof_trace_avail(struct snd_sof_dev *sdev,
236 			      loff_t pos, size_t buffer_size)
237 {
238 	loff_t host_offset = READ_ONCE(sdev->host_offset);
239 
240 	/*
241 	 * If host offset is less than local pos, it means write pointer of
242 	 * host DMA buffer has been wrapped. We should output the trace data
243 	 * at the end of host DMA buffer at first.
244 	 */
245 	if (host_offset < pos)
246 		return buffer_size - pos;
247 
248 	/* If there is available trace data now, it is unnecessary to wait. */
249 	if (host_offset > pos)
250 		return host_offset - pos;
251 
252 	return 0;
253 }
254 
255 static size_t sof_wait_trace_avail(struct snd_sof_dev *sdev,
256 				   loff_t pos, size_t buffer_size)
257 {
258 	wait_queue_entry_t wait;
259 	size_t ret = sof_trace_avail(sdev, pos, buffer_size);
260 
261 	/* data immediately available */
262 	if (ret)
263 		return ret;
264 
265 	if (!sdev->dtrace_is_enabled && sdev->dtrace_draining) {
266 		/*
267 		 * tracing has ended and all traces have been
268 		 * read by client, return EOF
269 		 */
270 		sdev->dtrace_draining = false;
271 		return 0;
272 	}
273 
274 	/* wait for available trace data from FW */
275 	init_waitqueue_entry(&wait, current);
276 	set_current_state(TASK_INTERRUPTIBLE);
277 	add_wait_queue(&sdev->trace_sleep, &wait);
278 
279 	if (!signal_pending(current)) {
280 		/* set timeout to max value, no error code */
281 		schedule_timeout(MAX_SCHEDULE_TIMEOUT);
282 	}
283 	remove_wait_queue(&sdev->trace_sleep, &wait);
284 
285 	return sof_trace_avail(sdev, pos, buffer_size);
286 }
287 
288 static ssize_t sof_dfsentry_trace_read(struct file *file, char __user *buffer,
289 				       size_t count, loff_t *ppos)
290 {
291 	struct snd_sof_dfsentry *dfse = file->private_data;
292 	struct snd_sof_dev *sdev = dfse->sdev;
293 	unsigned long rem;
294 	loff_t lpos = *ppos;
295 	size_t avail, buffer_size = dfse->size;
296 	u64 lpos_64;
297 
298 	/* make sure we know about any failures on the DSP side */
299 	sdev->dtrace_error = false;
300 
301 	/* check pos and count */
302 	if (lpos < 0)
303 		return -EINVAL;
304 	if (!count)
305 		return 0;
306 
307 	/* check for buffer wrap and count overflow */
308 	lpos_64 = lpos;
309 	lpos = do_div(lpos_64, buffer_size);
310 
311 	if (count > buffer_size - lpos) /* min() not used to avoid sparse warnings */
312 		count = buffer_size - lpos;
313 
314 	/* get available count based on current host offset */
315 	avail = sof_wait_trace_avail(sdev, lpos, buffer_size);
316 	if (sdev->dtrace_error) {
317 		dev_err(sdev->dev, "error: trace IO error\n");
318 		return -EIO;
319 	}
320 
321 	/* make sure count is <= avail */
322 	count = avail > count ? count : avail;
323 
324 	/* copy available trace data to debugfs */
325 	rem = copy_to_user(buffer, ((u8 *)(dfse->buf) + lpos), count);
326 	if (rem)
327 		return -EFAULT;
328 
329 	*ppos += count;
330 
331 	/* move debugfs reading position */
332 	return count;
333 }
334 
335 static int sof_dfsentry_trace_release(struct inode *inode, struct file *file)
336 {
337 	struct snd_sof_dfsentry *dfse = inode->i_private;
338 	struct snd_sof_dev *sdev = dfse->sdev;
339 
340 	/* avoid duplicate traces at next open */
341 	if (!sdev->dtrace_is_enabled)
342 		sdev->host_offset = 0;
343 
344 	return 0;
345 }
346 
347 static const struct file_operations sof_dfs_trace_fops = {
348 	.open = simple_open,
349 	.read = sof_dfsentry_trace_read,
350 	.llseek = default_llseek,
351 	.release = sof_dfsentry_trace_release,
352 };
353 
354 static int trace_debugfs_create(struct snd_sof_dev *sdev)
355 {
356 	struct snd_sof_dfsentry *dfse;
357 	int ret;
358 
359 	if (!sdev)
360 		return -EINVAL;
361 
362 	ret = trace_debugfs_filter_create(sdev);
363 	if (ret < 0)
364 		dev_err(sdev->dev, "error: fail in %s, %d", __func__, ret);
365 
366 	dfse = devm_kzalloc(sdev->dev, sizeof(*dfse), GFP_KERNEL);
367 	if (!dfse)
368 		return -ENOMEM;
369 
370 	dfse->type = SOF_DFSENTRY_TYPE_BUF;
371 	dfse->buf = sdev->dmatb.area;
372 	dfse->size = sdev->dmatb.bytes;
373 	dfse->sdev = sdev;
374 
375 	debugfs_create_file("trace", 0444, sdev->debugfs_root, dfse,
376 			    &sof_dfs_trace_fops);
377 
378 	return 0;
379 }
380 
381 int snd_sof_init_trace_ipc(struct snd_sof_dev *sdev)
382 {
383 	struct sof_ipc_fw_ready *ready = &sdev->fw_ready;
384 	struct sof_ipc_fw_version *v = &ready->version;
385 	struct sof_ipc_dma_trace_params_ext params;
386 	struct sof_ipc_reply ipc_reply;
387 	int ret;
388 
389 	if (!sdev->dtrace_is_supported)
390 		return 0;
391 
392 	if (sdev->dtrace_is_enabled || !sdev->dma_trace_pages)
393 		return -EINVAL;
394 
395 	/* set IPC parameters */
396 	params.hdr.cmd = SOF_IPC_GLB_TRACE_MSG;
397 	/* PARAMS_EXT is only supported from ABI 3.7.0 onwards */
398 	if (v->abi_version >= SOF_ABI_VER(3, 7, 0)) {
399 		params.hdr.size = sizeof(struct sof_ipc_dma_trace_params_ext);
400 		params.hdr.cmd |= SOF_IPC_TRACE_DMA_PARAMS_EXT;
401 		params.timestamp_ns = ktime_get(); /* in nanosecond */
402 	} else {
403 		params.hdr.size = sizeof(struct sof_ipc_dma_trace_params);
404 		params.hdr.cmd |= SOF_IPC_TRACE_DMA_PARAMS;
405 	}
406 	params.buffer.phy_addr = sdev->dmatp.addr;
407 	params.buffer.size = sdev->dmatb.bytes;
408 	params.buffer.pages = sdev->dma_trace_pages;
409 	params.stream_tag = 0;
410 
411 	sdev->host_offset = 0;
412 	sdev->dtrace_draining = false;
413 
414 	ret = snd_sof_dma_trace_init(sdev, &params.stream_tag);
415 	if (ret < 0) {
416 		dev_err(sdev->dev,
417 			"error: fail in snd_sof_dma_trace_init %d\n", ret);
418 		return ret;
419 	}
420 	dev_dbg(sdev->dev, "%s: stream_tag: %d\n", __func__, params.stream_tag);
421 
422 	/* send IPC to the DSP */
423 	ret = sof_ipc_tx_message(sdev->ipc,
424 				 params.hdr.cmd, &params, sizeof(params),
425 				 &ipc_reply, sizeof(ipc_reply));
426 	if (ret < 0) {
427 		dev_err(sdev->dev,
428 			"error: can't set params for DMA for trace %d\n", ret);
429 		goto trace_release;
430 	}
431 
432 	ret = snd_sof_dma_trace_trigger(sdev, SNDRV_PCM_TRIGGER_START);
433 	if (ret < 0) {
434 		dev_err(sdev->dev,
435 			"error: snd_sof_dma_trace_trigger: start: %d\n", ret);
436 		goto trace_release;
437 	}
438 
439 	sdev->dtrace_is_enabled = true;
440 
441 	return 0;
442 
443 trace_release:
444 	snd_sof_dma_trace_release(sdev);
445 	return ret;
446 }
447 
448 int snd_sof_init_trace(struct snd_sof_dev *sdev)
449 {
450 	int ret;
451 
452 	if (!sdev->dtrace_is_supported)
453 		return 0;
454 
455 	/* set false before start initialization */
456 	sdev->dtrace_is_enabled = false;
457 
458 	/* allocate trace page table buffer */
459 	ret = snd_dma_alloc_pages(SNDRV_DMA_TYPE_DEV, sdev->dev,
460 				  PAGE_SIZE, &sdev->dmatp);
461 	if (ret < 0) {
462 		dev_err(sdev->dev,
463 			"error: can't alloc page table for trace %d\n", ret);
464 		return ret;
465 	}
466 
467 	/* allocate trace data buffer */
468 	ret = snd_dma_alloc_pages(SNDRV_DMA_TYPE_DEV_SG, sdev->dev,
469 				  DMA_BUF_SIZE_FOR_TRACE, &sdev->dmatb);
470 	if (ret < 0) {
471 		dev_err(sdev->dev,
472 			"error: can't alloc buffer for trace %d\n", ret);
473 		goto page_err;
474 	}
475 
476 	/* create compressed page table for audio firmware */
477 	ret = snd_sof_create_page_table(sdev->dev, &sdev->dmatb,
478 					sdev->dmatp.area, sdev->dmatb.bytes);
479 	if (ret < 0)
480 		goto table_err;
481 
482 	sdev->dma_trace_pages = ret;
483 	dev_dbg(sdev->dev, "%s: dma_trace_pages: %d\n",
484 		__func__, sdev->dma_trace_pages);
485 
486 	if (sdev->first_boot) {
487 		ret = trace_debugfs_create(sdev);
488 		if (ret < 0)
489 			goto table_err;
490 	}
491 
492 	init_waitqueue_head(&sdev->trace_sleep);
493 
494 	ret = snd_sof_init_trace_ipc(sdev);
495 	if (ret < 0)
496 		goto table_err;
497 
498 	return 0;
499 table_err:
500 	sdev->dma_trace_pages = 0;
501 	snd_dma_free_pages(&sdev->dmatb);
502 page_err:
503 	snd_dma_free_pages(&sdev->dmatp);
504 	return ret;
505 }
506 EXPORT_SYMBOL(snd_sof_init_trace);
507 
508 int snd_sof_trace_update_pos(struct snd_sof_dev *sdev,
509 			     struct sof_ipc_dma_trace_posn *posn)
510 {
511 	if (!sdev->dtrace_is_supported)
512 		return 0;
513 
514 	if (sdev->dtrace_is_enabled && sdev->host_offset != posn->host_offset) {
515 		sdev->host_offset = posn->host_offset;
516 		wake_up(&sdev->trace_sleep);
517 	}
518 
519 	if (posn->overflow != 0)
520 		dev_err(sdev->dev,
521 			"error: DSP trace buffer overflow %u bytes. Total messages %d\n",
522 			posn->overflow, posn->messages);
523 
524 	return 0;
525 }
526 
527 /* an error has occurred within the DSP that prevents further trace */
528 void snd_sof_trace_notify_for_error(struct snd_sof_dev *sdev)
529 {
530 	if (!sdev->dtrace_is_supported)
531 		return;
532 
533 	if (sdev->dtrace_is_enabled) {
534 		sdev->dtrace_error = true;
535 		wake_up(&sdev->trace_sleep);
536 	}
537 }
538 EXPORT_SYMBOL(snd_sof_trace_notify_for_error);
539 
540 void snd_sof_release_trace(struct snd_sof_dev *sdev)
541 {
542 	struct sof_ipc_fw_ready *ready = &sdev->fw_ready;
543 	struct sof_ipc_fw_version *v = &ready->version;
544 	struct sof_ipc_cmd_hdr hdr;
545 	struct sof_ipc_reply ipc_reply;
546 	int ret;
547 
548 	if (!sdev->dtrace_is_supported || !sdev->dtrace_is_enabled)
549 		return;
550 
551 	ret = snd_sof_dma_trace_trigger(sdev, SNDRV_PCM_TRIGGER_STOP);
552 	if (ret < 0)
553 		dev_err(sdev->dev,
554 			"error: snd_sof_dma_trace_trigger: stop: %d\n", ret);
555 
556 	/*
557 	 * stop and free trace DMA in the DSP. TRACE_DMA_FREE is only supported from
558 	 * ABI 3.20.0 onwards
559 	 */
560 	if (v->abi_version >= SOF_ABI_VER(3, 20, 0)) {
561 		hdr.size = sizeof(hdr);
562 		hdr.cmd = SOF_IPC_GLB_TRACE_MSG | SOF_IPC_TRACE_DMA_FREE;
563 
564 		ret = sof_ipc_tx_message(sdev->ipc, hdr.cmd, &hdr, hdr.size,
565 					 &ipc_reply, sizeof(ipc_reply));
566 		if (ret < 0)
567 			dev_err(sdev->dev, "DMA_TRACE_FREE failed with error: %d\n", ret);
568 	}
569 
570 	ret = snd_sof_dma_trace_release(sdev);
571 	if (ret < 0)
572 		dev_err(sdev->dev,
573 			"error: fail in snd_sof_dma_trace_release %d\n", ret);
574 
575 	sdev->dtrace_is_enabled = false;
576 	sdev->dtrace_draining = true;
577 	wake_up(&sdev->trace_sleep);
578 }
579 EXPORT_SYMBOL(snd_sof_release_trace);
580 
581 void snd_sof_free_trace(struct snd_sof_dev *sdev)
582 {
583 	if (!sdev->dtrace_is_supported)
584 		return;
585 
586 	snd_sof_release_trace(sdev);
587 
588 	if (sdev->dma_trace_pages) {
589 		snd_dma_free_pages(&sdev->dmatb);
590 		snd_dma_free_pages(&sdev->dmatp);
591 		sdev->dma_trace_pages = 0;
592 	}
593 }
594 EXPORT_SYMBOL(snd_sof_free_trace);
595