sound/soc/sof/ipc3-dtrace.c

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