dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue #5329

jsarha · 2022-02-08T16:05:58Z

The first commit should be the the only one needed to fix #5120 .
The second commit should make sure the same problem does not bite us again. The third commit is pretty much optional, but I think the fix is correct and it is also cleaning up the code a bit.

src/trace/dma-trace.c

src/include/sof/lib/dma.h

kv2019i

The first one needs to be made platform-specific, but otherwise look good and test results show this is fixing #5120 which has been causing a lot of CI/validation pain.

src/trace/dma-trace.c

src/include/sof/lib/dma.h

src/trace/dma-trace.c

Force DMA buffer to be correctly aligned. If the buffer is only 64-byte aligned, when using hda-dma, then the last 64-bytes of the DMA buffer is not transferred correctly to host side. Signed-off-by: Jyri Sarha <jyri.sarha@intel.com>

Add check for DMA buffer address alignment to hda_dma_set_config(). Wrongly aligned DMA buffer does not work correctly. Signed-off-by: Jyri Sarha <jyri.sarha@intel.com>

It is possible that that in trace_work() sof_ipc_dma_trace_posn ipc message reaches host side sof driver before the dma_copy_to_host_nowait() is finished. Change the dma_copy_to_host_nowait() implementation to dma_copy_to_host() by adding DMA_COPY_BLOCKING flag to dma_copy() command. The flag is already there on the !defined(CONFIG_DMA_GW) version of the function and the old name of the function was a bit misleading. This commit changes also probe.c probe_task() so that it also uses the new blocking DMA copy. I could not see any justification to use nowait version there either. Signed-off-by: Jyri Sarha <jyri.sarha@intel.com>

andyross

Seems very reasonable from my perspective. @teburd will want to note this behavior for the Zephyr driver too. In Zephyrese that would probably be expressed as an assertion in the driver where it picks up the buffer pointers I guess, though a soft error isn't impossible (not sure if there's a return code where needed in our DMA API).

So... do we get to claim that Zephyr saw this problem more severely because its allocator is more fragmentation-resistant and thus more likely to produce a misaligned output buffer? It pleases me to think that, anyway.

teburd · 2022-02-09T20:06:47Z

Seems very reasonable from my perspective. @teburd will want to note this behavior for the Zephyr driver too. In Zephyrese that would probably be expressed as an assertion in the driver where it picks up the buffer pointers I guess, though a soft error isn't impossible (not sure if there's a return code where needed in our DMA API).

So... do we get to claim that Zephyr saw this problem more severely because its allocator is more fragmentation-resistant and thus more likely to produce a misaligned output buffer? It pleases me to think that, anyway.

Yes, I had this in mind and had an assertion on alignment in fact in a first pass as I noted the alignment mentioned in the docs, before I got sucked into a rabbit hole of getting a test working.

marc-hb · 2022-02-10T07:05:09Z

This is fascinating: the bug disappeared in the latest daily test run without merging this PR. The bug saw the PR, got scared and ran away. It's magic.

In daily run ID 10012 on Feb 7th, the DMA corruption impacted TGLU_UP_HDA_ZEPHYR and TGLH_RVP_NOCODEC_ZEPHYR massively. Most tests were failing and even the ones that passed (e.g.: check-playback-all-formats on TGLH_RVP_NOCODEC_ZEPHYR) were still showing this error at an extremely regular interval:

error: log_entry_address      0x6b0 is not in dictionary range!
warn: Seeking forward 4 bytes at a time until re-synchronize.

Start Time: 2022-02-07 22:27:29 UTC
Kernel Branch: topic/sof-dev
Kernel Commit:  03175849
SOF Branch: main
SOF Commit: 99b4bdffd279
Zephyr Commit: b374dc6a7fd8

Now moving 2 days later to daily run ID 10079, the DMA corruption is gone. There are still a couple failures including some sof-logger failures but much much fewer and they all look different. I searched all the logs of all the tests across all platforms and now only some CML platforms show the log_entry_address error above. It's never in any Zephyr test.

Start Time: 2022-02-09 22:27:36 UTC
Kernel Branch: topic/sof-dev
Kernel Commit: 8bf95cb0
SOF Branch: main
SOF Commit: 9983ab67a9fe
Zephyr Commit: 41a63f48fdc8

marc-hb · 2022-02-10T07:19:50Z

I cherry-picked this PR on top of the current a61ff1f and I can still reproduce the issue instantly with Zephyr 2f5976d674ff, my APL UP2 and sof-logger "hardening" #5340 (as a system configuration sanity check, XTOS is fine with the exact same SOF git commit)

jsarha · 2022-02-10T07:34:33Z

XTOS works just by change, or actually because of its different heap implementation. If one enforces the DMA buffer to be only 64-byte aligned but not 128-byte aligned (the way it usually is in the Zephyr version), the xtos version fails as miserably as Zephyr.

marc-hb · 2022-02-10T07:41:41Z

My main point was: this PR does not fix the issue at all in my (Zephyr) configuration.

I'm testing different Zephyr versions now.

EDIT: I combined this PR with all the SOF and Zephyr commits used by the daily runs references above. In every combination the sof-logger prints error: log_entry_address 0x.... is not in dictionary range! like clockwork.

This is with kernel 920d034ba4f2 in case that matters. I don't have any TGL device at home.

jsarha · 2022-02-10T10:08:43Z

I tried to put together a branch with all the mentioned pieces, even used the same linux hash, and tested that on my TGL board, but can not reproduce the problem. @marc-hb could you share exact branches and tests you run so I could try again? Also (a remote) access to same piece of HW could be helpful. My debug hacks here should help in finding out what is still wrong with the dtrace.

