Repository navigation
[BUG][TGL] Audio Speaker Playback stops sporadically #3732
Description
SOF Fw:
tgl-011-drop-stable
+ Maxim98373 DSM + Hotword enable
Steps to reproduce issue:
a) Hotwording path always ON
b) Start long hour "YouTube Playback" or "local Audio-video" files. i.e. Speaker Playback
c) Audio Speaker playback stops after some time
It is sporadic. Some times stops after hrs, some times in 30min.
d) Issue is able to reproduce in overnight tests (for e.g. 2 / 10 systems)
Note:
When issue happened,
- cat /proc/interrupts | grep audioDSP << is not updating
- localhost ~ # cat /sys/bus/pci/devices/0000:00:1f.3/power/runtime_status
active - if we try to do aplay to headset or HDMI ------ gives IO errors (no errors from kernel)
localhost ~ # aplay -Dhw:0,3 -f dat /dev/zero
Playing raw data '/dev/zero' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
aplay: pcm_write:2059: write error: Input/output error
SOF logs:
-
./sof-logger -l sof-tgl.ldc -t
…..
[648293734.114583] ( 560007.562500) c0 ll-schedule /schedule/timer_domain.c:91 ERROR timer_report_delay(): timer 3 delayed by 3 uS 147 ticks
[648333760.729167] ( 40026.613281) c0 ll-schedule /schedule/timer_domain.c:91 ERROR timer_report_delay(): timer 3 delayed by 13 uS 511 ticks -
./sof-logger -l sof-tgl.ldc
localhost ~ # ./sof-logger -l sof-tgl.ldc
TIMESTAMP DELTA C# COMPONENT LOCATION CONTENT
[138176223460.208344] ( nan) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1542 ERROR dmic_irq_handler(): full fifo B or PDM overrun
[138176223902.552094] ( 442.343750) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1542 ERROR dmic_irq_handler(): full fifo B or PDM overrun
[138176224208.593750] ( 306.041656) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1542 ERROR dmic_irq_handler(): full fifo B or PDM overrun
Activity
lgirdwood commentedon Jan 7, 2021
@sathya-nujella looks like something is stopping FW from scheduling work to empty DMIC FIFOs (via the timer_domain scheduler which is reporting a delay).
Can you confirm if DSM is active during this test ? If so, does the test still fail if DSM disabled ?
This error can be caused by too much "high priority" work within the DSP (i.e. higher or similar level as the scheduler timer domain). e.g. This could be an IRQ or timer scheduling other work....
mwasko commentedon Jan 7, 2021
@sathya-nujella can you confirm whether "dmic_irq_handler(): full fifo B or PDM" is present in the SOF logs after youtube playback stop but before the aplay to headse or HDMI?
We should probably focus first on why the playback stopped and what lead to that. The other errors after aplay to headset or HDMI are separate issues that are probably result of playback stop.
Is the hotword triggered during the long hour playback?
sathya-nujella commentedon Jan 10, 2021
DSM is active during the test (speaker playback stream has Maxim-98373 DSM enabled)
sathya-nujella commentedon Jan 10, 2021
Yes, speaker playback stopped is the main/critical issue.
2)
Hotword is not triggered during the playback. Just before playback, it has just started to keep "WoV" path ON.
3)
Because long hour playback test,
we are not able to clearly tell whether "speaker playback stopped first" or "DMIC FIFO overrun errors" coming first.
sathya-nujella commentedon Jan 10, 2021
Sent the SOF dma trace and etrace logs in email as it involves 3rd party modules.
From SOF etrace:
..
[3188835201.093750] ( 3040024.000000) c0 ll-schedule /schedule/timer_domain.c:91 ERROR timer_report_delay(): timer 3 delayed by 12 uS 463 ticks
[3193475228.593750] ( 4640027.500000) c0 ll-schedule /schedule/timer_domain.c:91 ERROR timer_report_delay(): timer 3 delayed by 13 uS 529 ticks
[3195275507.916667] ( 1800279.375000) c0 dmic-dai 2.0 src/drivers/intel/dmic.c:1542 ERROR dmic_irq_handler(): full fifo B or PDM overrun
keyonjie commentedon Jan 11, 2021
Good that you reproduce it with dmic_stop at xrun, can you attach dmesg of this also?
sathya-nujella commentedon Jan 11, 2021
If we enable all kernel and sof debug logs, issue was not reproducing.. so did not enable sof kernel audio driver prints.
When issue happen, there are no audio errors in dmesg.
Only changed this / Firmware built with:
a) Error & warning prints only
b) Enabled this print “perf comp_copy peak plat”
c) Added dmic_stop() in dmic_irq_handler()
5 remaining items
lgirdwood commentedon Jan 22, 2021
@cujomalainey fyi - I've also added debug and testing PRs to this issue for visibility.
cujomalainey commentedon Jan 22, 2021
Thanks, been tracking this internally, @sathya-nujella gabe me a great explanation yesterday
lgirdwood commentedon Jan 29, 2021
@sathya-nujella sorry, it looked like an automatic close based on a PR being merged (even though some PRs are still unmerged).
slawblauciak commentedon Feb 9, 2021
Issue not reproduced after more than 12 hours of testing with the supplied fixes (merged on tgl-011-drop-stable branch):
6fa7e0e
4271a0d
lgirdwood commentedon Feb 9, 2021
@slawblauciak when will you have the 2 PRs ready for master ?
slawblauciak commentedon Feb 9, 2021
@lgirdwood the margin change is already on master (done by you), the other change is already here: #3828
lgirdwood commentedon Feb 9, 2021
@slawblauciak thanks, btw #3828 was failing a CI test. Looks unrelated.
cujomalainey commentedon Feb 9, 2021
I will run tests today with those patches
slawblauciak commentedon Feb 18, 2021
All the fixes have been merged to https://github.com/thesofproject/sof/commits/tgl-011-drop-stable
They've cleared 2 test runs so far, currently running last, 3rd one.
This issue is caused by multiple erroneous conditions taking place:
Both have been addressed by fixes merged on the branch.
The previous, temporary changes have been reverted (one of which caused a regression #3823).
In their place, the final changes applied are timer margins and LL scheduler rework to address incorrect scheduling.
slawblauciak commentedon Feb 26, 2021
Issue resolved on tgl-011 branch, waiting for #3768 to be merged to master.