On Fri, 2017-10-13 at 11:13 -0500, Pierre-Louis Bossart wrote:

On 10/12/2017 03:35 AM, yan.wang@linux.intel.com wrote:

...

From: Yan Wang yan.wang@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);

}

Pierre, can you try this, it's only compile tested as it's late.

From 12c3df326c313b20f85622bcaef9b936908be9df Mon Sep 17 00:00:00 2001

From: Liam Girdwood liam.r.girdwood@linux.intel.com Date: Fri, 13 Oct 2017 23:16:52 +0100 Subject: [PATCH] trace: dma: Fix locking and buffer wraps on DMA trace

DMA trace must be run from a work context and not from any atomic context as it waits on DMA completion IRQs.

Check the host and local buffers for wrap.

Signed-off-by: Liam Girdwood liam.r.girdwood@linux.intel.com --- src/audio/dma-trace.c | 93 ++++++++++++++++++++++++++++---------- src/include/reef/audio/dma-trace.h | 2 + src/lib/trace.c | 9 +--- 3 files changed, 72 insertions(+), 32 deletions(-)

diff --git a/src/audio/dma-trace.c b/src/audio/dma-trace.c index 123853c..00a29b4 100644 --- a/src/audio/dma-trace.c +++ b/src/audio/dma-trace.c @@ -66,6 +66,7 @@ static int dma_trace_new_buffer(struct dma_trace_data *d, uint32_t buffer_size) buffer->size = buffer_size; buffer->w_ptr = buffer->r_ptr = buffer->addr; buffer->end_addr = buffer->addr + buffer->size; + buffer->avail = 0;

return 0; } @@ -74,25 +75,61 @@ static void trace_send(struct dma_trace_data *d) { struct dma_trace_buf *buffer = &d->dmatb; struct dma_sg_config *config = &d->config; - uint32_t size = 0; + unsigned long flags; int32_t offset = 0; - - if (buffer->w_ptr == buffer->r_ptr) + uint32_t avail = buffer->avail; + uint32_t bytes_copied = avail; + uint32_t size; + uint32_t hsize; + uint32_t lsize; + + /* any data to copy ? */ + if (avail == 0) return;

- size = buffer->w_ptr - buffer->r_ptr; - if (d->host_offset + size > d->host_size) - d->host_offset = 0; + /* copy to host in sections if we wrap */ + while (avail > 0) {

- offset = dma_copy_to_host(config, d->host_offset, - buffer->r_ptr, size); - if (offset < 0) { - trace_buffer_error("ebb"); - return; + lsize = hsize = avail; + + /* host buffer wrap ? */ + if (d->host_offset + buffer->avail > d->host_size) + hsize = d->host_offset + buffer->avail - d->host_size; + + /* local buffer wrap ? */ + if (buffer->r_ptr > buffer->w_ptr) + lsize = buffer->end_addr - buffer->r_ptr; + + /* get smallest size */ + if (hsize < lsize) + size = hsize; + else + size = lsize; + + /* copy this section to host */ + offset = dma_copy_to_host(config, d->host_offset, + buffer->r_ptr, size); + if (offset < 0) { + trace_buffer_error("ebb"); + return; + } + + /* update host pointer and check for wrap */ + d->host_offset += size; + if (d->host_offset + size >= d->host_size) + d->host_offset = 0; + + /* update local pointer and check for wrap */ + buffer->r_ptr += size; + if (buffer->r_ptr >= buffer->end_addr) + buffer->r_ptr = buffer->addr; + + avail -= size; }

- d->host_offset += size; - buffer->r_ptr += size; + spin_lock_irq(&d->lock, flags); + buffer->avail -= bytes_copied; + spin_unlock_irq(&d->lock, flags); }

static uint64_t trace_work(void *data, uint64_t delay) @@ -125,6 +162,7 @@ int dma_trace_init(struct dma_trace_data *d) trace_data = d;

work_init(&d->dmat_work, trace_work, d, WORK_ASYNC); + spinlock_init(&d->lock); return 0; }

@@ -155,34 +193,39 @@ void dtrace_event(const char *e, uint32_t length) { struct dma_trace_buf *buffer = NULL; int margin = 0; + unsigned long flags;

- if (trace_data == NULL || length < 1) + if (trace_data == NULL || length == 0) return;

buffer = &trace_data->dmatb; if (buffer == NULL) return;

+ spin_lock_irq(&trace_data->lock, flags); + margin = buffer->end_addr - buffer->w_ptr;

+ /* check for buffer wrap */ if (margin > length) { + + /* no wrap */ memcpy(buffer->w_ptr, e, length); buffer->w_ptr += length; } else { - memcpy(buffer->w_ptr, e, margin); - buffer->w_ptr += margin;

- if(trace_data->ready) - trace_send(trace_data); - - buffer->w_ptr = buffer->r_ptr = buffer->addr; - bzero(buffer->addr, buffer->size); + /* data is bigger than remaining margin so we wrap */ + memcpy(buffer->w_ptr, e, margin); + buffer->w_ptr = buffer->addr;

memcpy(buffer->w_ptr, e + margin, length - margin); - buffer->w_ptr += length -margin; + buffer->w_ptr += length - margin; }

- length = buffer->w_ptr - buffer->r_ptr; - if (trace_data->ready && length >= (DMA_TRACE_LOCAL_SIZE / 2)) - trace_send(trace_data); + buffer->avail += length; + spin_unlock_irq(&trace_data->lock, flags); + + /* schedule copy now if buffer > 50% full */ + if (trace_data->ready && buffer->avail >= (DMA_TRACE_LOCAL_SIZE / 2)) + work_reschedule_default(&trace_data->dmat_work, 100); } diff --git a/src/include/reef/audio/dma-trace.h b/src/include/reef/audio/dma-trace.h index 438fd2f..20f2e18 100644 --- a/src/include/reef/audio/dma-trace.h +++ b/src/include/reef/audio/dma-trace.h @@ -49,6 +49,7 @@ struct dma_trace_buf { void *addr; /* buffer base address */ void *end_addr; /* buffer end address */ uint32_t size; /* size of buffer in bytes */ + uint32_t avail; /* avail bytes in buffer */ };

struct dma_trace_data { @@ -58,6 +59,7 @@ struct dma_trace_data { uint32_t host_size; struct work dmat_work; uint32_t ready; + spinlock_t lock; };

int dma_trace_init(struct dma_trace_data *d); diff --git a/src/lib/trace.c b/src/lib/trace.c index ebe2d31..bdd50ae 100644 --- a/src/lib/trace.c +++ b/src/lib/trace.c @@ -60,7 +60,7 @@ void _trace_error(uint32_t event) spin_lock_irq(&trace.lock, flags);

/* write timestamp and event to trace buffer */ - t =(volatile uint64_t*)(MAILBOX_TRACE_BASE + trace.pos); + t = (volatile uint64_t*)(MAILBOX_TRACE_BASE + trace.pos); t[0] = platform_timer_get(platform_timer); t[1] = event;

@@ -69,7 +69,7 @@ void _trace_error(uint32_t event)

trace.pos += (sizeof(uint64_t) << 1);

- if (trace.pos >= MAILBOX_TRACE_SIZE) + if (trace.pos > MAILBOX_TRACE_SIZE - sizeof(uint64_t) * 2) trace.pos = 0;

spin_unlock_irq(&trace.lock, flags); @@ -77,7 +77,6 @@ void _trace_error(uint32_t event)

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

@@ -87,13 +86,9 @@ void _trace_event(uint32_t event) 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)