Repository navigation
Description
Describe the bug
With “options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8”, "SDW_SCP_INTMASK1 write failed:-61" occurred when run multipipeline stress test. Test for 500 times issue occured at 190th/191th time.
Note: Function cannot be effected when issue occurred.
To Reproduce
1.Boot up system.
2.Run "./multiplex_pipeline-test.sh pcm0p pcm2p pcm3p pcm5p pcm7p pcm1c pcm4c".
Reproduce rate
2/500
Expected result
No failed occured during multipipeline stress test.
Actual result
"SDW_SCP_INTMASK1 write failed:-61" occurred when run multipipeline stress test.
Dmesg:
[ 2342.226142] intel-sdw sdw-master-2: sdw_handle_slave_status: start
[ 2342.226143] rt1308 sdw:2:25d:1308:0: sdw_modify_slave_status: changing status slave 1 status 0 new status 1
[ 2342.226144] rt1308 sdw:2:25d:1308:0: sdw_modify_slave_status: signaling completion for Slave 1
[ 2342.226180] intel-sdw sdw-master-2: Msg ignored for Slave 1
[ 2342.226185] intel-sdw sdw-master-2: SDW_SCP_INTMASK1 write failed:-61
[ 2342.226186] intel-sdw sdw-master-2: Slave 1 initialization failed: -61
[ 2342.226187] intel-sdw sdw-master-2: Updating Slave 1 status
[ 2342.226189] intel-sdw sdw-master-2: sdw_handle_slave_status: Updating Slave 1 status done
[ 2342.226194] intel-sdw sdw-master-2: intel_startup: SDW2 Pin2: start
[ 2342.226198] intel-sdw sdw-master-2: intel_startup: SDW2 Pin2: done
[ 2342.226200] SDW2-speakers: ASoC: open FE SDW2-speakers
[ 2342.226202] sof-audio-pci 0000:00:1f.3: pcm: open stream 3 dir 0
[ 2342.226204] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 2342.226205] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 2342.226206] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 2342.226212] intel-sdw sdw-master-2: sdw_handle_slave_status: end
[ 2342.226218] HDMI1: ASoC: found 0 audio playback paths
sof_error_trace:
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 SA 2927763558.020833 nan src/lib/agent.c:55 validate(), ll drift detected, delta = 26086
0 1 SA 2927878643.854167 115085.835938 src/lib/agent.c:55 validate(), ll drift detected, delta = 26017
0 1 SA 2927976236.770833 97592.914062 src/lib/agent.c:55 validate(), ll drift detected, delta = 26067
0 1 SA 2927978838.854167 2602.083252 src/lib/agent.c:55 validate(), ll drift detected, delta = 25930
0 1 SA 2927981421.875000 2583.020752 src/lib/agent.c:55 validate(), ll drift detected, delta = 25779
0 1 SA 2927982738.020833 1316.145874 src/lib/agent.c:55 validate(), ll drift detected, delta = 25268
0 1 SA 2928086575.312500 103837.289062 src/lib/agent.c:55 validate(), ll drift detected, delta = 25759
scripts:
multiplex_pipeline-test.txt
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: e6392c0
FW: https://github.com/thesofproject/sof/commits/cml-010-drop-stable commit: 5e5f69e
Tplg: Same with FW branch, sof-cml-rt711-rt1308-rt715.tplg
Platform:CML-H Laptop with codec ALC711, 2 x RT1308, RT715 in SDW mode.
Activity
sinahuang commentedon Dec 18, 2019
This issue maybe related to #1597
plbossart commentedon Dec 19, 2019
@RanderWang @bardliao can you take a look at the log, I find some very odd things
and when we restart the clock we have issues
This looks like a case where the clock is not properly stopped?
bardliao commentedon Dec 19, 2019
@plbossart My theory is somehow cdns.link_up is still true when the link is powered down. Every register will read as 0xffffffff when the link is powered down. When any interrupt is triggered, we will check each link's irq status and we will get a lot of superfluous irq since we actually read registers when the link is off. I believe that the issue will be solved by
But what I am not clear is that how can cdns.link_up be true when intel_link_power_down() is called and return 0?
plbossart commentedon Dec 19, 2019
@bardliao I wonder if the sequences are correct. Somehow we should probably enable the interrupts last, after the bus reset. And conversely when suspending we should disable the interrupts first.
The other mystery in in mode 0x0, why do we power down the link?
this is fine when we do the complete re-enumeration but I am not sure it's needed or even legit when the DSP remains powered.
plbossart commentedon Dec 19, 2019
enable_interrupt.diff.txt
plbossart commentedon Dec 19, 2019
@bardliao @RanderWang we could also harden the interrupts.
a) when we restart the clock, we could read MCP_SlaveIntStat0/MCP_SlaveIntStat1 and write1 to clear the bits. That would make sure we start from a clean state, and not from whatever was in the status before the clock was stopped (if the status is preserved)
b) the MCP_INSTAT register has reserved values in bits 30:17, so if we detect a one in any of these bits it's a bad interrupt
c) we should also track MCP_INTSTAT.WakeUp, which tells us when the master left the clock stop mode. That would be really useful since it should come before Slaves can even signal their own status change.
plbossart commentedon Dec 19, 2019
@bardliao @sinahuang @RanderWang can you try this #1640
Completely untested on my side, just ideas to try and make progress
bardliao commentedon Dec 19, 2019
@plbossart Sorry, but I think we can't invert the sequence between enable interrupt and clock stop. sdw_slave_clk_stop_callback() will be triggered on the clock stop process, and interrupt is needed for transmission.
YvonneYang2 commentedon Dec 19, 2019
Issue can be reproduced on CML-U sdw laptop with latest soundwire-latest(121c751) during suspend/resume with aplay0,6 stress test. Run 300 times, failed at 150th time.
s3_test_150_logger_all.log
test_150.log
sinahuang commentedon Dec 19, 2019
Verified this issue with soundwire-latest(commit: 121c751 +PR #1640) on CML-H, "IO transfer timed out" occured, failed at 1st time.
dmesg
Test recipe
Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 121c751 +PR #1640
FW: https://github.com/thesofproject/sof/commits/cml-010-drop-stable commit: 5e5f69e
Tplg: Same with FW branch, sof-cml-rt711-rt1308-rt715.tplg
Platform:CML-H Laptop with codec ALC711, 2 x RT1308, RT715 in SDW mode.
failed_multipipeline_test_1_all_logger.log
failed_multipipeline_test_1_dmesg.log
failed_multipipeline_test_1_logger_error.log
RanderWang commentedon Dec 20, 2019
yes, we need interrupt to do clock stop setting
37 remaining items
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
UPSTREAM: soundwire: stream: don't program ports when a stream that h…
UPSTREAM: soundwire: stream: don't program ports when a stream that h…
UPSTREAM: soundwire: stream: don't program ports when a stream that h…
UPSTREAM: soundwire: stream: don't program ports when a stream that h…
UPSTREAM: soundwire: stream: don't program ports when a stream that h…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…
soundwire: stream: don't program ports when a stream that has not bee…