From 9d53fc174c4bd340f83e103da11f7676c0f52d8c Mon Sep 17 00:00:00 2001 From: Ranjani Sridharan Date: Sun, 21 Apr 2019 23:35:29 -0700 Subject: [PATCH 1/3] ASoC: SOF: add mode parameter for snd_sof_debugfs_buf_item Add mode parameter for snd_sof_debugfs_buf_item() to specify the mode while creating debugfs entries. Signed-off-by: Ranjani Sridharan --- sound/soc/sof/debug.c | 4 ++-- sound/soc/sof/loader.c | 4 ++-- sound/soc/sof/sof-priv.h | 2 +- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c index 55f1d808dba04f..219c3becf670fb 100644 --- a/sound/soc/sof/debug.c +++ b/sound/soc/sof/debug.c @@ -161,7 +161,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 +177,7 @@ 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, + 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 */ 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..14faf3c4550e08 100644 --- a/sound/soc/sof/sof-priv.h +++ b/sound/soc/sof/sof-priv.h @@ -547,7 +547,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); From 190110bed0996559feba48e7e6b08c170d815202 Mon Sep 17 00:00:00 2001 From: Ranjani Sridharan Date: Tue, 7 May 2019 22:05:37 -0700 Subject: [PATCH 2/3] ASoC: SOF: ipc: Introduce SOF_IPC_GLB_TEST_MSG IPC command Add a new class of IPC command along with the first test type, IPC_FLOOD, which will be used for flooding the DSP with IPCs. Signed-off-by: Ranjani Sridharan --- include/sound/sof/header.h | 6 +++++- sound/soc/sof/ipc.c | 9 +++++++++ 2 files changed, 14 insertions(+), 1 deletion(-) 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/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; } From ea033614a3237ae10cc98029225d71bfebf47193 Mon Sep 17 00:00:00 2001 From: Ranjani Sridharan Date: Tue, 7 May 2019 22:08:19 -0700 Subject: [PATCH 3/3] ASoC: SOF: debug: add new debugfs entries for IPC flood test Add a couple of new debugfs entries "ipc_flood_count" and "ipc_flood_duration_ms" that can be used to execute the IPC flood test. "ipc_flood_count" floods the DSP with the number of test IPCs specified and ipc_flood_duration_ms floods the DSP with test IPC's for the duration(in ms) specified. The test stats such as average, min and max IPC response times are logged in the dmesg and saved in the debugfs entry cache buffer. Signed-off-by: Ranjani Sridharan --- sound/soc/sof/Kconfig | 8 ++ sound/soc/sof/debug.c | 243 +++++++++++++++++++++++++++++++++++++++ sound/soc/sof/sof-priv.h | 6 +- 3 files changed, 256 insertions(+), 1 deletion(-) 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 219c3becf670fb..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 */ @@ -177,6 +391,17 @@ int snd_sof_debugfs_buf_item(struct snd_sof_dev *sdev, dfse->size = size; dfse->sdev = sdev; +#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) { @@ -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/sof-priv.h b/sound/soc/sof/sof-priv.h index 14faf3c4550e08..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;