[PATCH 00/19] ASoC: SOF: Improvements for debugging

[PATCH 00/19] ASoC: SOF: Improvements for debugging

[Peter Ujfalusi]

Hi,

The aim of this series is to clean up, make it easier to interpret and less
'chatty' prints aimed for debugging errors.

For example currently the DSP/IPC dump is printed every time we have an IPC
timeout and it is posible to lost the first and more indicative dump to find the
rootcause.

Regards,
Peter
---
Peter Ujfalusi (18):
  ASoC: SOF: debug: Swap the dsp_dump and ipc_dump sequence for
    fw_exception
  ASoC: SOF: ipc and dsp dump: Add markers for better visibility
  ASoC: SOF: Print the dbg_dump and ipc_dump once to reduce kernel log
    noise
  ASoC: SOF: loader: Print the DSP dump if boot fails
  ASoC: SOF: intel: atom: No need to do a DSP dump in atom_run()
  ASoC: SOF: debug/ops: Move the IPC and DSP dump functions out from the
    header
  ASoC: SOF: debug: Add SOF_DBG_DUMP_OPTIONAL flag for DSP dumping
  ASoC: SOF: intel: hda-loader: Use snd_sof_dsp_dbg_dump() for DSP dump
  ASoC: SOF: Drop SOF_DBG_DUMP_FORCE_ERR_LEVEL and sof_dev_dbg_or_err
  ASoC: SOF: debug: Print out the fw_state along with the DSP dump
  ASoC: SOF: ipc: Re-enable dumps after successful IPC tx
  ASoC: SOF: ops: Force DSP panic dumps to be printed
  ASoC: SOF: Introduce macro to set the firmware state
  ASoC: SOF: intel: hda: Drop 'error' prefix from error dump functions
  ASoC: SOF: core: Clean up snd_sof_get_status() prints
  ASoC: SOF: loader: Drop SOF_DBG_DUMP_REGS flag when firmware start
    fails
  ASoC: SOF: Intel: hda-loader: Drop SOF_DBG_DUMP_REGS flag from
    dbg_dump calls
  ASoC: SOF: Intel: hda: Dump registers and stack when SOF_DBG_DUMP_REGS
    is set

Pierre-Louis Bossart (1):
  ASoC: SOF: core: debug: force all processing on primary core

 sound/soc/sof/core.c             | 24 ++++++-------
 sound/soc/sof/debug.c            | 61 ++++++++++++++++++++++++++++++--
 sound/soc/sof/intel/atom.c       |  5 +--
 sound/soc/sof/intel/hda-loader.c | 11 +++---
 sound/soc/sof/intel/hda.c        | 16 +++------
 sound/soc/sof/ipc.c              | 10 ++++--
 sound/soc/sof/loader.c           | 11 ++++--
 sound/soc/sof/ops.c              |  3 ++
 sound/soc/sof/ops.h              | 12 +------
 sound/soc/sof/pm.c               |  6 ++--
 sound/soc/sof/sof-priv.h         | 31 ++++++++++------
 sound/soc/sof/topology.c         |  6 ++++
 12 files changed, 131 insertions(+), 65 deletions(-)

-- 
2.33.0

[PATCH 01/19] ASoC: SOF: core: debug: force all processing on primary core

[Peter Ujfalusi]

From: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>

The topology file currently provides information on which
pipeline/processing is to be scheduled on which DSP core.

To help diagnose potential issues, this patch provides an override of
the 'core' tokens to use the primary core (typically core0). Of course
this may result in a Core0 activity that exceeds hardware
capabilities, so this should only be used when the total processing
fits on DSP - possibly using firmware mockup processing and stubs.

No new dmesg log was added to avoid adding noise during topology
parsing, but the existing logs will show the primary core being used.

This is strictly for validation/debug, products should NEVER use this
override, the topology is assumed to be the description of the
firmware graph.

Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Bard Liao <bard.liao@intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
---
 sound/soc/sof/sof-priv.h | 3 +++
 sound/soc/sof/topology.c | 6 ++++++
 2 files changed, 9 insertions(+)

diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h
index 4e5bab838cbf..0ca64f0f8873 100644
--- a/sound/soc/sof/sof-priv.h
+++ b/sound/soc/sof/sof-priv.h
@@ -30,6 +30,9 @@
 #define SOF_DBG_DYNAMIC_PIPELINES_ENABLE	BIT(4) /* 0: use static pipelines
 							* 1: use dynamic pipelines
 							*/
+#define SOF_DBG_DISABLE_MULTICORE		BIT(5) /* schedule all pipelines/widgets
+							* on primary core
+							*/
 
 #define SOF_DBG_DUMP_REGS		BIT(0)
 #define SOF_DBG_DUMP_MBOX		BIT(1)
diff --git a/sound/soc/sof/topology.c b/sound/soc/sof/topology.c
index 534f004f6162..73c0ee7b88ac 100644
--- a/sound/soc/sof/topology.c
+++ b/sound/soc/sof/topology.c
@@ -1759,6 +1759,9 @@ static int sof_widget_load_pipeline(struct snd_soc_component *scomp, int index,
 		goto err;
 	}
 
+	if (sof_core_debug & SOF_DBG_DISABLE_MULTICORE)
+		pipeline->core = SOF_DSP_PRIMARY_CORE;
+
 	if (sof_core_debug & SOF_DBG_DYNAMIC_PIPELINES_OVERRIDE)
 		swidget->dynamic_pipeline_widget = sof_core_debug &
 			SOF_DBG_DYNAMIC_PIPELINES_ENABLE;
@@ -2356,6 +2359,9 @@ static int sof_widget_ready(struct snd_soc_component *scomp, int index,
 		return ret;
 	}
 
+	if (sof_core_debug & SOF_DBG_DISABLE_MULTICORE)
+		comp.core = SOF_DSP_PRIMARY_CORE;
+
 	swidget->core = comp.core;
 
 	ret = sof_parse_tokens(scomp, &swidget->comp_ext, comp_ext_tokens,
-- 
2.33.0

[PATCH 02/19] ASoC: SOF: debug: Swap the dsp_dump and ipc_dump sequence for fw_exception

[Peter Ujfalusi]

snd_sof_dsp_panic() only prints dsp_dump followed by flushing the DMA trace
buffer.

To retain similar 'sequence' first do an ipc_dump then the dsp_dump and
finally flush the trace buffer in case of fw_exception.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/debug.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c
index f37ea1956406..3b85e0484411 100644
--- a/sound/soc/sof/debug.c
+++ b/sound/soc/sof/debug.c
@@ -832,8 +832,8 @@ void snd_sof_handle_fw_exception(struct snd_sof_dev *sdev)
 	}
 
 	/* dump vital information to the logs */
-	snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX);
 	snd_sof_ipc_dump(sdev);
+	snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX);
 	snd_sof_trace_notify_for_error(sdev);
 }
 EXPORT_SYMBOL(snd_sof_handle_fw_exception);
-- 
2.33.0

[PATCH 03/19] ASoC: SOF: ipc and dsp dump: Add markers for better visibility

[Peter Ujfalusi]

