[PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Richard Fitzgerald]

The DSP_SCRATCH1 register is used by firmwares to hold diagnostic
information. Include this in the shutdown message - it can be
useful for debugging.

Signed-off-by: Richard Fitzgerald <rf@opensource.wolfsonmicro.com>
---
 sound/soc/codecs/wm_adsp.c |   14 +++++++++++++-
 1 files changed, 13 insertions(+), 1 deletions(-)

diff --git a/sound/soc/codecs/wm_adsp.c b/sound/soc/codecs/wm_adsp.c
index f6642c1..9b7c03c 100644
--- a/sound/soc/codecs/wm_adsp.c
+++ b/sound/soc/codecs/wm_adsp.c
@@ -121,6 +121,11 @@
 #define ADSP2_WDMA_CONFIG_2 0x31
 #define ADSP2_RDMA_CONFIG_1 0x34
 
+#define ADSP2_SCRATCH0        0x40
+#define ADSP2_SCRATCH1        0x41
+#define ADSP2_SCRATCH2        0x42
+#define ADSP2_SCRATCH3        0x43
+
 /*
  * ADSP2 Control
  */
@@ -1880,6 +1885,7 @@ int wm_adsp2_event(struct snd_soc_dapm_widget *w,
 	struct wm_adsp *dsp = &dsps[w->shift];
 	struct wm_adsp_alg_region *alg_region;
 	struct wm_coeff_ctl *ctl;
+	unsigned int scratch1 = 0xFFFFFFFF;
 	int ret;
 
 	switch (event) {
@@ -1898,6 +1904,12 @@ int wm_adsp2_event(struct snd_soc_dapm_widget *w,
 		break;
 
 	case SND_SOC_DAPM_PRE_PMD:
+		/* Capture DSP_SCRATCH1, it can be useful for analysis */
+		ret = regmap_read(dsp->regmap, dsp->base + ADSP2_SCRATCH1,
+				  &scratch1);
+		if (ret)
+			adsp_err(dsp, "Failed to read SCRATCH1 %d\n", ret);
+
 		dsp->running = false;
 
 		regmap_update_bits(dsp->regmap, dsp->base + ADSP2_CONTROL,
@@ -1935,7 +1947,7 @@ int wm_adsp2_event(struct snd_soc_dapm_widget *w,
 			kfree(alg_region);
 		}
 
-		adsp_dbg(dsp, "Shutdown complete\n");
+		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);
 		break;
 
 	default:
-- 
1.7.2.5

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Mark Brown]

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

On Thu, May 28, 2015 at 02:45:14PM +0100, Richard Fitzgerald wrote:

> +#define ADSP2_SCRATCH0        0x40
> +#define ADSP2_SCRATCH1        0x41
> +#define ADSP2_SCRATCH2        0x42
> +#define ADSP2_SCRATCH3        0x43

May as well dump the other scratches while you're at it?

> +	unsigned int scratch1 = 0xFFFFFFFF;

Why is this being initialized?

> -		adsp_dbg(dsp, "Shutdown complete\n");
> +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);

That seems a bit loud for a diagnostic message, why raise the severity?

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Mark Brown]

[-- Attachment #1.1: Type: text/plain, Size: 539 bytes --]

On Thu, May 28, 2015 at 02:45:14PM +0100, Richard Fitzgerald wrote:

> +#define ADSP2_SCRATCH0        0x40
> +#define ADSP2_SCRATCH1        0x41
> +#define ADSP2_SCRATCH2        0x42
> +#define ADSP2_SCRATCH3        0x43

May as well dump the other scratches while you're at it?

> +	unsigned int scratch1 = 0xFFFFFFFF;

Why is this being initialized?

> -		adsp_dbg(dsp, "Shutdown complete\n");
> +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);

That seems a bit loud for a diagnostic message, why raise the severity?

[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Richard Fitzgerald]

On Thu, May 28, 2015 at 02:57:51PM +0100, Mark Brown wrote:
> On Thu, May 28, 2015 at 02:45:14PM +0100, Richard Fitzgerald wrote:
> 
> > +#define ADSP2_SCRATCH0        0x40
> > +#define ADSP2_SCRATCH1        0x41
> > +#define ADSP2_SCRATCH2        0x42
> > +#define ADSP2_SCRATCH3        0x43
> 
> May as well dump the other scratches while you're at it?
> 

Fair enough

> > +	unsigned int scratch1 = 0xFFFFFFFF;
> 
> Why is this being initialized?
> 

