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