Add markers to identify the start and end of the IPC and DSP dumps in the
kernel log.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/ops.h | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/sound/soc/sof/ops.h b/sound/soc/sof/ops.h
index a93aa5b943b2..d143a35f16fc 100644
--- a/sound/soc/sof/ops.h
+++ b/sound/soc/sof/ops.h
@@ -243,14 +243,20 @@ snd_sof_dsp_set_power_state(struct snd_sof_dev *sdev,
 /* debug */
 static inline void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
 {
-	if (sof_ops(sdev)->dbg_dump)
+	if (sof_ops(sdev)->dbg_dump) {
+		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
 		sof_ops(sdev)->dbg_dump(sdev, flags);
+		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
+	}
 }
 
 static inline void snd_sof_ipc_dump(struct snd_sof_dev *sdev)
 {
-	if (sof_ops(sdev)->ipc_dump)
+	if (sof_ops(sdev)->ipc_dump) {
+		dev_err(sdev->dev, "------------[ IPC dump start ]------------\n");
 		sof_ops(sdev)->ipc_dump(sdev);
+		dev_err(sdev->dev, "------------[ IPC dump end ]------------\n");
+	}
 }
 
 static inline int snd_sof_debugfs_add_region_item(struct snd_sof_dev *sdev,
-- 
2.33.0

[PATCH 04/19] ASoC: SOF: Print the dbg_dump and ipc_dump once to reduce kernel log noise

[Peter Ujfalusi]

Do not print the dump more than once to keep the kernel log cleaner in case
of a firmware failure.

When the DSP is rebooted due to suspend or runtime_suspend reset the flags
to re-enable the dump prints.

Add also a debug flag to print all dumps to get more coverage if needed.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/debug.c    | 4 +++-
 sound/soc/sof/loader.c   | 4 ++++
 sound/soc/sof/ops.h      | 8 ++++++--
 sound/soc/sof/sof-priv.h | 3 +++
 4 files changed, 16 insertions(+), 3 deletions(-)

diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c
index 3b85e0484411..221808a8e759 100644
--- a/sound/soc/sof/debug.c
+++ b/sound/soc/sof/debug.c
@@ -827,7 +827,9 @@ void snd_sof_handle_fw_exception(struct snd_sof_dev *sdev)
 	if (IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_RETAIN_DSP_CONTEXT) ||
 	    (sof_core_debug & SOF_DBG_RETAIN_CTX)) {
 		/* should we prevent DSP entering D3 ? */
-		dev_info(sdev->dev, "info: preventing DSP entering D3 state to preserve context\n");
+		if (!sdev->ipc_dump_printed)
+			dev_info(sdev->dev,
+				 "preventing DSP entering D3 state to preserve context\n");
 		pm_runtime_get_noresume(sdev->dev);
 	}
 
diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c
index 62e6f257c3f0..6a3bc1927627 100644
--- a/sound/soc/sof/loader.c
+++ b/sound/soc/sof/loader.c
@@ -791,6 +791,10 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 
 	init_waitqueue_head(&sdev->boot_wait);
 
+	/* (re-)enable dsp dump */
+	sdev->dbg_dump_printed = false;
+	sdev->ipc_dump_printed = false;
+
 	/* 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,
diff --git a/sound/soc/sof/ops.h b/sound/soc/sof/ops.h
index d143a35f16fc..c7670514aa68 100644
--- a/sound/soc/sof/ops.h
+++ b/sound/soc/sof/ops.h
@@ -243,19 +243,23 @@ snd_sof_dsp_set_power_state(struct snd_sof_dev *sdev,
 /* debug */
 static inline void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
 {
-	if (sof_ops(sdev)->dbg_dump) {
+	if (sof_ops(sdev)->dbg_dump && !sdev->dbg_dump_printed) {
 		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
 		sof_ops(sdev)->dbg_dump(sdev, flags);
 		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
+		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
+			sdev->dbg_dump_printed = true;
 	}
 }
 
 static inline void snd_sof_ipc_dump(struct snd_sof_dev *sdev)
 {
-	if (sof_ops(sdev)->ipc_dump) {
+	if (sof_ops(sdev)->ipc_dump  && !sdev->ipc_dump_printed) {
 		dev_err(sdev->dev, "------------[ IPC dump start ]------------\n");
 		sof_ops(sdev)->ipc_dump(sdev);
 		dev_err(sdev->dev, "------------[ IPC dump end ]------------\n");
+		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
+			sdev->ipc_dump_printed = true;
 	}
 }
 
diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h
index 0ca64f0f8873..bb6de1c1e3ec 100644
--- a/sound/soc/sof/sof-priv.h
+++ b/sound/soc/sof/sof-priv.h
@@ -33,6 +33,7 @@
 #define SOF_DBG_DISABLE_MULTICORE		BIT(5) /* schedule all pipelines/widgets
 							* on primary core
 							*/
+#define SOF_DBG_PRINT_ALL_DUMPS		BIT(6) /* Print all ipc and dsp dumps */
 
 #define SOF_DBG_DUMP_REGS		BIT(0)
 #define SOF_DBG_DUMP_MBOX		BIT(1)
@@ -421,6 +422,8 @@ struct snd_sof_dev {
 	/* debug */
 	struct dentry *debugfs_root;
 	struct list_head dfsentry_list;
+	bool dbg_dump_printed;
+	bool ipc_dump_printed;
 
 	/* firmware loader */
 	struct snd_dma_buffer dmab;
-- 
2.33.0

[PATCH 05/19] ASoC: SOF: loader: Print the DSP dump if boot fails

[Peter Ujfalusi]

It can be useful to print the DSP dump from the core in case the DSP boot
failed.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/loader.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c
index 6a3bc1927627..144b72bf8190 100644
--- a/sound/soc/sof/loader.c
+++ b/sound/soc/sof/loader.c
@@ -819,7 +819,9 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 	/* boot the firmware on the DSP */
 	ret = snd_sof_dsp_run(sdev);
 	if (ret < 0) {
-		dev_err(sdev->dev, "error: failed to reset DSP\n");
+		dev_err(sdev->dev, "error: failed to start DSP\n");
+		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX |
+				     SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_FORCE_ERR_LEVEL);
 		return ret;
 	}
 
-- 
2.33.0

[PATCH 06/19] ASoC: SOF: intel: atom: No need to do a DSP dump in atom_run()

[Peter Ujfalusi]

The core already prints a dump if the DSP failed to start in
snd_sof_run_firmware(), there is no need to print it locally as well.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/intel/atom.c | 5 +----
 1 file changed, 1 insertion(+), 4 deletions(-)

diff --git a/sound/soc/sof/intel/atom.c b/sound/soc/sof/intel/atom.c
index d8804efede5e..74c630bb9847 100644
--- a/sound/soc/sof/intel/atom.c
+++ b/sound/soc/sof/intel/atom.c
@@ -283,11 +283,8 @@ int atom_run(struct snd_sof_dev *sdev)
 			break;
 		msleep(100);
 	}
-	if (tries < 0) {
-		dev_err(sdev->dev, "error:  unable to run DSP firmware\n");
-		atom_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX);
+	if (tries < 0)
 		return -ENODEV;
-	}
 
 	/* return init core mask */
 	return 1;
-- 
2.33.0

[PATCH 07/19] ASoC: SOF: debug/ops: Move the IPC and DSP dump functions out from the header

[Peter Ujfalusi]

To be usable in platform code, move the IPC and DSP dump function to
debug.c and export it in a similar way as the snd_sof_handle_fw_exception()

Make the snd_sof_ipc_dump() static as it is only used in debug.c

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/debug.c | 23 +++++++++++++++++++++++
 sound/soc/sof/ops.h   | 22 +---------------------
 2 files changed, 24 insertions(+), 21 deletions(-)

diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c
index 221808a8e759..9ed6728c2017 100644
--- a/sound/soc/sof/debug.c
+++ b/sound/soc/sof/debug.c
@@ -822,6 +822,29 @@ void snd_sof_free_debug(struct snd_sof_dev *sdev)
 }
 EXPORT_SYMBOL_GPL(snd_sof_free_debug);
 
