diff --git a/include/sound/sof/header.h b/include/sound/sof/header.h index ab5862d80afedf..12867bbd4372ac 100644 --- a/include/sound/sof/header.h +++ b/include/sound/sof/header.h @@ -49,6 +49,7 @@ #define SOF_IPC_GLB_DAI_MSG SOF_GLB_TYPE(0x8U) #define SOF_IPC_GLB_TRACE_MSG SOF_GLB_TYPE(0x9U) #define SOF_IPC_GLB_GDB_DEBUG SOF_GLB_TYPE(0xAU) +#define SOF_IPC_GLB_TEST_MSG SOF_GLB_TYPE(0xBU) /* * DSP Command Message Types @@ -99,11 +100,14 @@ #define SOF_IPC_STREAM_VORBIS_PARAMS SOF_CMD_TYPE(0x010) #define SOF_IPC_STREAM_VORBIS_FREE SOF_CMD_TYPE(0x011) -/* trace and debug */ +/* trace */ #define SOF_IPC_TRACE_DMA_PARAMS SOF_CMD_TYPE(0x001) #define SOF_IPC_TRACE_DMA_POSITION SOF_CMD_TYPE(0x002) #define SOF_IPC_TRACE_DMA_PARAMS_EXT SOF_CMD_TYPE(0x003) +/* debug */ +#define SOF_IPC_TEST_IPC_FLOOD SOF_CMD_TYPE(0x001) + /* Get message component id */ #define SOF_IPC_MESSAGE_ID(x) ((x) & 0xffff) diff --git a/sound/soc/sof/Kconfig b/sound/soc/sof/Kconfig index a468ffc1cfd5bc..8e2188e5600015 100644 --- a/sound/soc/sof/Kconfig +++ b/sound/soc/sof/Kconfig @@ -136,6 +136,14 @@ config SND_SOC_SOF_DEBUG_ENABLE_FIRMWARE_TRACE module parameter (similar to dynamic debug) If unsure, select "N". +config SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST + bool "SOF enable IPC flood test" + help + This option enables the IPC flood test which can be used to flood + the DSP with test IPCs and gather stats about response times. + Say Y if you want to enable IPC flood test. + If unsure, select "N". + endif ## SND_SOC_SOF_DEBUG endif ## SND_SOC_SOF_OPTIONS diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c index 55f1d808dba04f..54bb53bfc81bf2 100644 --- a/sound/soc/sof/debug.c +++ b/sound/soc/sof/debug.c @@ -17,6 +17,203 @@ #include "sof-priv.h" #include "ops.h" +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) +#define MAX_IPC_FLOOD_DURATION_MS 1000 +#define MAX_IPC_FLOOD_COUNT 10000 +#define IPC_FLOOD_TEST_RESULT_LEN 512 + +static int sof_debug_ipc_flood_test(struct snd_sof_dev *sdev, + struct snd_sof_dfsentry *dfse, + bool flood_duration_test, + unsigned long ipc_duration_ms, + unsigned long ipc_count) +{ + struct sof_ipc_cmd_hdr hdr; + struct sof_ipc_reply reply; + u64 min_response_time = U64_MAX; + ktime_t start, end, test_end; + u64 avg_response_time = 0; + u64 max_response_time = 0; + u64 ipc_response_time; + int i = 0; + int ret; + + /* configure test IPC */ + hdr.cmd = SOF_IPC_GLB_TEST_MSG | SOF_IPC_TEST_IPC_FLOOD; + hdr.size = sizeof(hdr); + + /* set test end time for duration flood test */ + if (flood_duration_test) + test_end = ktime_get_ns() + ipc_duration_ms * NSEC_PER_MSEC; + + /* send test IPC's */ + while (1) { + start = ktime_get(); + ret = sof_ipc_tx_message(sdev->ipc, hdr.cmd, &hdr, hdr.size, + &reply, sizeof(reply)); + end = ktime_get(); + + if (ret < 0) + break; + + /* compute min and max response times */ + ipc_response_time = ktime_to_ns(ktime_sub(end, start)); + min_response_time = min(min_response_time, ipc_response_time); + max_response_time = max(max_response_time, ipc_response_time); + + /* sum up response times */ + avg_response_time += ipc_response_time; + i++; + + /* test complete? */ + if (flood_duration_test) { + if (ktime_to_ns(end) >= test_end) + break; + } else { + if (i == ipc_count) + break; + } + } + + if (ret < 0) + dev_err(sdev->dev, + "error: ipc flood test failed at %d iterations\n", i); + + /* return if the first IPC fails */ + if (!i) + return ret; + + /* compute average response time */ + do_div(avg_response_time, i); + + /* clear previous test output */ + memset(dfse->cache_buf, 0, IPC_FLOOD_TEST_RESULT_LEN); + + if (flood_duration_test) { + dev_dbg(sdev->dev, "IPC Flood test duration: %lums\n", + ipc_duration_ms); + snprintf(dfse->cache_buf, IPC_FLOOD_TEST_RESULT_LEN, + "IPC Flood test duration: %lums\n", ipc_duration_ms); + } + + dev_dbg(sdev->dev, + "IPC Flood count: %d, Avg response time: %lluns\n", + i, avg_response_time); + dev_dbg(sdev->dev, "Max response time: %lluns\n", + max_response_time); + dev_dbg(sdev->dev, "Min response time: %lluns\n", + min_response_time); + + /* format output string */ + snprintf(dfse->cache_buf + strlen(dfse->cache_buf), + IPC_FLOOD_TEST_RESULT_LEN - strlen(dfse->cache_buf), + "IPC Flood count: %d\nAvg response time: %lluns\n", + i, avg_response_time); + + snprintf(dfse->cache_buf + strlen(dfse->cache_buf), + IPC_FLOOD_TEST_RESULT_LEN - strlen(dfse->cache_buf), + "Max response time: %lluns\nMin response time: %lluns\n", + max_response_time, min_response_time); + + return ret; +} +#endif + +static ssize_t sof_dfsentry_write(struct file *file, const char __user *buffer, + size_t count, loff_t *ppos) +{ +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) + struct snd_sof_dfsentry *dfse = file->private_data; + struct snd_sof_dev *sdev = dfse->sdev; + unsigned long ipc_duration_ms = 0; + bool flood_duration_test = false; + unsigned long ipc_count = 0; + int err; +#endif + size_t size; + char *string; + int ret; + + string = kzalloc(count, GFP_KERNEL); + if (!string) + return -ENOMEM; + + size = simple_write_to_buffer(string, count, ppos, buffer, count); + ret = size; + +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) + /* + * write op is only supported for ipc_flood_count or + * ipc_flood_duration_ms debugfs entries atm. + * ipc_flood_count floods the DSP with the number of IPC's specified. + * ipc_duration_ms test floods the DSP for the time specified + * in the debugfs entry. + */ + if (strcmp(dfse->dfsentry->d_name.name, "ipc_flood_count") && + strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms")) + return -EINVAL; + + if (!strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms")) + flood_duration_test = true; + + /* test completion criterion */ + if (flood_duration_test) + ret = kstrtoul(string, 0, &ipc_duration_ms); + else + ret = kstrtoul(string, 0, &ipc_count); + if (ret < 0) + return ret; + + /* limit max duration/ipc count for flood test */ + if (flood_duration_test) { + if (!ipc_duration_ms) { + ret = size; + goto out; + } + + /* find the minimum. min() is not used to avoid warnings */ + if (ipc_duration_ms > MAX_IPC_FLOOD_DURATION_MS) + ipc_duration_ms = MAX_IPC_FLOOD_DURATION_MS; + } else { + if (!ipc_count) { + ret = size; + goto out; + } + + /* find the minimum. min() is not used to avoid warnings */ + if (ipc_count > MAX_IPC_FLOOD_COUNT) + ipc_count = MAX_IPC_FLOOD_COUNT; + } + + ret = pm_runtime_get_sync(sdev->dev); + if (ret < 0) { + dev_err_ratelimited(sdev->dev, + "error: debugfs write failed to resume %d\n", + ret); + pm_runtime_put_noidle(sdev->dev); + return ret; + } + + /* flood test */ + ret = sof_debug_ipc_flood_test(sdev, dfse, flood_duration_test, + ipc_duration_ms, ipc_count); + + pm_runtime_mark_last_busy(sdev->dev); + err = pm_runtime_put_autosuspend(sdev->dev); + if (err < 0) + dev_err_ratelimited(sdev->dev, + "error: debugfs write failed to idle %d\n", + err); + + /* return size if test is successful */ + if (ret >= 0) + ret = size; +out: +#endif + kfree(string); + return ret; +} + static ssize_t sof_dfsentry_read(struct file *file, char __user *buffer, size_t count, loff_t *ppos) { @@ -28,6 +225,22 @@ static ssize_t sof_dfsentry_read(struct file *file, char __user *buffer, int size; u8 *buf; +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) + if ((!strcmp(dfse->dfsentry->d_name.name, "ipc_flood_count") || + !strcmp(dfse->dfsentry->d_name.name, "ipc_flood_duration_ms")) && + dfse->cache_buf) { + if (*ppos) + return 0; + + count = strlen(dfse->cache_buf); + size_ret = copy_to_user(buffer, dfse->cache_buf, count); + if (size_ret) + return -EFAULT; + + *ppos += count; + return count; + } +#endif size = dfse->size; /* validate position & count */ @@ -107,6 +320,7 @@ static const struct file_operations sof_dfs_fops = { .open = simple_open, .read = sof_dfsentry_read, .llseek = default_llseek, + .write = sof_dfsentry_write, }; /* create FS entry for debug files that can expose DSP memories, registers */ @@ -161,7 +375,7 @@ EXPORT_SYMBOL_GPL(snd_sof_debugfs_io_item); /* create FS entry for debug files to expose kernel memory */ int snd_sof_debugfs_buf_item(struct snd_sof_dev *sdev, void *base, size_t size, - const char *name) + const char *name, mode_t mode) { struct snd_sof_dfsentry *dfse; @@ -177,7 +391,18 @@ int snd_sof_debugfs_buf_item(struct snd_sof_dev *sdev, dfse->size = size; dfse->sdev = sdev; - dfse->dfsentry = debugfs_create_file(name, 0444, sdev->debugfs_root, +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) + /* + * cache_buf is unused for SOF_DFSENTRY_TYPE_BUF debugfs entries. + * So, use it to save the results of the last IPC flood test. + */ + dfse->cache_buf = devm_kzalloc(sdev->dev, IPC_FLOOD_TEST_RESULT_LEN, + GFP_KERNEL); + if (!dfse->cache_buf) + return -ENOMEM; +#endif + + dfse->dfsentry = debugfs_create_file(name, mode, sdev->debugfs_root, dfse, &sof_dfs_fops); if (!dfse->dfsentry) { /* can't rely on debugfs, only log error and keep going */ @@ -221,6 +446,24 @@ int snd_sof_dbg_init(struct snd_sof_dev *sdev) return err; } +#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST) + /* create read-write ipc_flood_count debugfs entry */ + err = snd_sof_debugfs_buf_item(sdev, NULL, 0, + "ipc_flood_count", 0666); + + /* errors are only due to memory allocation, not debugfs */ + if (err < 0) + return err; + + /* create read-write ipc_flood_duration_ms debugfs entry */ + err = snd_sof_debugfs_buf_item(sdev, NULL, 0, + "ipc_flood_duration_ms", 0666); + + /* errors are only due to memory allocation, not debugfs */ + if (err < 0) + return err; +#endif + return 0; } EXPORT_SYMBOL_GPL(snd_sof_dbg_init); diff --git a/sound/soc/sof/ipc.c b/sound/soc/sof/ipc.c index 2414640a32d18d..558b596e2133a4 100644 --- a/sound/soc/sof/ipc.c +++ b/sound/soc/sof/ipc.c @@ -175,6 +175,15 @@ static void ipc_log_header(struct device *dev, u8 *text, u32 cmd) break; case SOF_IPC_GLB_TRACE_MSG: str = "GLB_TRACE_MSG"; break; + case SOF_IPC_GLB_TEST_MSG: + str = "GLB_TEST_MSG"; + switch (type) { + case SOF_IPC_TEST_IPC_FLOOD: + str2 = "IPC_FLOOD"; break; + default: + str2 = "unknown type"; break; + } + break; default: str = "unknown GLB command"; break; } diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c index 628fae5524424a..1021df12db112f 100644 --- a/sound/soc/sof/loader.c +++ b/sound/soc/sof/loader.c @@ -337,11 +337,11 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev) init_waitqueue_head(&sdev->boot_wait); sdev->boot_complete = false; - /* create fw_version debugfs to store boot version info */ + /* create read-only fw_version debugfs to store boot version info */ if (sdev->first_boot) { ret = snd_sof_debugfs_buf_item(sdev, &sdev->fw_version, sizeof(sdev->fw_version), - "fw_version"); + "fw_version", 0444); /* errors are only due to memory allocation, not debugfs */ if (ret < 0) { dev_err(sdev->dev, "error: snd_sof_debugfs_buf_item failed\n"); diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h index 03d852293d2794..563623bcaad6e2 100644 --- a/sound/soc/sof/sof-priv.h +++ b/sound/soc/sof/sof-priv.h @@ -56,6 +56,10 @@ #define SOF_FORMATS (SNDRV_PCM_FMTBIT_S16_LE | SNDRV_PCM_FMTBIT_S24_LE | \ SNDRV_PCM_FMTBIT_S32_LE | SNDRV_PCM_FMTBIT_FLOAT) +#define ENABLE_DEBUGFS_CACHEBUF \ + (IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE) || \ + IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_IPC_FLOOD_TEST)) + struct snd_sof_dev; struct snd_sof_ipc_msg; struct snd_sof_ipc; @@ -226,7 +230,7 @@ struct snd_sof_dfsentry { * or if it is accessible only when the DSP is in D0. */ enum sof_debugfs_access_type access_type; -#if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE) +#if ENABLE_DEBUGFS_CACHEBUF char *cache_buf; /* buffer to cache the contents of debugfs memory */ #endif struct snd_sof_dev *sdev; @@ -547,7 +551,7 @@ int snd_sof_debugfs_io_item(struct snd_sof_dev *sdev, enum sof_debugfs_access_type access_type); int snd_sof_debugfs_buf_item(struct snd_sof_dev *sdev, void *base, size_t size, - const char *name); + const char *name, mode_t mode); int snd_sof_trace_update_pos(struct snd_sof_dev *sdev, struct sof_ipc_dma_trace_posn *posn); void snd_sof_trace_notify_for_error(struct snd_sof_dev *sdev);