Repository navigation
[BUG] [TGL] XRUN on speaker/headset path with the IGO integrated firmware while starting the PCM99 capture #4418
Description
Describe the bug
With the IGO integrated firmware and topology, XRUN is observed in the playback pipeline, be it headset/the speaker path with DSM module.
To Reproduce
Start playback on one terminal(speaker with DSM or the headset pipeline)
localhost ~ # aplay -Dhw:0,0 Titanium_low1.wav -c2 -r48000 -fs24_le
start capture on other terminal:
localhost ~ # arecord -Dhw:0,99 try.wav -c4 -r48000 -fs32_le -d60 &
The moment the capture stream is opened
Playback returns I/O error:
aplay: pcm_write:2059: write error: Input/output error
Reproduction Rate
Always.
Very easy to repro.
Expected behavior
playback is on core 0 and IGO module runs on core 1.
The moment capture stream is started the playback on core 0 stalls.
Is it that core 0 is blocked here?
Impact
blocker for IGO integration
Environment
Tgl_13release + private patches in google repo+ Intelligo module(
have shared all the binaries through email as they are closed source.
Please let me know if you need more details.
Screenshots or console output
localhost ~ # ./sof-logger -l sof-tgl.ldc
TIMESTAMP (us) DELTA C# COMPONENT LOCATION CONTENT ktime=75.835s @ 2021-06-21 18:39:54 -0700 PDT
[ 105098936.344577] ( 0.000000) c0 dma-trace src/trace/dma-trace.c:335 ERROR FW ABI 0x3012001 DBG ABI 0x5003000 tag v1.8-rc2-45-gd143acb3ece8 src hash 0x38d78a96 (ldc hash 0x38d78a96)
[ 20826327.349519] ( 20826328.000000) c0 dw-dma src/drivers/dw/dma.c:1100 ERROR dw_dma_get_data_size(): xrun detected
[ 20826344.641185] ( 17.291666) c0 dai 1.5 src/audio/dai.c:1069 ERROR dai_report_xrun(): underrun due to no data available
[ 20826361.984935] ( 17.343750) c0 dai 1.5 src/audio/dai.c:686 ERROR comp_underrun(): dev->comp.id = 5, source->avail = 384, copy_bytes = 0
[ 20826481.412013] ( 119.427078) c0 pipe 1.6 ....../pipeline-stream.c:168 ERROR pipeline_copy(): ret = -61, start->comp.id = 5, dir = 1
[ 20826500.422429] ( 19.010416) c0 pipe 1.6 ..../pipeline-schedule.c:63 ERROR pipeline_task(): xrun recover failed! pipeline will be stopped!
Activity
slawblauciak commentedon Jun 29, 2021
Here are my observations:
I was successfully able to reproduce the issue. At the point of problem occurring (I/O error in aplay) I could see an xrun in the FW trace logs, followed by a constant flow of warnings from the system agent, which shows a consistent problem in the DSP core taking too long to process.
[ 11611479.642768] ( 31989.634766) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 370857I can get the same warnings to appear without aplay, just arecord running.
@RDharageswari
Reading the logs, it appears the period for this pipeline is 16 ms. Is that correct?
Performance counters show that the IGO component takes upwards of 3.8M cycles to complete a copy. Now, if one would assume that each instruction takes exactly one cycle, that'd make it 9.5 ms, which is well below 16 ms. The problem is that very assumption however, since various instructions take different amounts of cycles to complete and it all depends on the state of the DSP pipeline.
If we were to assume 1.5 cycles per instruction, that's already over 14 ms.
This finding in conjunction with the agent constantly complaining every other period reinforces my suspicion that the IGO simply takes too long to complete, as a result making the DSP core unable to respond to various events properly, such as IDC communication, which in turn causes other cores trying to communicate with it to stall, in the end, manifesting itself as this xrun.
I will continue debugging this, to ensure that the initial measurements are correct, this time using alternative method.
fuyuntsuo commentedon Jun 30, 2021
Thanks @slawblauciak . Your observation is correct that IGO component takes about 9.5 ms to complete. That's why we moved it to Core 1 (c32a0e0) so that other components and IDC shouldn't be affected by IGO's long computing time. We just don't understand why IDC (on Core 0) still complains and why smart-amp (on Core 0) turns out to be xrun even in this case.
Here is a information might help. Before moving IGO to Core 1, we used to extend smart-amp period to 16ms (7769778), prolonging buffer so that no xrun occurs. Now since IGO is running on Core 1, there should be no need to apply such patch.
To my surprise, this patch is still working after IGO moved to Core 1.
I am working on integrating IGO component on SOF. Please ping me if needed. Thanks.
fuyuntsuo commentedon Jun 30, 2021
Another question: does the performance counter count cycle or instruction? If cycle then 3.5M cycles should be okay. If instruction, then cycle-per-instruction does matter as you pointed out.
keyonjie commentedon Jun 30, 2021
@fuyuntsuo it's big information that the IGO component takes about 9.5 ms to complete each iteration, this will for sure blocks other tasks (e.g. 1ms SA task) regular runs.
ranj063 commentedon Jun 30, 2021
@keyonjie SA is disabled in the chrome prpducts.
keyonjie commentedon Jun 30, 2021
Okay, I see that from @slawblauciak 's comment:
Anyway, we still have bunch of pipelines scheduled in 1ms period.
@fuyuntsuo how could it happen to takes 9.5ms for each IGO .copy()? it's ~40 times of DSM or GHD!
fuyuntsuo commentedon Jun 30, 2021
Hi @keyonjie, let's make this assumption here if the answer is not blocking this issue. We could discuss why IGO takes much cycles via email since Intel has signed NDA with us. Can anyone from Intel bridge us?
fuyuntsuo commentedon Jun 30, 2021
May I know what does SA stand for? And why it is affected given IGO is running on Core 1.
ranj063 commentedon Jun 30, 2021
@fuyuntsuo SA is the system agent. It is not enabled in the chrome product FW. So its not a concern
53 remaining items
keyonjie commentedon Aug 16, 2021
@fuyuntsuo @lgirdwood the draft PR with the W/A here: #4640
fuyuntsuo commentedon Aug 16, 2021
Hi @keyonjie @lgirdwood , I've tested it at my end and the XRUN doesn't occur anymore. Thank you both.
Apologize for being pushy on this issue, whose root cause is totally beyond my expectation. Hopefully we could close all the other issues with help of this W/A.
keyonjie commentedon Aug 17, 2021
@fuyuntsuo good that it fix the issue at your end.
Yep, the root cause of the issue looks so interesting, we will not stop here, we need to go forward and pursue an explicit explanation of it.
lgirdwood commentedon Aug 17, 2021
@fuyuntsuo @keyonjie thanks, good effort from everyone, sometimes the reasons are not obvious at the beginning but I'm glad we have resolved it.
keyonjie commentedon Aug 17, 2021
Hi @fuyuntsuo the PR is simplified and now looks much easier for us, can you help to verify if the new version work for you?
fuyuntsuo commentedon Aug 17, 2021
@keyonjie this version works too. I also raise a question there.
lgirdwood commentedon Aug 17, 2021
@RDharageswari can you arrange the full validation so we can close. Thanks !
keyonjie commentedon Aug 20, 2021
@fuyuntsuo @lancedkhou I have just updated the PR #4640 , could you please help to check if it work at your end?
lancedkhou commentedon Aug 20, 2021
Hi @keyonjie,
Though I can reproduce the panic, however, both headset and internal MIC are still working.
The voice is still coming from both headset and internal MIC and I can hear the remote sound loud and clear.
lancedkhou commentedon Aug 20, 2021
linux-messages.txt
sof-dump-dsp-panic.txt
mengdonglin commentedon Jan 25, 2022
Set it to P3 as with PR #4640, no impact on user experience.
mengdonglin commentedon Jan 25, 2022
@lancedkhou Close this issue. Please create a new issue to track remaining problem if need.