+void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
+{
+	if (sof_ops(sdev)->dbg_dump && !sdev->dbg_dump_printed) {
+		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
+		sof_ops(sdev)->dbg_dump(sdev, flags);
+		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
+		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
+			sdev->dbg_dump_printed = true;
+	}
+}
+EXPORT_SYMBOL(snd_sof_dsp_dbg_dump);
+
+static void snd_sof_ipc_dump(struct snd_sof_dev *sdev)
+{
+	if (sof_ops(sdev)->ipc_dump  && !sdev->ipc_dump_printed) {
+		dev_err(sdev->dev, "------------[ IPC dump start ]------------\n");
+		sof_ops(sdev)->ipc_dump(sdev);
+		dev_err(sdev->dev, "------------[ IPC dump end ]------------\n");
+		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
+			sdev->ipc_dump_printed = true;
+	}
+}
+
 void snd_sof_handle_fw_exception(struct snd_sof_dev *sdev)
 {
 	if (IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_RETAIN_DSP_CONTEXT) ||
diff --git a/sound/soc/sof/ops.h b/sound/soc/sof/ops.h
index c7670514aa68..290e32a8a7d4 100644
--- a/sound/soc/sof/ops.h
+++ b/sound/soc/sof/ops.h
@@ -241,27 +241,7 @@ snd_sof_dsp_set_power_state(struct snd_sof_dev *sdev,
 }
 
 /* debug */
-static inline void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
-{
-	if (sof_ops(sdev)->dbg_dump && !sdev->dbg_dump_printed) {
-		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
-		sof_ops(sdev)->dbg_dump(sdev, flags);
-		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
-		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
-			sdev->dbg_dump_printed = true;
-	}
-}
-
-static inline void snd_sof_ipc_dump(struct snd_sof_dev *sdev)
-{
-	if (sof_ops(sdev)->ipc_dump  && !sdev->ipc_dump_printed) {
-		dev_err(sdev->dev, "------------[ IPC dump start ]------------\n");
-		sof_ops(sdev)->ipc_dump(sdev);
-		dev_err(sdev->dev, "------------[ IPC dump end ]------------\n");
-		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
-			sdev->ipc_dump_printed = true;
-	}
-}
+void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags);
 
 static inline int snd_sof_debugfs_add_region_item(struct snd_sof_dev *sdev,
 		enum snd_sof_fw_blk_type blk_type, u32 offset, size_t size,
-- 
2.33.0

[PATCH 08/19] ASoC: SOF: debug: Add SOF_DBG_DUMP_OPTIONAL flag for DSP dumping

[Peter Ujfalusi]

The new SOF_DBG_DUMP_OPTIONAL flag can be used to mark a DSP dump that
should only be printed when the SOF_DBG_PRINT_ALL_DUMPS sof_core_debug
flag is set, otherwise it should be ignored and not printed.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/debug.c    | 7 ++++++-
 sound/soc/sof/sof-priv.h | 2 +-
 2 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c
index 9ed6728c2017..bcd381f495c0 100644
--- a/sound/soc/sof/debug.c
+++ b/sound/soc/sof/debug.c
@@ -824,11 +824,16 @@ EXPORT_SYMBOL_GPL(snd_sof_free_debug);
 
 void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
 {
+	bool print_all = !!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS);
+
+	if (flags & SOF_DBG_DUMP_OPTIONAL && !print_all)
+		return;
+
 	if (sof_ops(sdev)->dbg_dump && !sdev->dbg_dump_printed) {
 		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
 		sof_ops(sdev)->dbg_dump(sdev, flags);
 		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
-		if (!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS))
+		if (!print_all)
 			sdev->dbg_dump_printed = true;
 	}
 }
diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h
index bb6de1c1e3ec..d20ead47be1b 100644
--- a/sound/soc/sof/sof-priv.h
+++ b/sound/soc/sof/sof-priv.h
@@ -40,7 +40,7 @@
 #define SOF_DBG_DUMP_TEXT		BIT(2)
 #define SOF_DBG_DUMP_PCI		BIT(3)
 #define SOF_DBG_DUMP_FORCE_ERR_LEVEL	BIT(4) /* used to dump dsp status with error log level */
-
+#define SOF_DBG_DUMP_OPTIONAL		BIT(5) /* only dump if SOF_DBG_PRINT_ALL_DUMPS is set */
 
 /* global debug state set by SOF_DBG_ flags */
 extern int sof_core_debug;
-- 
2.33.0

[PATCH 09/19] ASoC: SOF: intel: hda-loader: Use snd_sof_dsp_dbg_dump() for DSP dump

[Peter Ujfalusi]

Do not call directly the hda_dsp_dump(), use the generic wrapper instead
to provide consistent output.

Mark the DSP dumps as optional to not spam the kernel log with the
exception of the last dump in case the DSP fails to run.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/intel/hda-loader.c | 18 ++++++++++++------
 1 file changed, 12 insertions(+), 6 deletions(-)

diff --git a/sound/soc/sof/intel/hda-loader.c b/sound/soc/sof/intel/hda-loader.c
index 6f4771bf9de3..d2be02dc2801 100644
--- a/sound/soc/sof/intel/hda-loader.c
+++ b/sound/soc/sof/intel/hda-loader.c
@@ -177,13 +177,19 @@ static int cl_dsp_init(struct snd_sof_dev *sdev, int stream_tag)
 			__func__);
 
 err:
-	flags = SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX;
+	flags = SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX |
+		SOF_DBG_DUMP_OPTIONAL;
 
-	/* force error log level after max boot attempts */
-	if (hda->boot_iteration == HDA_FW_BOOT_ATTEMPTS)
+	/*
+	 * after max boot attempts make sure that the dump is printed and error
+	 * log level is used
+	 */
+	if (hda->boot_iteration == HDA_FW_BOOT_ATTEMPTS) {
 		flags |= SOF_DBG_DUMP_FORCE_ERR_LEVEL;
+		flags &= ~SOF_DBG_DUMP_OPTIONAL;
+	}
 
-	hda_dsp_dump(sdev, flags);
+	snd_sof_dsp_dbg_dump(sdev, flags);
 	snd_sof_dsp_core_power_down(sdev, chip->host_managed_cores_mask);
 
 	return ret;
