ASoC: SOF: Intel: hda: add dev_err() traces for snd_sof_dsp_read_poll_timeout()

Such traces should be extremely rare but extremely useful for debug.

Report errors for all calls to sdn_sof_dsp_read_poll_timeout(), but
only on negative values for consistency.

Add traces that enable each timeout to be uniquely identified.

Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Link: https://lore.kernel.org/r/20191022192844.21022-3-pierre-louis.bossart@linux.intel.com
Signed-off-by: Mark Brown <broonie@kernel.org>

diff --git a/sound/soc/sof/intel/hda-dsp.c b/sound/soc/sof/intel/hda-dsp.c
index fb55a3c5afd0d50cbab4dacbd55c5df1f50cf564..3ea401646e0c211247f0b9aad8299b51fbb77df9 100644 (file)
--- a/sound/soc/sof/intel/hda-dsp.c
+++ b/sound/soc/sof/intel/hda-dsp.c
@@ -42,6 +42,12 @@ int hda_dsp_core_reset_enter(struct snd_sof_dev *sdev, unsigned int core_mask)
                                        ((adspcs & reset) == reset),
                                        HDA_DSP_REG_POLL_INTERVAL_US,
                                        HDA_DSP_RESET_TIMEOUT_US);
+       if (ret < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout on HDA_DSP_REG_ADSPCS read\n",
+                       __func__);
+               return ret;
+       }
 
        /* has core entered reset ? */
        adspcs = snd_sof_dsp_read(sdev, HDA_DSP_BAR,
@@ -77,6 +83,13 @@ int hda_dsp_core_reset_leave(struct snd_sof_dev *sdev, unsigned int core_mask)
                                            HDA_DSP_REG_POLL_INTERVAL_US,
                                            HDA_DSP_RESET_TIMEOUT_US);
 
+       if (ret < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout on HDA_DSP_REG_ADSPCS read\n",
+                       __func__);
+               return ret;
+       }
+
        /* has core left reset ? */
        adspcs = snd_sof_dsp_read(sdev, HDA_DSP_BAR,
                                  HDA_DSP_REG_ADSPCS);
@@ -151,8 +164,12 @@ int hda_dsp_core_power_up(struct snd_sof_dev *sdev, unsigned int core_mask)
                                            (adspcs & cpa) == cpa,
                                            HDA_DSP_REG_POLL_INTERVAL_US,
                                            HDA_DSP_RESET_TIMEOUT_US);