It was done a way to avoid having two shutdown messages to cover
the rare case that we somehow failed to read the register value, since
the firmware could never write this value (it as 31 bits set).


> > -		adsp_dbg(dsp, "Shutdown complete\n");
> > +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);
> 
> That seems a bit loud for a diagnostic message, why raise the severity?

It's a diagnostic of the firmware, not the driver, and we can't assume that
people trying to use a firmware have the ability to build and flash a kernel
with a debug version of the driver

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Mark Brown]

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

On Thu, May 28, 2015 at 03:24:39PM +0100, Richard Fitzgerald wrote:
> On Thu, May 28, 2015 at 02:57:51PM +0100, Mark Brown wrote:

> > > -		adsp_dbg(dsp, "Shutdown complete\n");
> > > +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);

> > That seems a bit loud for a diagnostic message, why raise the severity?

> It's a diagnostic of the firmware, not the driver, and we can't assume that
> people trying to use a firmware have the ability to build and flash a kernel
> with a debug version of the driver

The default is that dev_dbg() is available in dmesg but not on the
console which usually seems like a reasonable balance for this sort of
thing - it's there if people want it but not included in the default
logging.

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Mark Brown]

[-- Attachment #1.1: Type: text/plain, Size: 741 bytes --]

On Thu, May 28, 2015 at 03:24:39PM +0100, Richard Fitzgerald wrote:
> On Thu, May 28, 2015 at 02:57:51PM +0100, Mark Brown wrote:

> > > -		adsp_dbg(dsp, "Shutdown complete\n");
> > > +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);

> > That seems a bit loud for a diagnostic message, why raise the severity?

> It's a diagnostic of the firmware, not the driver, and we can't assume that
> people trying to use a firmware have the ability to build and flash a kernel
> with a debug version of the driver

The default is that dev_dbg() is available in dmesg but not on the
console which usually seems like a reasonable balance for this sort of
thing - it's there if people want it but not included in the default
logging.

[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Richard Fitzgerald]

On Thu, May 28, 2015 at 03:37:24PM +0100, Mark Brown wrote:
> On Thu, May 28, 2015 at 03:24:39PM +0100, Richard Fitzgerald wrote:
> > On Thu, May 28, 2015 at 02:57:51PM +0100, Mark Brown wrote:
> 
> > > > -		adsp_dbg(dsp, "Shutdown complete\n");
> > > > +		adsp_info(dsp, "Shutdown complete (SCRATCH1:0x%x)\n", scratch1);
> 
> > > That seems a bit loud for a diagnostic message, why raise the severity?
> 
> > It's a diagnostic of the firmware, not the driver, and we can't assume that
> > people trying to use a firmware have the ability to build and flash a kernel
> > with a debug version of the driver
> 
> The default is that dev_dbg() is available in dmesg but not on the
> console which usually seems like a reasonable balance for this sort of
> thing - it's there if people want it but not included in the default
> logging.

What you're describing seems to be the default for dev_info().
For me I don't get any dev_dbg() output in the dmesg log unless the source
file has a #define DEBUG at the top.

Re: [PATCH] ASoC: wm_adsp: Dump DSP_SCRATCH1 on DSP shutdown

[Mark Brown]

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

On Thu, May 28, 2015 at 05:13:13PM +0100, Richard Fitzgerald wrote:
> On Thu, May 28, 2015 at 03:37:24PM +0100, Mark Brown wrote:

> > The default is that dev_dbg() is available in dmesg but not on the
> > console which usually seems like a reasonable balance for this sort of
> > thing - it's there if people want it but not included in the default
> > logging.

> What you're describing seems to be the default for dev_info().
> For me I don't get any dev_dbg() output in the dmesg log unless the source
> file has a #define DEBUG at the top.

Interesting...  the dev_dbg default appears to have been changed at some
point, possibly with the addition of dynamic debug (which I tend to have
on in my configurations and is common for distros and so on).  The info
default is overridden by a lot of distros.  In any case, it's still the
way we generally do debug - doing this on every DSP stop does seem quite
chatty from a system point of view (and yes, some of the existing
logging in the driver does seem a bit enthusiastic here too in
retrospect, IIRC at the time request_firmware() was chatty too but that
has been fixed).

Users will typically have the option to get this via ftrace as well (we
have trace points for register read), and you might also want to
consider the option of exporting the value via a sysfs file so people
can grab the latest value whenever they like.

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 473 bytes --]