@@ -414,8 +420,8 @@ int hda_dsp_cl_boot_firmware(struct snd_sof_dev *sdev)
 	if (!ret) {
 		dev_dbg(sdev->dev, "Firmware download successful, booting...\n");
 	} else {
-		hda_dsp_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX |
-			     SOF_DBG_DUMP_FORCE_ERR_LEVEL);
+		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI |
+				     SOF_DBG_DUMP_MBOX | SOF_DBG_DUMP_FORCE_ERR_LEVEL);
 		dev_err(sdev->dev, "error: load fw failed ret: %d\n", ret);
 	}
 
-- 
2.33.0

[PATCH 10/19] ASoC: SOF: Drop SOF_DBG_DUMP_FORCE_ERR_LEVEL and sof_dev_dbg_or_err

[Peter Ujfalusi]

The sof_dev_dbg_or_err() is only used by intel/hda.c when dumping dsp
debug information.
It was used to print the extended rom status in either dev_dbg (during
retries) and finally with dev_err, but other lines were printed with
dev_err regardless.

Since we now only print the dump once, the flag and the macros is no longer
needed.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
---
 sound/soc/sof/intel/hda-loader.c | 11 +++--------
 sound/soc/sof/intel/hda.c        |  3 +--
 sound/soc/sof/loader.c           |  4 ++--
 sound/soc/sof/sof-priv.h         | 12 +-----------
 4 files changed, 7 insertions(+), 23 deletions(-)

diff --git a/sound/soc/sof/intel/hda-loader.c b/sound/soc/sof/intel/hda-loader.c
index d2be02dc2801..10b37e8ad30b 100644
--- a/sound/soc/sof/intel/hda-loader.c
+++ b/sound/soc/sof/intel/hda-loader.c
@@ -180,14 +180,9 @@ static int cl_dsp_init(struct snd_sof_dev *sdev, int stream_tag)
 	flags = SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX |
 		SOF_DBG_DUMP_OPTIONAL;
 
-	/*
-	 * after max boot attempts make sure that the dump is printed and error
-	 * log level is used
-	 */
-	if (hda->boot_iteration == HDA_FW_BOOT_ATTEMPTS) {
-		flags |= SOF_DBG_DUMP_FORCE_ERR_LEVEL;
+	/* after max boot attempts make sure that the dump is printed */
+	if (hda->boot_iteration == HDA_FW_BOOT_ATTEMPTS)
 		flags &= ~SOF_DBG_DUMP_OPTIONAL;
-	}
 
 	snd_sof_dsp_dbg_dump(sdev, flags);
 	snd_sof_dsp_core_power_down(sdev, chip->host_managed_cores_mask);
@@ -421,7 +416,7 @@ int hda_dsp_cl_boot_firmware(struct snd_sof_dev *sdev)
 		dev_dbg(sdev->dev, "Firmware download successful, booting...\n");
 	} else {
 		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI |
-				     SOF_DBG_DUMP_MBOX | SOF_DBG_DUMP_FORCE_ERR_LEVEL);
+				     SOF_DBG_DUMP_MBOX);
 		dev_err(sdev->dev, "error: load fw failed ret: %d\n", ret);
 	}
 
diff --git a/sound/soc/sof/intel/hda.c b/sound/soc/sof/intel/hda.c
index 1463f3de01bc..c4dcab10e64b 100644
--- a/sound/soc/sof/intel/hda.c
+++ b/sound/soc/sof/intel/hda.c
@@ -532,8 +532,7 @@ static void hda_dsp_dump_ext_rom_status(struct snd_sof_dev *sdev, u32 flags)
 		len += snprintf(msg + len, sizeof(msg) - len, " 0x%x", value);
 	}
 
-	sof_dev_dbg_or_err(sdev->dev, flags & SOF_DBG_DUMP_FORCE_ERR_LEVEL,
-			   "extended rom status: %s", msg);
+	dev_err(sdev->dev, "error: extended rom status: %s", msg);
 
 }
 
diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c
index 144b72bf8190..a0ae174f9bb0 100644
--- a/sound/soc/sof/loader.c
+++ b/sound/soc/sof/loader.c
@@ -821,7 +821,7 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 	if (ret < 0) {
 		dev_err(sdev->dev, "error: failed to start DSP\n");
 		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX |
-				     SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_FORCE_ERR_LEVEL);
+				     SOF_DBG_DUMP_PCI);
 		return ret;
 	}
 
@@ -837,7 +837,7 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 	if (ret == 0) {
 		dev_err(sdev->dev, "error: firmware boot failure\n");
 		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX |
-			SOF_DBG_DUMP_TEXT | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_FORCE_ERR_LEVEL);
+				     SOF_DBG_DUMP_TEXT | SOF_DBG_DUMP_PCI);
 		sdev->fw_state = SOF_FW_BOOT_FAILED;
 		return -EIO;
 	}
diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h
index d20ead47be1b..5c1939339936 100644
--- a/sound/soc/sof/sof-priv.h
+++ b/sound/soc/sof/sof-priv.h
@@ -39,8 +39,7 @@
 #define SOF_DBG_DUMP_MBOX		BIT(1)
 #define SOF_DBG_DUMP_TEXT		BIT(2)
 #define SOF_DBG_DUMP_PCI		BIT(3)
-#define SOF_DBG_DUMP_FORCE_ERR_LEVEL	BIT(4) /* used to dump dsp status with error log level */
-#define SOF_DBG_DUMP_OPTIONAL		BIT(5) /* only dump if SOF_DBG_PRINT_ALL_DUMPS is set */
+#define SOF_DBG_DUMP_OPTIONAL		BIT(4) /* only dump if SOF_DBG_PRINT_ALL_DUMPS is set */
 
 /* global debug state set by SOF_DBG_ flags */
 extern int sof_core_debug;
@@ -593,13 +592,4 @@ int intel_pcm_close(struct snd_sof_dev *sdev,
 		    struct snd_pcm_substream *substream);
 
 int sof_machine_check(struct snd_sof_dev *sdev);
-
-#define sof_dev_dbg_or_err(dev, is_err, fmt, ...)			\
-	do {								\
-		if (is_err)						\
-			dev_err(dev, "error: " fmt, __VA_ARGS__);	\
-		else							\
-			dev_dbg(dev, fmt, __VA_ARGS__);			\
-	} while (0)
-
 #endif
-- 
2.33.0

[PATCH 11/19] ASoC: SOF: debug: Print out the fw_state along with the DSP dump

[Peter Ujfalusi]

The fw state can be an important information along with the DSP dump.
Print it out before the dump.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/debug.c | 27 +++++++++++++++++++++++++++
 1 file changed, 27 insertions(+)

diff --git a/sound/soc/sof/debug.c b/sound/soc/sof/debug.c
index bcd381f495c0..dc1df5fb7b4c 100644
--- a/sound/soc/sof/debug.c
+++ b/sound/soc/sof/debug.c
@@ -822,6 +822,32 @@ void snd_sof_free_debug(struct snd_sof_dev *sdev)
 }
 EXPORT_SYMBOL_GPL(snd_sof_free_debug);
 
