[Sound-open-firmware] [PATCH 2/2] Forward trace event to DMA buffer.

[Pierre-Louis Bossart]

On 10/12/2017 03:35 AM, yan.wang at linux.intel.com wrote:
> From: Yan Wang <yan.wang at linux.intel.com>
>
> 1. Ignore DMA trace event when forwarding for avoiding dead lock
> because DMA tracing uses DMA API to copy trace event.
> 2. Add _trace_error() API to send error event by mail box at the same
> time too when copying error event by DMA.
This patch introduces severe regressions (hw_params, IPC errors) and 
should be reverted until we figure out why it breaks audio playback. 
More validation please...

the program flow is also questionable and needs more attention

void _trace_error(uint32_t event)
{
     unsigned long flags;
     volatile uint32_t *t;

     if (!trace.enable)
         return;

     /* save event to DMA tracing buffer */
     _trace_event(event); <<< this takes a spin_lock and releases it

     /* send event by mail box too. */
     spin_lock_irq(&trace.lock, flags); <<< Here we take the same spin 
lock we just released in _trace_event???
...

void _trace_event(uint32_t event)
{
     unsigned long flags;
     volatile uint64_t dt[2];
     volatile uint32_t et = (event & 0xff000000);

     if (!trace.enable)
         return;

     if (et == TRACE_CLASS_DMA)
         return;

     spin_lock_irq(&trace.lock, flags);
     dt[0] = platform_timer_get(platform_timer);
     dt[1] = event;
     dtrace_event((const char*)dt, sizeof(uint64_t) * 2);

     spin_unlock_irq(&trace.lock, flags);
}

[root at MinnowTurbot ~]# aplay -Dhw:2,0 -c2 -r48000 -f dat 55.pcm
Playing raw data '55.pcm' : Signed 16 bit Little Endian, Rate 48000 Hz, 
Stereo
[root at MinnowTurbot ~]# aplay -Dhw:2,0 -c2 -r48000 -f dat 55.pcm
Playing raw data '55.pcm' : Signed 16 bit Little Endian, Rate 48000 Hz, 
Stereo
aplay: pcm_write:2004: write error: Input/output error
[root at MinnowTurbot ~]# aplay -Dhw:2,0 -c2 -r48000 -f dat 55.pcm
Playing raw data '55.pcm' : Signed 16 bit Little Endian, Rate 48000 Hz, 
Stereo
aplay: set_params:1361: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 32
CHANNELS: 2
RATE: 48000
PERIOD_TIME: 84000
PERIOD_SIZE: 4032
PERIOD_BYTES: 16128
PERIODS: (4 5)
BUFFER_TIME: 340000
BUFFER_SIZE: 16320
BUFFER_BYTES: 65280
TICK_TIME: 0

[   56.324833] sof-audio sof-audio: error: ipc timed out for 0x60050000 
size 0xc

[   62.886941] sof-audio sof-audio: ASoC: sof-audio hw params failed: -110
[   62.886961]  Low Latency: ASoC: hw_params FE failed -110
[   63.190486] sof-audio sof-audio: error: ipc timed out for 0x60030000 
size 0xc

>
> Signed-off-by: Yan Wang <yan.wang at linux.intel.com>
> ---
>   src/include/reef/trace.h |  4 +++-
>   src/lib/trace.c          | 28 +++++++++++++++++++++++++++-
>   2 files changed, 30 insertions(+), 2 deletions(-)
>
> diff --git a/src/include/reef/trace.h b/src/include/reef/trace.h
> index 300e8d8..cdd8158 100644
> --- a/src/include/reef/trace.h
> +++ b/src/include/reef/trace.h
> @@ -94,6 +94,7 @@
>   #define TRACEE	1
>   
>   void _trace_event(uint32_t event);
> +void _trace_error(uint32_t event);
>   void trace_off(void);
>   void trace_init(struct reef * reef);
>   
> @@ -117,7 +118,8 @@ void trace_init(struct reef * reef);
>   
>   /* error tracing */
>   #if TRACEE
> -#define trace_error(__c, __e) trace_event(__c, __e)
> +#define trace_error(__c, __e) \
> +	_trace_error(__c | (__e[0] << 16) | (__e[1] <<8) | __e[2])
>   #else
>   #define trace_error(__c, __e)
>   #endif
> diff --git a/src/lib/trace.c b/src/lib/trace.c
> index 33e1466..b0b32d6 100644
> --- a/src/lib/trace.c
> +++ b/src/lib/trace.c
> @@ -34,6 +34,7 @@
>   #include <arch/cache.h>
>   #include <platform/timer.h>
>   #include <reef/lock.h>
> +#include <reef/audio/dma-trace.h>
>   #include <stdint.h>
>   
>   struct trace {
> @@ -44,7 +45,7 @@ struct trace {
>   
>   static struct trace trace;
>   
> -void _trace_event(uint32_t event)
> +void _trace_error(uint32_t event)
>   {
>   	unsigned long flags;
>   	volatile uint32_t *t;
> @@ -52,6 +53,10 @@ void _trace_event(uint32_t event)
>   	if (!trace.enable)
>   		return;
>   
> +	/* save event to DMA tracing buffer */
> +	_trace_event(event);
> +
> +	/* send event by mail box too. */
>   	spin_lock_irq(&trace.lock, flags);
>   
>   	/* write timestamp and event to trace buffer */
> @@ -70,6 +75,27 @@ void _trace_event(uint32_t event)
>   	spin_unlock_irq(&trace.lock, flags);
>   }
>   
> +void _trace_event(uint32_t event)
> +{
> +	unsigned long flags;
> +	volatile uint64_t dt[2];
> +	volatile uint32_t et = (event & 0xff000000);
> +
> +	if (!trace.enable)
> +		return;
> +
> +	if (et == TRACE_CLASS_DMA)
> +		return;
> +
> +	spin_lock_irq(&trace.lock, flags);
> +
> +	dt[0] = platform_timer_get(platform_timer);
> +	dt[1] = event;
> +	dtrace_event((const char*)dt, sizeof(uint64_t) * 2);
> +
> +	spin_unlock_irq(&trace.lock, flags);
> +}
> +
>   void trace_off(void)
>   {
>   	trace.enable = 0;