-       if (ret < 0)
-               dev_err(sdev->dev, "error: timeout on core powerup\n");
+       if (ret < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout on HDA_DSP_REG_ADSPCS read\n",
+                       __func__);
+               return ret;
+       }
 
        /* did core power up ? */
        adspcs = snd_sof_dsp_read(sdev, HDA_DSP_BAR,
@@ -171,17 +188,24 @@ int hda_dsp_core_power_up(struct snd_sof_dev *sdev, unsigned int core_mask)
 int hda_dsp_core_power_down(struct snd_sof_dev *sdev, unsigned int core_mask)
 {
        u32 adspcs;
+       int ret;
 
        /* update bits */
        snd_sof_dsp_update_bits_unlocked(sdev, HDA_DSP_BAR,
                                         HDA_DSP_REG_ADSPCS,
                                         HDA_DSP_ADSPCS_SPA_MASK(core_mask), 0);
 
-       return snd_sof_dsp_read_poll_timeout(sdev, HDA_DSP_BAR,
+       ret = snd_sof_dsp_read_poll_timeout(sdev, HDA_DSP_BAR,
                                HDA_DSP_REG_ADSPCS, adspcs,
                                !(adspcs & HDA_DSP_ADSPCS_SPA_MASK(core_mask)),
                                HDA_DSP_REG_POLL_INTERVAL_US,
                                HDA_DSP_PD_TIMEOUT * USEC_PER_MSEC);
+       if (ret < 0)
+               dev_err(sdev->dev,
+                       "error: %s: timeout on HDA_DSP_REG_ADSPCS read\n",
+                       __func__);
+
+       return ret;
 }
 
 bool hda_dsp_core_is_enabled(struct snd_sof_dev *sdev,

diff --git a/sound/soc/sof/intel/hda-loader.c b/sound/soc/sof/intel/hda-loader.c
index 7956dbf5be8882527bd095d0fcbacfb16cd890b1..b1783360fe106bdbf33acffc4443d142bfd81240 100644 (file)
--- a/sound/soc/sof/intel/hda-loader.c
+++ b/sound/soc/sof/intel/hda-loader.c
@@ -126,7 +126,8 @@ static int cl_dsp_init(struct snd_sof_dev *sdev, const void *fwdata,
                                            HDA_DSP_INIT_TIMEOUT_US);
 
        if (ret < 0) {
-               dev_err(sdev->dev, "error: waiting for HIPCIE done\n");
+               dev_err(sdev->dev, "error: %s: timeout for HIPCIE done\n",
+                       __func__);
                goto err;
        }
 
@@ -152,6 +153,10 @@ static int cl_dsp_init(struct snd_sof_dev *sdev, const void *fwdata,
        if (!ret)
                return 0;
 
+       dev_err(sdev->dev,
+               "error: %s: timeout HDA_DSP_SRAM_REG_ROM_STATUS read\n",
+               __func__);
+
 err:
        hda_dsp_dump(sdev, SOF_DBG_REGS | SOF_DBG_PCI | SOF_DBG_MBOX);
        hda_dsp_core_reset_power_down(sdev, chip->cores_mask);
@@ -258,6 +263,12 @@ static int cl_copy_fw(struct snd_sof_dev *sdev, struct hdac_ext_stream *stream)
         * but we return the initial error should the DMA stop also fail
         */
 
+       if (status < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout HDA_DSP_SRAM_REG_ROM_STATUS read\n",
+                       __func__);
+       }
+
        ret = cl_trigger(sdev, stream, SNDRV_PCM_TRIGGER_STOP);
        if (ret < 0) {
                dev_err(sdev->dev, "error: DMA trigger stop failed\n");

diff --git a/sound/soc/sof/intel/hda-stream.c b/sound/soc/sof/intel/hda-stream.c
index 2c744718840254fc30eec8a12dc39ac45d014a14..450f9c55785fa4828acb2c542fd329ad168fa0d6 100644 (file)
--- a/sound/soc/sof/intel/hda-stream.c
+++ b/sound/soc/sof/intel/hda-stream.c
@@ -275,8 +275,12 @@ int hda_dsp_stream_trigger(struct snd_sof_dev *sdev,
                                        HDA_DSP_REG_POLL_INTERVAL_US,
                                        HDA_DSP_STREAM_RUN_TIMEOUT);
 
-               if (ret)
+               if (ret < 0) {
+                       dev_err(sdev->dev,
+                               "error: %s: cmd %d: timeout on STREAM_SD_OFFSET read\n",
+                               __func__, cmd);
                        return ret;
+               }
 
                hstream->running = true;
                break;
@@ -294,8 +298,12 @@ int hda_dsp_stream_trigger(struct snd_sof_dev *sdev,
                                                HDA_DSP_REG_POLL_INTERVAL_US,
                                                HDA_DSP_STREAM_RUN_TIMEOUT);
 
-               if (ret)
+               if (ret < 0) {
+                       dev_err(sdev->dev,
+                               "error: %s: cmd %d: timeout on STREAM_SD_OFFSET read\n",
+                               __func__, cmd);
                        return ret;
+               }
 
                snd_sof_dsp_write(sdev, HDA_DSP_HDA_BAR, sd_offset +
                                  SOF_HDA_ADSP_REG_CL_SD_STS,
@@ -356,8 +364,12 @@ int hda_dsp_stream_hw_params(struct snd_sof_dev *sdev,
                                            HDA_DSP_REG_POLL_INTERVAL_US,
                                            HDA_DSP_STREAM_RUN_TIMEOUT);
 
-       if (ret)
+       if (ret < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout on STREAM_SD_OFFSET read1\n",
+                       __func__);
                return ret;
+       }
 
        snd_sof_dsp_update_bits(sdev, HDA_DSP_HDA_BAR,
                                sd_offset + SOF_HDA_ADSP_REG_CL_SD_STS,
@@ -418,8 +430,12 @@ int hda_dsp_stream_hw_params(struct snd_sof_dev *sdev,
                                            HDA_DSP_REG_POLL_INTERVAL_US,
                                            HDA_DSP_STREAM_RUN_TIMEOUT);
 
-       if (ret)
+       if (ret < 0) {
+               dev_err(sdev->dev,
+                       "error: %s: timeout on STREAM_SD_OFFSET read2\n",
+                       __func__);
                return ret;
+       }
 
        snd_sof_dsp_update_bits(sdev, HDA_DSP_HDA_BAR,
                                sd_offset + SOF_HDA_ADSP_REG_CL_SD_STS,