+static const struct soc_fw_state_info {
+	enum snd_sof_fw_state state;
+	const char *name;
+} fw_state_dbg[] = {
+	{SOF_FW_BOOT_NOT_STARTED, "SOF_FW_BOOT_NOT_STARTED"},
+	{SOF_FW_BOOT_PREPARE, "SOF_FW_BOOT_PREPARE"},
+	{SOF_FW_BOOT_IN_PROGRESS, "SOF_FW_BOOT_IN_PROGRESS"},
+	{SOF_FW_BOOT_FAILED, "SOF_FW_BOOT_FAILED"},
+	{SOF_FW_BOOT_READY_FAILED, "SOF_FW_BOOT_READY_FAILED"},
+	{SOF_FW_BOOT_COMPLETE, "SOF_FW_BOOT_COMPLETE"},
+};
+
+static void snd_sof_dbg_print_fw_state(struct snd_sof_dev *sdev)
+{
+	int i;
+
+	for (i = 0; i < ARRAY_SIZE(fw_state_dbg); i++) {
+		if (sdev->fw_state == fw_state_dbg[i].state) {
+			dev_err(sdev->dev, "fw_state: %s (%d)\n", fw_state_dbg[i].name, i);
+			return;
+		}
+	}
+
+	dev_err(sdev->dev, "fw_state: UNKNOWN (%d)\n", sdev->fw_state);
+}
+
 void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
 {
 	bool print_all = !!(sof_core_debug & SOF_DBG_PRINT_ALL_DUMPS);
@@ -831,6 +857,7 @@ void snd_sof_dsp_dbg_dump(struct snd_sof_dev *sdev, u32 flags)
 
 	if (sof_ops(sdev)->dbg_dump && !sdev->dbg_dump_printed) {
 		dev_err(sdev->dev, "------------[ DSP dump start ]------------\n");
+		snd_sof_dbg_print_fw_state(sdev);
 		sof_ops(sdev)->dbg_dump(sdev, flags);
 		dev_err(sdev->dev, "------------[ DSP dump end ]------------\n");
 		if (!print_all)
-- 
2.33.0

[PATCH 12/19] ASoC: SOF: ipc: Re-enable dumps after successful IPC tx

[Peter Ujfalusi]

The dumps are silenced after an IPC tx timeout by default.
The IPC timeout can indicate severe error (firmware crash) or in some cases
it is less devastating and the firmware remains operational, the timeout
was due to a scheduling spike or other anomaly.

In any case consequent IPC timeouts will not print dumps but if any IPC do
succeed than we should re-enable the dumps to print dumps the next time
a timeout might happen.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/ipc.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/sound/soc/sof/ipc.c b/sound/soc/sof/ipc.c
index 53593df95155..5c698fa662f4 100644
--- a/sound/soc/sof/ipc.c
+++ b/sound/soc/sof/ipc.c
@@ -267,6 +267,12 @@ static int tx_wait_done(struct snd_sof_ipc *ipc, struct snd_sof_ipc_msg *msg,
 				memcpy(reply_data, msg->reply_data,
 				       msg->reply_size);
 		}
+
+		/* re-enable dumps after successful IPC tx */
+		if (sdev->ipc_dump_printed) {
+			sdev->dbg_dump_printed = false;
+			sdev->ipc_dump_printed = false;
+		}
 	}
 
 	return ret;
-- 
2.33.0

[PATCH 13/19] ASoC: SOF: ops: Force DSP panic dumps to be printed

[Peter Ujfalusi]

If a DSP panic happens we want to see the dumps.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/ops.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/sound/soc/sof/ops.c b/sound/soc/sof/ops.c
index 11ecebd07907..160b88a2d59f 100644
--- a/sound/soc/sof/ops.c
+++ b/sound/soc/sof/ops.c
@@ -157,6 +157,9 @@ void snd_sof_dsp_panic(struct snd_sof_dev *sdev, u32 offset)
 		dev_dbg(sdev->dev, "panic: dsp_oops_offset %zu offset %d\n",
 			sdev->dsp_oops_offset, offset);
 
+	/* We want to see the DSP panic! */
+	sdev->dbg_dump_printed = false;
+
 	snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX);
 	snd_sof_trace_notify_for_error(sdev);
 }
-- 
2.33.0

[PATCH 14/19] ASoC: SOF: Introduce macro to set the firmware state

[Peter Ujfalusi]

Add sof_set_fw_state() macro to wrap the sdev->fw_state management to allow
actions to be taken when certain state is set or when state is changing.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/core.c     |  8 ++++----
 sound/soc/sof/ipc.c      |  4 ++--
 sound/soc/sof/loader.c   |  2 +-
 sound/soc/sof/pm.c       |  6 +++---
 sound/soc/sof/sof-priv.h | 13 +++++++++++++
 5 files changed, 23 insertions(+), 10 deletions(-)

diff --git a/sound/soc/sof/core.c b/sound/soc/sof/core.c
index 2ea29186e397..22a1c5090ae0 100644
--- a/sound/soc/sof/core.c
+++ b/sound/soc/sof/core.c
@@ -147,7 +147,7 @@ static int sof_probe_continue(struct snd_sof_dev *sdev)
 		return ret;
 	}
 
-	sdev->fw_state = SOF_FW_BOOT_PREPARE;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_PREPARE);
 
 	/* check machine info */
 	ret = sof_machine_check(sdev);
@@ -189,7 +189,7 @@ static int sof_probe_continue(struct snd_sof_dev *sdev)
 		goto fw_load_err;
 	}
 
-	sdev->fw_state = SOF_FW_BOOT_IN_PROGRESS;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_IN_PROGRESS);
 
 	/*
 	 * Boot the firmware. The FW boot status will be modified
@@ -265,7 +265,7 @@ static int sof_probe_continue(struct snd_sof_dev *sdev)
 	snd_sof_remove(sdev);
 
 	/* all resources freed, update state to match */
-	sdev->fw_state = SOF_FW_BOOT_NOT_STARTED;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_NOT_STARTED);
 	sdev->first_boot = true;
 
 	return ret;
@@ -300,7 +300,7 @@ int snd_sof_device_probe(struct device *dev, struct snd_sof_pdata *plat_data)
 
 	sdev->pdata = plat_data;
 	sdev->first_boot = true;
-	sdev->fw_state = SOF_FW_BOOT_NOT_STARTED;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_NOT_STARTED);
 #if IS_ENABLED(CONFIG_SND_SOC_SOF_DEBUG_PROBES)
 	sdev->extractor_stream_tag = SOF_PROBE_INVALID_NODE_ID;
 #endif
diff --git a/sound/soc/sof/ipc.c b/sound/soc/sof/ipc.c
index 5c698fa662f4..5a308c62f7ca 100644
--- a/sound/soc/sof/ipc.c
+++ b/sound/soc/sof/ipc.c
@@ -458,9 +458,9 @@ void snd_sof_ipc_msgs_rx(struct snd_sof_dev *sdev)
 		if (sdev->fw_state == SOF_FW_BOOT_IN_PROGRESS) {
 			err = sof_ops(sdev)->fw_ready(sdev, cmd);
 			if (err < 0)
-				sdev->fw_state = SOF_FW_BOOT_READY_FAILED;
+				sof_set_fw_state(sdev, SOF_FW_BOOT_READY_FAILED);
 			else
-				sdev->fw_state = SOF_FW_BOOT_COMPLETE;
+				sof_set_fw_state(sdev, SOF_FW_BOOT_COMPLETE);
 
 			/* wake up firmware loader */
 			wake_up(&sdev->boot_wait);
diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c
index a0ae174f9bb0..de7082f3226c 100644
--- a/sound/soc/sof/loader.c
+++ b/sound/soc/sof/loader.c
@@ -838,7 +838,7 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 		dev_err(sdev->dev, "error: firmware boot failure\n");
 		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX |
 				     SOF_DBG_DUMP_TEXT | SOF_DBG_DUMP_PCI);
