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