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