-		sdev->fw_state = SOF_FW_BOOT_FAILED;
+		sof_set_fw_state(sdev, SOF_FW_BOOT_FAILED);
 		return -EIO;
 	}
 
diff --git a/sound/soc/sof/pm.c b/sound/soc/sof/pm.c
index 77a3496d3dbd..bf759bfa305e 100644
--- a/sound/soc/sof/pm.c
+++ b/sound/soc/sof/pm.c
@@ -122,7 +122,7 @@ static int sof_resume(struct device *dev, bool runtime_resume)
 	    old_state == SOF_DSP_PM_D0)
 		return 0;
 
-	sdev->fw_state = SOF_FW_BOOT_PREPARE;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_PREPARE);
 
 	/* load the firmware */
 	ret = snd_sof_load_firmware(sdev);
@@ -133,7 +133,7 @@ static int sof_resume(struct device *dev, bool runtime_resume)
 		return ret;
 	}
 
-	sdev->fw_state = SOF_FW_BOOT_IN_PROGRESS;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_IN_PROGRESS);
 
 	/*
 	 * Boot the firmware. The FW boot status will be modified
@@ -257,7 +257,7 @@ static int sof_suspend(struct device *dev, bool runtime_suspend)
 		return ret;
 
 	/* reset FW state */
-	sdev->fw_state = SOF_FW_BOOT_NOT_STARTED;
+	sof_set_fw_state(sdev, SOF_FW_BOOT_NOT_STARTED);
 	sdev->enabled_cores_mask = 0;
 
 	return ret;
diff --git a/sound/soc/sof/sof-priv.h b/sound/soc/sof/sof-priv.h
index 5c1939339936..d9525f3ff5cd 100644
--- a/sound/soc/sof/sof-priv.h
+++ b/sound/soc/sof/sof-priv.h
@@ -561,6 +561,19 @@ static inline void sof_oops(struct snd_sof_dev *sdev, void *oops)
 
 extern const struct dsp_arch_ops sof_xtensa_arch_ops;
 
+/*
+ * Firmware state tracking
+ */
+static inline void sof_set_fw_state(struct snd_sof_dev *sdev,
+				    enum snd_sof_fw_state new_state)
+{
+	if (sdev->fw_state == new_state)
+		return;
+
+	dev_dbg(sdev->dev, "fw_state change: %d -> %d\n", sdev->fw_state, new_state);
+	sdev->fw_state = new_state;
+}
+
 /*
  * Utilities
  */
-- 
2.33.0

[PATCH 15/19] ASoC: SOF: intel: hda: Drop 'error' prefix from error dump functions

[Peter Ujfalusi]

Drop the 'error' prefix printed in hda_dsp_dump_ext_rom_status(),
hda_ipc_irq_dump() and hda_ipc_dump() as it gives no value to the
information we print.

The DSP and IPC dump is marked now, which makes the 'error' prefix more
redundant.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/intel/hda.c | 12 ++++--------
 1 file changed, 4 insertions(+), 8 deletions(-)

diff --git a/sound/soc/sof/intel/hda.c b/sound/soc/sof/intel/hda.c
index c4dcab10e64b..2d715f48f599 100644
--- a/sound/soc/sof/intel/hda.c
+++ b/sound/soc/sof/intel/hda.c
@@ -532,7 +532,7 @@ static void hda_dsp_dump_ext_rom_status(struct snd_sof_dev *sdev, u32 flags)
 		len += snprintf(msg + len, sizeof(msg) - len, " 0x%x", value);
 	}
 
-	dev_err(sdev->dev, "error: extended rom status: %s", msg);
+	dev_err(sdev->dev, "extended rom status: %s", msg);
 
 }
 
@@ -575,12 +575,9 @@ void hda_ipc_irq_dump(struct snd_sof_dev *sdev)
 	ppsts = snd_sof_dsp_read(sdev, HDA_DSP_PP_BAR, SOF_HDA_REG_PP_PPSTS);
 	rirbsts = snd_hdac_chip_readb(bus, RIRBSTS);
 
-	dev_err(sdev->dev,
-		"error: hda irq intsts 0x%8.8x intlctl 0x%8.8x rirb %2.2x\n",
+	dev_err(sdev->dev, "hda irq intsts 0x%8.8x intlctl 0x%8.8x rirb %2.2x\n",
 		intsts, intctl, rirbsts);
-	dev_err(sdev->dev,
-		"error: dsp irq ppsts 0x%8.8x adspis 0x%8.8x\n",
-		ppsts, adspis);
+	dev_err(sdev->dev, "dsp irq ppsts 0x%8.8x adspis 0x%8.8x\n", ppsts, adspis);
 }
 
 void hda_ipc_dump(struct snd_sof_dev *sdev)
@@ -598,8 +595,7 @@ void hda_ipc_dump(struct snd_sof_dev *sdev)
 
 	/* dump the IPC regs */
 	/* TODO: parse the raw msg */
-	dev_err(sdev->dev,
-		"error: host status 0x%8.8x dsp status 0x%8.8x mask 0x%8.8x\n",
+	dev_err(sdev->dev, "host status 0x%8.8x dsp status 0x%8.8x mask 0x%8.8x\n",
 		hipcie, hipct, hipcctl);
 }
 
-- 
2.33.0

[PATCH 16/19] ASoC: SOF: core: Clean up snd_sof_get_status() prints

[Peter Ujfalusi]

