Repository navigation
LNL SDW AIOC: controller timeout on bank switch #4823
Description
Intel daily tests
#/result/planresultdetail/37931?model=LNLM_SDW_AIOC&testcase=multiple-pipeline-playback-50
[ 2306.620665] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[ 2309.418584] kernel: soundwire sdw-master-0-0: Controller Timed out on bank switch
[ 2309.418602] kernel: soundwire sdw-master-0-0: multi link bank switch failed: -110
[ 2309.418612] kernel: _sdw_prepare_stream: do_bank_switch failed: -110
[ 2309.418629] kernel: SDW0-Playback: ASoC: error at snd_soc_link_prepare on SDW0-Playback: -110
[ 2309.418636] kernel: SDW0-Playback: ASoC: error at __soc_pcm_prepare on SDW0-Playback: -110
[ 2309.418643] kernel: Deepbuffer Jack Out: ASoC: error at dpcm_be_dai_prepare on Deepbuffer Jack Out: -110
[ 2309.418655] kernel: Deepbuffer Jack Out: ASoC: error at dpcm_fe_dai_prepare on Deepbuffer Jack Out: -110
[ 2309.922501] kernel: soundwire_intel soundwire_intel.link.0: IO transfer timed out, cmd 2 device 6 addr 302 len 1
[ 2309.922565] kernel: soundwire sdw-master-0-0: trf on Slave 6 failed:-110 read addr 302 count 0
[ 2309.922575] kernel: rt711-sdca sdw:0:0:025d:0711:01: DPN_PortCtrl register write failed for port 3
[ 2309.922582] kernel: soundwire sdw-master-0-0: Program transport params failed: -110
[ 2309.922587] kernel: soundwire sdw-master-0-0: Program params failed: -110
[ 2309.922598] kernel: SDW0-Playback: ASoC: error at snd_soc_link_prepare on SDW0-Playback: -110
[ 2309.922605] kernel: SDW0-Playback: ASoC: error at __soc_pcm_prepare on SDW0-Playback: -110
[ 2309.922611] kernel: Jack Out: ASoC: error at dpcm_be_dai_prepare on Jack Out: -110
[ 2309.922623] kernel: Jack Out: ASoC: error at dpcm_fe_dai_prepare on Jack Out: -110
[ 2309.922822] kernel: snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: free stream 31 dir 0
This did not reproduce on the last test, we'd need to check how many times this happened before, if ever.
The trace suggests that we have an alert status during a bank switch, that's a potential red flag or a sign of a race condition.
@bardliao FYI
cc:
Activity
bardliao commentedon Feb 19, 2024
The issue happened on check-suspend-resume-with-playback-5.sh and check-suspend-resume-with-capture-5.sh, too.
plbossart commentedon Feb 20, 2024
Humm, I don't see the link between multiple pipelines and suspend with audio cases. Weird.
bardliao commentedon Feb 20, 2024
@plbossart The issue only happens on devices in JF. Let's wait Fred to upgrade the BIOS to the correct version and check it again.
fredoh9 commentedon Feb 21, 2024
I will flash right BIOS tomorrow morning. Sorry about the delay.
fredoh9 commentedon Feb 21, 2024
I updated the BIOS with same version from SH device. I was able to test twice multiple-pipeline-playback-50 on each device. It looks stable now.
Sorry again, I tested only the sound card enumeration and playback once when I upgraded the latest BIOS.
verify-kernel-boot-log: use dmidecode to print the BIOS version
verify-kernel-boot-log: use dmidecode to print the BIOS version
marc-hb commentedon Feb 21, 2024
BIOS versions printed for all devices thanks to one-line change thesofproject/sof-test#1161, please review.
verify-kernel-boot-log: use dmidecode to print the BIOS version
keqiaozhang commentedon Mar 4, 2024
This issue cannot be reproduced after BIOS upgrade. Closing this bug.
plbossart commentedon Mar 4, 2024
That's good, I had no idea where to start on this one... Thanks @keqiaozhang
marc-hb commentedon May 20, 2024
This re-appeared, see internal issue 566
11 remaining items
bardliao commentedon Jun 5, 2024
I tried to reproduce the issue today. But I can't reproduce it with any test. I run check-playback-3times.sh check-capture-3times.sh check-playback-3rounds.sh check-capture-3rounds.sh check-pause-resume-playback-100.sh check-pause-resume-capture-100.sh so many times on jf-lnlm-rvp-sdw-1, and I can't get a single failure. But it is quite easy to reproduce in a PR test. I started a PR test without any PR applied, and it does report the issue on 5 test cases. That is really interesting.
plbossart commentedon Jun 5, 2024
Does your test platform have the updated BIOS @bardliao ? This issue seems related to either resources or timing handled by the BIOS/IFWI.
bardliao commentedon Jun 5, 2024
I am using the same device as PR test. And the issue happens on both JF and BA's devices.
Edit: CI reported the issue on both JF and BA's devices, but I can't reproduce it by manually run the PR test cases.
plbossart commentedon Jun 6, 2024
Summary as of June 6 16:00 UTC of experiments I started and expanded by @bardliao
It's not clear if the issue is identical to #4943 where interrupts were missed as well, since the problems happen in completely different stages (was during enumeration, here it's during prepare).
@ujfalusi @lgirdwood FYI, if you have suggestions we're all ears.
plbossart commentedon Jun 7, 2024
The last logs show the Controller Timed out error happens when we don't get an interrupt after a write.
https://sof-ci.01.org/linuxpr/PR5042/build3462/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-capture-10sec
bardliao commentedon Jun 7, 2024
Another log
plbossart commentedon Jun 11, 2024
https://sof-ci.01.org/linuxpr/PR5047/build3543/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-signal-stop-start-capture-10
interesting interaction of bank switch not completing and jack detection
bardliao commentedon Jun 13, 2024
It turns out that is related to DSDT provided by BIOS. The new BIOS added 9.6MHz clock rate support on sdw bus. But, we didn't implement corresponding change to fit the 9.6MHz clock rate in kernel yet. The test result of #5059 shows no bank switch timed out with 4.8MHz clock rate.
plbossart commentedon Jun 17, 2024
this is most likely fixed by #5064, we haven't seen this error since
Closing to mark this problem as resolved. Of course this needs to be re-opened if tests prove us wrong.
marc-hb commentedon Jun 17, 2024
Last daily test run with these failures was just before #5064 was merged:
Start Time: 2024-06-14 13:04:00 UTC
End Time: 2024-06-14 15:53:23 UTC
Linux Branch: topic/sof-dev
Linux Commit: 8ce6e1a
KConfig Branch: master
KConfig Commit: c3171afedc63
Then we had 2 runs on the 16th and 17th and they were both clean (wrt. to this failure)
marc-hb commentedon Jun 21, 2024
and now we just saw that error for the first time on...
jf-cml-sku0983-sdw-1Maybe because of #5064?
Re-open or new bug?
stable-v2.2 daily test run 43002?model=CML_SKU0983_SDW-ipc3&testcase=multiple-pipeline-playback-50
Linux Branch: topic/sof-dev
Linux Commit: e9eea140a1d9
KConfig Branch: master
KConfig Commit: c3171afedc63
bardliao commentedon Jun 24, 2024
#5064 should not impact CML_SKU0983_SDW. #5064 will only take effect when there are more than one sdw frequency is supported. I.e. prop->num_clk_freq > 1. And I checked the DSDT of jf-cml-sku0983-sdw-1, it supported just one frequency.
I also checked the clock on dmesg
clk_freq=6000000 which is exactly the value listed by DSDT.
I would suggest that we create a new bug for the CML bank switch timed out issue.
plbossart commentedon Jun 24, 2024
it's definitively a different error, the problem happened only on LNL/ACE2.x, and this is CML/cAVS 1.8, three generations earlier -> new bug.
It's also not clear if this is reproducible, it's been a week since we merged #5064.