Repository navigation
[BUG][SDW]"Program transport params failed: -22" occured during multipipline stress test. #1494
Description
Describe the bug
"Program transport params failed: -22" occured during multipipline stress test, but aplay function will not be effected.
Issue can be reproduced with MSI interrupt mode and legacy interrupt mode.
To Reproduce
1.Boot up system;
2.Run "./multiplex_pipeline-test.sh pcm0p pcm2p pcm1c pcm3c pcm4c";
Scripts:
multiplex_pipeline-test.txt
Reproduce rate
1st try: 16/100;
2nd try:12/100;
Expected result
Multipipline works normally.
Actual result
"Program transport params failed: -22" occured during multipipline stress test.
dmesg
[ 501.586917] intel-sdw sdw-master-0: intel_hw_params: SDW0 Pin3: start
[ 501.586953] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 501.587056] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 501.587069] sof-audio-pci 0000:00:1f.3: nothing to do in IPC IRQ thread
[ 501.587230] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 00e0 <= 0003
[ 501.587288] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 00f0 <= 0003
[ 501.587291] rt711 sdw:0:25d:711:0: rt711_clock_config complete, clk_freq=4800000
[ 501.587293] intel-sdw sdw-master-0: Program transport params failed: -22
[ 501.587298] intel-sdw sdw-master-0: Program params failed: -22
[ 501.587303] sdw_enable_stream: SDW0 Pin2-Playback: done
[ 501.587307] intel-sdw sdw-master-0: intel_trigger trigger 1 failed: -22
[ 501.587308] intel-sdw sdw-master-0: intel_hw_params: SDW0 Pin3: done
[ 501.587311] intel-sdw sdw-master-0: Update DAI routes for SDW0 Pin3 capture
[ 501.587315] intel-sdw sdw-master-0: intel_trigger: SDW0 Pin2: done
[ 501.587317] SDW0-mics: ASoC: hw_params FE SDW0-mics rate 48000 chan 2 fmt 2
[ 501.587320] sof-audio-pci 0000:00:1f.3: Update DAI routes for SDW0-mics 1 capture
[ 501.587322] SDW0-Playback: ASoC: trigger BE failed -22
[ 501.587324] sof-audio-pci 0000:00:1f.3: Connecting DAI route PCM1C -> Passthrough Capture 1
[ 501.587326] sof-audio-pci 0000:00:1f.3: pcm: hw params stream 1 dir 1
[ 501.587329] SDW0-headphone: ASoC: trigger FE cmd: 1 failed: -22
[ 501.587332] sof-audio-pci 0000:00:1f.3: generating page table for 000000002e0a4024 size 0xffc0 pages 16
[ 501.587336] SDW0-headphone: ASoC: pre trigger FE SDW0-headphone cmd 0
[ 501.587340] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[ 501.587342] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 501.587345] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 501.587373] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 501.587376] sof-audio-pci 0000:00:1f.3: period_bytes:0x3fc0
[ 501.587377] sof-audio-pci 0000:00:1f.3: periods:4
sof error trace:
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 SA 992692582.656250 992692608.000000 src/lib/agent.c:55 validate(), ll drift detected, delta = 41475
0 1 SA 992710650.416667 18067.759766 src/lib/agent.c:55 validate(), ll drift detected, delta = 40411
0 1 SA 992712786.822917 2136.406250 src/lib/agent.c:55 validate(), ll drift detected, delta = 41022
0 1 SA 992714910.937500 2124.114502 src/lib/agent.c:55 validate(), ll drift detected, delta = 40780
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 1bb06ec
FW: https://github.com/thesofproject/sof/commits/master commit: decd206
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.
multipipeline_test_40_dmesg.log
multipipeline_test_40_all_logger.log
multipipeline_test_40_error_logger.log
Activity
[-][BUG][SDW]"Program transport params failed: -22" occured during multipipline stress test.[/-][+][BUG][TGL][SDW]"Program transport params failed: -22" occured during multipipline stress test.[/+]sinahuang commentedon Nov 18, 2019
Issue still can be reproduced on TGL RVP, issue first occured at 66th time.
Reproduce rate: 65/500
sof_error_trace log:
Dmesg log:
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 246ab27
FW: https://github.com/thesofproject/sof/commits/master commit: 655d077
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.
66th log.zip
YvonneYang2 commentedon Dec 4, 2019
Run multi-pipline stress test, issue can be reproduced on integration/soundwire-latest(b4f9bfa) + #1580 with sof-pci-debug=1 and sdw_md_flags=0x01000001.
Platforms: CML Laptop with ALC711+ ALC1308+ ALC715 in SDW mode
When issue reproduced, terminate it then start again can recover it.
multipipeline_test_22_all_logger.log
multipipeline_test_22_dmesg.log
YvonneYang2 commentedon Dec 9, 2019
With options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x1 for not allowed, run multi-pipline stress test 500 times, issue can be reproduced at 291th/292th/293th/294th/295th time. Terminate it and restart again can recover the issue.
dmesg
multipipeline_test_291_all_logger.log
multipipeline_test_291_dmesg.log
Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: b036eac + #1586
FW: https://github.com/thesofproject/sof/commits/master commit: 65de27d
tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML-U Laptop with codec ALC711, RT1308, RT715 in SDW mode
YvonneYang2 commentedon Dec 10, 2019
With options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x1 for not allowed, run multi-pipline stress test 500 times, issue cannot be reproduced.
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: e375909+ PR1586
FW: https://github.com/thesofproject/sof/commits/master commit: 8f51e6b
tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML-U Laptop with codec ALC711, RT1308, RT715 in SDW mode
sinahuang commentedon Dec 10, 2019
With options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x1,now issue cannot be reproduced on CML-U Laptop and CML-H Laptop, but TGL-RVP can still reproduce this issue during multipipline stress test.
multipipeline_test_138_dmesg.log
multipipeline_test_138_all_logger.log
multipipeline_test_138_logger_error.log
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: e375909 +PR #1586
FW: https://github.com/thesofproject/sof/commits/master commit: 8f51e6b
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
YvonneYang2 commentedon Dec 11, 2019
Run 1000 times again with same environment , issue can still be reproduced. Reproduced rate is about 5/1000
multipipeline_test_320_dmesg.log
multipipeline_test_320_all_logger.zip
[-][BUG][TGL][SDW]"Program transport params failed: -22" occured during multipipline stress test.[/-][+][BUG][SDW]"Program transport params failed: -22" occured during multipipline stress test.[/+]plbossart commentedon Dec 19, 2019
@YvonneYang2 can you retry with integration/soundwire-latest 121c751
I added a set of traces to figure out what the -22 (-EINVAL) return value might come from.
2 remaining items
plbossart commentedon Dec 19, 2019
Thanks @YvonneYang2 the traces do show what happens:
something is clearly wrong, we should not be using port 0, so there's bad code somewhere...
plbossart commentedon Dec 20, 2019
I can reproduce this error on a CML laptop with a single amp with #1640 73faa6b
with options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8
this happens at the 3rd stress test so quite easy to see
sinahuang commentedon Dec 20, 2019
With options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8, issue still can be reproduced on TGL-U.
Run 500 times, failed at 6th time.
Dmesg:
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 121c751
FW: https://github.com/thesofproject/sof/commits/master commit: f587993
Tplg: Same with TGL FW branch : sof-tgl-rt711-rt1308.tplg
Platform:TGL-U RVP with codec ALC711 in SDW mode and RT1308 in I2S mode
6th.zip
bardliao commentedon Dec 23, 2019
I suspect that the issue is somehow sdw_program_slave_port_params() is called between sdw_port_alloc() and sdw_compute_slave_ports(). @sinahuang @YvonneYang2 Could you apply
0001-TEST-soundwire-add-trace-for-invalid-port-number.patch.txt and test it?
sinahuang commentedon Dec 24, 2019
Checked this issue on TGL-U RVP and CML-U Laptop after applying 0001-TEST-soundwire-add-trace-for-invalid-port-number.patch.txt in soudnwire-latest(commit:121c751), issue still can be reproduced.
Verified with options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8 on TGL-U RVP with codec ALC711 in SDW mode and RT1308 in I2S mode, test for 500 times , failed 121 times
dmesg :
multipipeline_test_22_dmesg.log
multipipeline_test_22_logger_error.log
Verified with options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x1 on CML-U Laptop with codec ALC711, RT1308, RT715 in SDW mode.test for 500 times, failed 5 times.
dmesg:
multipipeline_test_363_all_logger.log
multipipeline_test_363_dmesg.log
multipipeline_test_363_logger_error.log
bardliao commentedon Dec 24, 2019
Thanks @sinahuang the trace do show sdw_program_slave_port_params() is called between sdw_port_alloc() and sdw_compute_slave_ports().
YvonneYang2 commentedon Dec 30, 2019
Tested it 1000 times, issue cannot be reproduced with latest integration/soundwire-latest(121c751) + #1640 + #1654
YvonneYang2 commentedon Jan 8, 2020
Tested it 1000 times on CML-U sdw laptop DVT2, issue cannot be reproduced with latest integration/soundwire-latest + #1665.
sinahuang commentedon Jan 9, 2020
Tested it 1000 times on CML-H/TGL-U sdw laptop with integration/soundwire-latest(commit:07348fa), issue cannot be reproduced, so closed it.