Clean up the error prints when decoding the status in snd_sof_get_status():
Drop the "error:" prefixes from the prints,
Use %# to print hexadecimal numbers,
Reword some of the messages to be more precise,
For a known error print out the panic code as well,
For unknown error print only the panic code without the magic

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/core.c | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/sound/soc/sof/core.c b/sound/soc/sof/core.c
index 22a1c5090ae0..2c3de295f11f 100644
--- a/sound/soc/sof/core.c
+++ b/sound/soc/sof/core.c
@@ -67,7 +67,7 @@ void snd_sof_get_status(struct snd_sof_dev *sdev, u32 panic_code,
 
 	/* is firmware dead ? */
 	if ((panic_code & SOF_IPC_PANIC_MAGIC_MASK) != SOF_IPC_PANIC_MAGIC) {
-		dev_err(sdev->dev, "error: unexpected fault 0x%8.8x trace 0x%8.8x\n",
+		dev_err(sdev->dev, "unexpected fault %#010x trace %#010x\n",
 			panic_code, tracep_code);
 		return; /* no fault ? */
 	}
@@ -76,20 +76,20 @@ void snd_sof_get_status(struct snd_sof_dev *sdev, u32 panic_code,
 
 	for (i = 0; i < ARRAY_SIZE(panic_msg); i++) {
 		if (panic_msg[i].id == code) {
-			dev_err(sdev->dev, "error: %s\n", panic_msg[i].msg);
-			dev_err(sdev->dev, "error: trace point %8.8x\n",
-				tracep_code);
+			dev_err(sdev->dev, "reason: %s (%#x)\n", panic_msg[i].msg,
+				code & SOF_IPC_PANIC_CODE_MASK);
+			dev_err(sdev->dev, "trace point: %#010x\n", tracep_code);
 			goto out;
 		}
 	}
 
 	/* unknown error */
-	dev_err(sdev->dev, "error: unknown reason %8.8x\n", panic_code);
-	dev_err(sdev->dev, "error: trace point %8.8x\n", tracep_code);
+	dev_err(sdev->dev, "unknown panic code: %#x\n", code & SOF_IPC_PANIC_CODE_MASK);
+	dev_err(sdev->dev, "trace point: %#010x\n", tracep_code);
 
 out:
-	dev_err(sdev->dev, "error: panic at %s:%d\n",
-		panic_info->filename, panic_info->linenum);
+	dev_err(sdev->dev, "panic at %s:%d\n", panic_info->filename,
+		panic_info->linenum);
 	sof_oops(sdev, oops);
 	sof_stack(sdev, oops, stack, stack_words);
 }
-- 
2.33.0

[PATCH 17/19] ASoC: SOF: loader: Drop SOF_DBG_DUMP_REGS flag when firmware start fails

[Peter Ujfalusi]

snd_sof_dsp_run() failure indicates that the DSP did not even booted up,
thus asking for dumping registers at this point is not valid.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/loader.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/sound/soc/sof/loader.c b/sound/soc/sof/loader.c
index de7082f3226c..54aa7764d2b3 100644
--- a/sound/soc/sof/loader.c
+++ b/sound/soc/sof/loader.c
@@ -820,8 +820,7 @@ int snd_sof_run_firmware(struct snd_sof_dev *sdev)
 	ret = snd_sof_dsp_run(sdev);
 	if (ret < 0) {
 		dev_err(sdev->dev, "error: failed to start DSP\n");
-		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_MBOX |
-				     SOF_DBG_DUMP_PCI);
+		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_MBOX | SOF_DBG_DUMP_PCI);
 		return ret;
 	}
 
-- 
2.33.0

[PATCH 18/19] ASoC: SOF: Intel: hda-loader: Drop SOF_DBG_DUMP_REGS flag from dbg_dump calls

[Peter Ujfalusi]

In cl_dsp_init() we are powering up the DSP, register dump is not valid.
In hda_dsp_cl_boot_firmware() we are downloading the firmware to DSP, again
the register dump is not a valid concept.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/intel/hda-loader.c | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/sound/soc/sof/intel/hda-loader.c b/sound/soc/sof/intel/hda-loader.c
index 10b37e8ad30b..abad6d0ceb83 100644
--- a/sound/soc/sof/intel/hda-loader.c
+++ b/sound/soc/sof/intel/hda-loader.c
@@ -177,8 +177,7 @@ static int cl_dsp_init(struct snd_sof_dev *sdev, int stream_tag)
 			__func__);
 
 err:
-	flags = SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX |
-		SOF_DBG_DUMP_OPTIONAL;
+	flags = SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX | SOF_DBG_DUMP_OPTIONAL;
 
 	/* after max boot attempts make sure that the dump is printed */
 	if (hda->boot_iteration == HDA_FW_BOOT_ATTEMPTS)
@@ -415,8 +414,7 @@ int hda_dsp_cl_boot_firmware(struct snd_sof_dev *sdev)
 	if (!ret) {
 		dev_dbg(sdev->dev, "Firmware download successful, booting...\n");
 	} else {
-		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_REGS | SOF_DBG_DUMP_PCI |
-				     SOF_DBG_DUMP_MBOX);
+		snd_sof_dsp_dbg_dump(sdev, SOF_DBG_DUMP_PCI | SOF_DBG_DUMP_MBOX);
 		dev_err(sdev->dev, "error: load fw failed ret: %d\n", ret);
 	}
 
-- 
2.33.0

[PATCH 19/19] ASoC: SOF: Intel: hda: Dump registers and stack when SOF_DBG_DUMP_REGS is set

[Peter Ujfalusi]

Instead of checking the fw_state to decide what information should be
printed, use the SOF_DBG_DUMP_REGS bit in the flags to dump registers and
stack.

Signed-off-by: Peter Ujfalusi <peter.ujfalusi@linux.intel.com>
Reviewed-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Reviewed-by: Ranjani Sridharan <ranjani.sridharan@linux.intel.com>
Reviewed-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
---
 sound/soc/sof/intel/hda.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/sound/soc/sof/intel/hda.c b/sound/soc/sof/intel/hda.c
index 2d715f48f599..883d78dd01b5 100644
--- a/sound/soc/sof/intel/hda.c
+++ b/sound/soc/sof/intel/hda.c
@@ -545,8 +545,7 @@ void hda_dsp_dump(struct snd_sof_dev *sdev, u32 flags)
 	/* print ROM/FW status */
 	hda_dsp_get_status(sdev);
 
-	/* print panic info if FW boot is complete. Otherwise, print the extended ROM status */
-	if (sdev->fw_state == SOF_FW_BOOT_COMPLETE) {
+	if (flags & SOF_DBG_DUMP_REGS) {
 		u32 status = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_SRAM_REG_FW_STATUS);
 		u32 panic = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_SRAM_REG_FW_TRACEP);
 
-- 
2.33.0

Re: [PATCH 00/19] ASoC: SOF: Improvements for debugging

[Mark Brown]

[-- Attachment #1: Type: text/plain, Size: 624 bytes --]

On Wed, Oct 06, 2021 at 02:06:26PM +0300, Peter Ujfalusi wrote:
> Hi,
> 
> The aim of this series is to clean up, make it easier to interpret and less
> 'chatty' prints aimed for debugging errors.
> 
> For example currently the DSP/IPC dump is printed every time we have an IPC
> timeout and it is posible to lost the first and more indicative dump to find the
> rootcause.

You might want to look at tracepoints and/or trace_printk, apart from
anything else they're very useful for flight recorder style applications
since they're very low overhead and have comparitively speeaking lots of
storage available.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCH 00/19] ASoC: SOF: Improvements for debugging

[Pierre-Louis Bossart]

On 10/6/21 6:23 AM, Mark Brown wrote:
> On Wed, Oct 06, 2021 at 02:06:26PM +0300, Peter Ujfalusi wrote:
>> Hi,
>>
>> The aim of this series is to clean up, make it easier to interpret and less
>> 'chatty' prints aimed for debugging errors.
>>
>> For example currently the DSP/IPC dump is printed every time we have an IPC
>> timeout and it is posible to lost the first and more indicative dump to find the
>> rootcause.
> 
> You might want to look at tracepoints and/or trace_printk, apart from
> anything else they're very useful for flight recorder style applications
> since they're very low overhead and have comparitively speeaking lots of
> storage available.

Yes, for the dev_dbg() I am thinking of a transition to tracepoints
indeed. That would be most interesting for IPC, stream events, state
machines, etc. We'll probably want to gather kernel and firmware traces
with the same tools as well, something that should already be supported
in hardware and not using due to inertia, lack of time, etc.

