sound/soc/sof/debug.c

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