[BUG] mtrace dropping log messages

[kv2019i]

Describe the bug
The mtrace logging backend loses log messages in fairly common use-cases. As the backend is based on use of a small SRAM window, it simply cannot handle a large bandwidth of messages, but performance should be sufficient with ERR/WARN/INFO level logs that are currently the default in SOF Zephyr builds.

To Reproduce
~/sof-test/test-case/multiple-pipeline.sh -f p -l 5

Reproduction Rate
Roughly 20% log messages lost in the above multiple-pipeline test.

Expected behavior
<1% lost rate in defaul config

Impact
Makes debugging more difficult using FW logs

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel: sof-dev c693d0caf6fa1b416d08d48eacbb5db96a8fac58
   • SOF: main 880857b
2. Name of the topology file
   • Topology: sof-tgl-nocodec, IPC4 test
3. Name of the platform(s) on which the bug is observed.
   • Platform: TGL cavs2.5

Screenshots or console output

[kv2019i]

FYI to @andrula-song @ranj063 as you've both reported this.

[kv2019i]

With the linked two draft PRs (one to FW and one to kernel), I'm able to get log loss rate below 1% (from 20%) in the multi-pipeline test case. Ideally we could increase the SRAM allocation a bit, but that is out of the cards for the moment.

[lgirdwood]

With the linked two draft PRs (one to FW and one to kernel), I'm able to get log loss rate below 1% (from 20%) in the multi-pipeline test case. Ideally we could increase the SRAM allocation a bit, but that is out of the cards for the moment.

Kconfig option ? we could encode some bits in the IPC flow control messages to warn about missing messages etc....

[kv2019i]

With latest versions, only the FW change #6672 is needed. If this proves to work, I'll close the kernel PR for future use. We might add an opt-in debug mode to kernel to poll the sram window instead of using IPC messages, but for now it seems this is not needed.