But the changes that Peter did for this series are for 'major' issues
that should typically not happen, rare events using limited bandwidth
and usually not recoverable without a DSP reset. It's the kind of things
we want end-users to report with 'alsa-info'.

Re: [PATCH 00/19] ASoC: SOF: Improvements for debugging

[Péter Ujfalusi]

Hi Mark,

On 06/10/2021 14:23, Mark Brown wrote:
> On Wed, Oct 06, 2021 at 02:06:26PM +0300, Peter Ujfalusi wrote:
>> Hi,
>>
>> The aim of this series is to clean up, make it easier to interpret and less
>> 'chatty' prints aimed for debugging errors.
>>
>> For example currently the DSP/IPC dump is printed every time we have an IPC
>> timeout and it is posible to lost the first and more indicative dump to find the
>> rootcause.
> 
> You might want to look at tracepoints and/or trace_printk, apart from
> anything else they're very useful for flight recorder style applications
> since they're very low overhead and have comparitively speeaking lots of
> storage available.

The trace infra is indeed a direction which would help on new hardware,
architecture bringup.

I should have used different subject for the cover letter as the end
result is to have better quality bug reports from users in the unlikely
event that something goes wrong (mostly on the firmware side).

To speed up the turnaround to get it fixed as the first report should
contain enough details to hint us where to look.

At the end the series will actually reduce the noise from dev_err() in
case of a failure by printing only needed information without repetition.

-- 
Péter

Re: [PATCH 00/19] ASoC: SOF: Improvements for debugging

[Péter Ujfalusi]

Hi Mark,

my mail client dropped everyone except the list, resending with correct
TO/CC

On 06/10/2021 14:23, Mark Brown wrote:
> On Wed, Oct 06, 2021 at 02:06:26PM +0300, Peter Ujfalusi wrote:
>> Hi,
>>
>> The aim of this series is to clean up, make it easier to interpret and less
>> 'chatty' prints aimed for debugging errors.
>>
>> For example currently the DSP/IPC dump is printed every time we have an IPC
>> timeout and it is posible to lost the first and more indicative dump to find the
>> rootcause.
> 
> You might want to look at tracepoints and/or trace_printk, apart from
> anything else they're very useful for flight recorder style applications
> since they're very low overhead and have comparitively speeaking lots of
> storage available.

The trace infra is indeed a direction which would help on new hardware,
architecture bringup.

I should have used different subject for the cover letter as the end
result is to have better quality bug reports from users in the unlikely
event that something goes wrong (mostly on the firmware side).

To speed up the turnaround to get it fixed as the first report should
contain enough details to hint us where to look.

At the end the series will actually reduce the noise from dev_err() in
case of a failure by printing only needed information without repetition.


-- 
Péter

Re: [PATCH 00/19] ASoC: SOF: Improvements for debugging

[Mark Brown]

On Wed, 6 Oct 2021 14:06:26 +0300, Peter Ujfalusi wrote:
> The aim of this series is to clean up, make it easier to interpret and less
> 'chatty' prints aimed for debugging errors.
> 
> For example currently the DSP/IPC dump is printed every time we have an IPC
> timeout and it is posible to lost the first and more indicative dump to find the
> rootcause.
> 
> [...]

Applied to

   https://git.kernel.org/pub/scm/linux/kernel/git/broonie/sound.git for-next

Thanks!

[01/19] ASoC: SOF: core: debug: force all processing on primary core
        commit: 1539c8c5fcca217e3de063e7fbec97f83c7938a7
[02/19] ASoC: SOF: debug: Swap the dsp_dump and ipc_dump sequence for fw_exception
        commit: e85c26eca639f3cf0ad989756f0eac2045391bb6
[03/19] ASoC: SOF: ipc and dsp dump: Add markers for better visibility
        commit: 3f7561f74169e199f9d6f4f0cdb9eb681052381a
[04/19] ASoC: SOF: Print the dbg_dump and ipc_dump once to reduce kernel log noise
        commit: 9ff90859b95f6c85ce2d671ecd1e95e91dbe7f15
[05/19] ASoC: SOF: loader: Print the DSP dump if boot fails
        commit: 247ac640739dda167a127a2ecb158595695ffd7d
[06/19] ASoC: SOF: intel: atom: No need to do a DSP dump in atom_run()
        commit: e131bc58868a529c1c97567fc6d0d8855bdb3ffd
[07/19] ASoC: SOF: debug/ops: Move the IPC and DSP dump functions out from the header
        commit: 360fa3234e9205306b7730d9afa64c8c3f909160
[08/19] ASoC: SOF: debug: Add SOF_DBG_DUMP_OPTIONAL flag for DSP dumping
        commit: 34346a383de96e9fcecb1906d711fc1b09d9b90a
[09/19] ASoC: SOF: intel: hda-loader: Use snd_sof_dsp_dbg_dump() for DSP dump
        commit: 0ecaa2fff2debf46d6cc978cd6e48d923e3d339d
[10/19] ASoC: SOF: Drop SOF_DBG_DUMP_FORCE_ERR_LEVEL and sof_dev_dbg_or_err
        commit: 23013335bc3c906e304cda507d80b8006381a4f7
[11/19] ASoC: SOF: debug: Print out the fw_state along with the DSP dump
        commit: c05ec07143998d8505a054378f8d5b287648c9bf
[12/19] ASoC: SOF: ipc: Re-enable dumps after successful IPC tx
        commit: e6ff3db9efe96a9c3cd8b0c33744f259c1928a42
[13/19] ASoC: SOF: ops: Force DSP panic dumps to be printed
        commit: 705f4539c4c834de9a7885512585b3a27fedf216
[14/19] ASoC: SOF: Introduce macro to set the firmware state
        commit: 58a5c9a4aa993fe2059c1b8dbcff9bf468d722b8
[15/19] ASoC: SOF: intel: hda: Drop 'error' prefix from error dump functions
        commit: 4fade25dfbe121f8ef61458b4655966f133b1907
[16/19] ASoC: SOF: core: Clean up snd_sof_get_status() prints
        commit: e51838909b69a8c941629a6f86804f8e189103e2
[17/19] ASoC: SOF: loader: Drop SOF_DBG_DUMP_REGS flag when firmware start fails
        commit: f8c3ec4368df1e5051030beaeb961fd7f625d2d1
[18/19] ASoC: SOF: Intel: hda-loader: Drop SOF_DBG_DUMP_REGS flag from dbg_dump calls
        commit: 7511b0edf1b8d9a1321ac19cb076fcdfe534439a
[19/19] ASoC: SOF: Intel: hda: Dump registers and stack when SOF_DBG_DUMP_REGS is set
        commit: 3ad7b8f4817fcfd68a101ec9986c435f17cc74a1

All being well this means that it will be integrated into the linux-next
tree (usually sometime in the next 24 hours) and sent to Linus during
the next merge window (or sooner if it is a bug fix), however if
problems are discovered then the patch may be dropped or reverted.

You may get further e-mails resulting from automated or manual testing
and review of the tree, please engage with people reporting problems and
send followup patches addressing any issues that are reported if needed.

If any updates are required or you are submitting further changes they
should be sent as incremental updates against current git, existing
patches will not be replaced.

Please add any relevant lists and maintainers to the CCs when replying
to this mail.

Thanks,
Mark