From 8b616863bd08049da5f82b4dacff955326c4a08d Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Tue, 14 Sep 2021 04:57:10 +0000 Subject: [PATCH 1/3] alloc.c: fix DEBUG_TRACE_PTR() not to trace before trace is initialized As reported in #4759, #4636 and a few others linked from there. Signed-off-by: Marc Herbert --- src/lib/alloc.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/lib/alloc.c b/src/lib/alloc.c index b7de858c0fb6..ce340a1b471d 100644 --- a/src/lib/alloc.c +++ b/src/lib/alloc.c @@ -646,13 +646,13 @@ static void alloc_trace_heap(enum mem_zone zone, uint32_t caps, size_t bytes) } #define DEBUG_TRACE_PTR(ptr, bytes, zone, caps, flags) \ - do { \ + if (trace_get()) { \ if (!ptr) { \ tr_err(&mem_tr, "failed to alloc 0x%x bytes zone 0x%x caps 0x%x flags 0x%x", \ bytes, zone, caps, flags); \ alloc_trace_heap(zone, caps, bytes); \ - } \ - } while (0) + } + #else #define DEBUG_TRACE_PTR(ptr, bytes, zone, caps, flags) #endif From 583f85251c5d4769986feba33ec4a6b1d709a0ae Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Mon, 13 Sep 2021 22:22:02 +0000 Subject: [PATCH 2/3] Revert "trace: enable trace after it is ready" This reverts commit 7df367451d0fa638b530c1c92f02d645845dbe53. This restores the ability to use CONFIG_TRACEM (copy everything to mailbox) without crashing, in other words it fixes #4699 This also fixes the other DSP panic #4676 and removes the need for logical changes in #4678, which can be reverted too. commit 7df367451d0f ("trace: enable trace after it is ready") was meant to fix a crash when tr_xxx() was used early. However I've used very early tracing for months and it never caused any crash (see #4334) I tried adding a tr_err() statement immediately after trace_init(sof) in primary_core_init() and it works just fine. primary_core_init() runs extremely early so I don't think it's too demanding not to use an tr_XXX() before the trace even exists. The reverted commits confused initializing and enabling. Reproduction #4683 did not seem to demonstrate anything obvious, there's not even a link to a failed test run. I don't understand how playing with spin locks is relevant to this. Later, reproduction #4759 finally demonstrated the real issue: through DEBUG_TRACE_PTR(), some tr_XXX() can indeed be called (in very unusal debug circumstances specific to the original author) before the trace is initialized. The previous commit in this series fixes that by simply guarding it with if(trace_get()) -------- I am _not_ pretending that these reverts make the tracing code bug-free and perfect again, absolutely not and very far from it. I'm merely saying that: - The first reverted commit caused at least two regressions: #4676 and #4699 - These two commits added yet another variable (time) in an already complex situation with an already existing combinatorial "explosion": compile-time Kconfigs, run-time settings, platform-specific bugs (#4333, #4573, ...), various races, mbox + DMA, different DMA engines, Zephyr vs XTOS, etc. - Last but not least, we don't want to invest in making the exist trace implementation better. We want to switch to the Zephyr implementation instead So let's go back to a previous known good state, I mean _relatively_ good and stay there if we can. Signed-off-by: Marc Herbert --- src/init/init.c | 5 ++--- src/trace/dma-trace.c | 1 + src/trace/trace.c | 4 +++- 3 files changed, 6 insertions(+), 4 deletions(-) diff --git a/src/init/init.c b/src/init/init.c index cef4bfa64e38..eb379746129f 100644 --- a/src/init/init.c +++ b/src/init/init.c @@ -134,8 +134,10 @@ static int primary_core_init(int argc, char *argv[], struct sof *sof) interrupt_init(sof); #endif /* __ZEPHYR__ */ +#if CONFIG_TRACE trace_point(TRACE_BOOT_SYS_TRACES); trace_init(sof); +#endif trace_point(TRACE_BOOT_SYS_NOTIFIER); init_system_notify(sof); @@ -149,9 +151,6 @@ static int primary_core_init(int argc, char *argv[], struct sof *sof) trace_point(TRACE_BOOT_PLATFORM); - /* now start the trace */ - trace_on(); - #if CONFIG_NO_SECONDARY_CORE_ROM lp_sram_unpack(); #endif diff --git a/src/trace/dma-trace.c b/src/trace/dma-trace.c index 779480e49468..3c5bbdfb10a8 100644 --- a/src/trace/dma-trace.c +++ b/src/trace/dma-trace.c @@ -200,6 +200,7 @@ int dma_trace_init_complete(struct dma_trace_data *d) SOF_TASK_PRI_MED, trace_work, d, 0, 0); out: + return ret; } diff --git a/src/trace/trace.c b/src/trace/trace.c index fb21dc5ce229..866ff0af4ec3 100644 --- a/src/trace/trace.c +++ b/src/trace/trace.c @@ -289,8 +289,9 @@ void trace_log_filtered(bool send_atomic, const void *log_entry, const struct tr uint64_t current_ts; #endif /* CONFIG_TRACE_FILTERING_ADAPTIVE */ - if (!trace || !trace->enable) + if (!trace->enable) { return; + } #if CONFIG_TRACE_FILTERING_VERBOSITY if (!trace_filter_verbosity(lvl, ctx)) @@ -510,6 +511,7 @@ void trace_off(void) void trace_init(struct sof *sof) { sof->trace = rzalloc(SOF_MEM_ZONE_SYS_SHARED, 0, SOF_MEM_CAPS_RAM, sizeof(*sof->trace)); + sof->trace->enable = 1; sof->trace->pos = 0; #if CONFIG_TRACE_FILTERING_ADAPTIVE sof->trace->user_filter_override = false; From 878bd7fadd88decf6e9f1712ff0ee55266788c5d Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Mon, 13 Sep 2021 21:00:00 +0000 Subject: [PATCH 3/3] Revert "dma-trace: add check to avoid dereference from NULL" This reverts commit 89ec377cb55de04270dd6fa2bd8672c3dea3e83d. As commit 7df367451d0f ("trace: enable trace after it is ready") is reverted this is not required anymore. See long previous commit message. Signed-off-by: Marc Herbert --- src/ipc/dma-copy.c | 8 -------- src/platform/intel/cavs/platform.c | 4 +--- src/trace/dma-trace.c | 6 ++++-- src/trace/trace.c | 3 ++- 4 files changed, 7 insertions(+), 14 deletions(-) diff --git a/src/ipc/dma-copy.c b/src/ipc/dma-copy.c index fd2730f732a1..ac2ecc345f48 100644 --- a/src/ipc/dma-copy.c +++ b/src/ipc/dma-copy.c @@ -64,10 +64,6 @@ int dma_copy_to_host_nowait(struct dma_copy *dc, struct dma_sg_config *host_sg, { int ret; - /* return if DMA channel is not get yet */ - if (!dc->chan) - return -EINVAL; - /* tell gateway to copy */ ret = dma_copy(dc->chan, size, 0); if (ret < 0) @@ -89,10 +85,6 @@ int dma_copy_to_host_nowait(struct dma_copy *dc, struct dma_sg_config *host_sg, int32_t err; int32_t offset = host_offset; - /* return if DMA channel is not get yet */ - if (!dc->chan) - return -EINVAL; - if (size <= 0) return 0; diff --git a/src/platform/intel/cavs/platform.c b/src/platform/intel/cavs/platform.c index 3d7db4b2b5f2..66093ac2ab43 100644 --- a/src/platform/intel/cavs/platform.c +++ b/src/platform/intel/cavs/platform.c @@ -524,9 +524,7 @@ int platform_init(struct sof *sof) #elif CONFIG_TRACE /* Initialize DMA for Trace*/ trace_point(TRACE_BOOT_PLATFORM_DMA_TRACE); - ret = dma_trace_init_complete(sof->dmat); - if (ret < 0) - return ret; + dma_trace_init_complete(sof->dmat); #endif /* show heap status */ diff --git a/src/trace/dma-trace.c b/src/trace/dma-trace.c index 3c5bbdfb10a8..d113443f282e 100644 --- a/src/trace/dma-trace.c +++ b/src/trace/dma-trace.c @@ -477,8 +477,9 @@ void dma_trace_on(void) { struct dma_trace_data *trace_data = dma_trace_data_get(); - if (!trace_data || trace_data->enabled) + if (trace_data->enabled) { return; + } trace_data->enabled = 1; schedule_task(&trace_data->dmat_work, DMA_TRACE_PERIOD, @@ -490,8 +491,9 @@ void dma_trace_off(void) { struct dma_trace_data *trace_data = dma_trace_data_get(); - if (!trace_data || !trace_data->enabled) + if (!trace_data->enabled) { return; + } schedule_task_cancel(&trace_data->dmat_work); trace_data->enabled = 0; diff --git a/src/trace/trace.c b/src/trace/trace.c index 866ff0af4ec3..f31fb3a1c3e8 100644 --- a/src/trace/trace.c +++ b/src/trace/trace.c @@ -272,8 +272,9 @@ void trace_log_unfiltered(bool send_atomic, const void *log_entry, const struct struct trace *trace = trace_get(); va_list vl; - if (!trace || !trace->enable) + if (!trace->enable) { return; + } va_start(vl, arg_count); vatrace_log(send_atomic, (uint32_t)log_entry, ctx, lvl, id_1, id_2, arg_count, vl);