kv2019i

Thanks @jsarha , looks good! I think even there are stilll more issues, this seems like a step to the right direction and makes the DMA trace code more robust.

lgirdwood · 2022-02-10T11:56:45Z

Ack - this fixes the HW alignment as mentioned in the spec. We can now focus on why its not working with @marc-hb setup.

marc-hb · 2022-02-10T22:46:02Z

I cherry-picked this PR ...

Apologies, last night I was cherry-picking only the last commit in this PR :-( When cherry-picking the first, alignment commit then then problem does instantly go away in my configuration: from systematic corruption to none. Yesterday was a way too long day.

It's still fascinating that the issue went mostly away even before this PR was merged (involving zero fat finger of mine) but that's not new: we always knew this corruption was "randomly deterministic"!

Thanks a lot @jsarha , you've hopefully just made a huge difference to test results.

jsarha requested review from akloniex, bardliao, marcinszkudlinski, lgirdwood, plbossart, mmaka1, lbetlej and dbaluta as code owners February 8, 2022 16:05

jsarha changed the title ~~Issue 5120 fix~~ dma-trace: Align dma trace buffer correctly, fixes https://github.com/thesofproject/sof/issues/5120 Feb 8, 2022

jsarha changed the title ~~dma-trace: Align dma trace buffer correctly, fixes https://github.com/thesofproject/sof/issues/5120~~ dma-trace: Align dma trace buffer correctly, fixed dtrace issue Feb 8, 2022

jsarha changed the title ~~dma-trace: Align dma trace buffer correctly, fixed dtrace issue~~ dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue Feb 8, 2022

dbaluta reviewed Feb 8, 2022

View reviewed changes

src/trace/dma-trace.c Show resolved Hide resolved

lgirdwood reviewed Feb 9, 2022

View reviewed changes

src/trace/dma-trace.c Show resolved Hide resolved

src/include/sof/lib/dma.h Show resolved Hide resolved

kv2019i requested changes Feb 9, 2022

View reviewed changes

src/trace/dma-trace.c Show resolved Hide resolved

src/include/sof/lib/dma.h Show resolved Hide resolved

jsarha force-pushed the issue-5120-fix branch from 3e51b82 to f37830a Compare February 9, 2022 14:38

dbaluta reviewed Feb 9, 2022

View reviewed changes

src/trace/dma-trace.c Show resolved Hide resolved

lgirdwood added this to the v2.1 milestone Feb 9, 2022

jsarha added 3 commits February 9, 2022 19:26

drivers: Intel: hda-dma: DMA buffer address should be correctly aligned

d2b4056

Add check for DMA buffer address alignment to hda_dma_set_config(). Wrongly aligned DMA buffer does not work correctly. Signed-off-by: Jyri Sarha <jyri.sarha@intel.com>

jsarha force-pushed the issue-5120-fix branch from f37830a to 0f65d69 Compare February 9, 2022 17:39

marc-hb requested a review from andyross February 9, 2022 17:54

dbaluta approved these changes Feb 9, 2022

View reviewed changes

andyross approved these changes Feb 9, 2022

View reviewed changes

teburd approved these changes Feb 9, 2022

View reviewed changes

lgirdwood approved these changes Feb 9, 2022

View reviewed changes

jsarha requested a review from kv2019i February 10, 2022 06:37

marc-hb mentioned this pull request Feb 10, 2022

sof-logger: fail when an invalid address is found in the DMA trace #5340

Closed

kv2019i approved these changes Feb 10, 2022

View reviewed changes

lgirdwood merged commit 443b21d into thesofproject:main Feb 10, 2022

This was referenced Feb 11, 2022

error: log_entry_address 0x___ is not in dictionary range #5345

Closed

Restore early tracing #4334

Closed

This was referenced Feb 21, 2022

[BUG]Empty or stuck DMA trace - Initial FW ABI banner message not found in logger.data.txt #4333

Closed

Revert "dma-trace: Preserve logs while dtrace is disabled" #5410

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue #5329

dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue #5329

jsarha commented Feb 8, 2022

kv2019i left a comment

andyross left a comment

teburd commented Feb 9, 2022 •

edited

Loading

marc-hb commented Feb 10, 2022

marc-hb commented Feb 10, 2022 •

edited

Loading

jsarha commented Feb 10, 2022 •

edited

Loading

marc-hb commented Feb 10, 2022 •

edited

Loading

jsarha commented Feb 10, 2022

kv2019i left a comment

lgirdwood commented Feb 10, 2022

marc-hb commented Feb 10, 2022

dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue #5329

dma-trace: Align dma trace buffer correctly, fixed Zephyr dtrace issue #5329

Conversation

jsarha commented Feb 8, 2022

kv2019i left a comment

Choose a reason for hiding this comment

andyross left a comment

Choose a reason for hiding this comment

teburd commented Feb 9, 2022 • edited Loading

marc-hb commented Feb 10, 2022

marc-hb commented Feb 10, 2022 • edited Loading

jsarha commented Feb 10, 2022 • edited Loading

marc-hb commented Feb 10, 2022 • edited Loading

jsarha commented Feb 10, 2022

kv2019i left a comment

Choose a reason for hiding this comment

lgirdwood commented Feb 10, 2022

marc-hb commented Feb 10, 2022

teburd commented Feb 9, 2022 •

edited

Loading

marc-hb commented Feb 10, 2022 •

edited

Loading

jsarha commented Feb 10, 2022 •

edited

Loading

marc-hb commented Feb 10, 2022 •

edited

Loading