Repository navigation
[SDW] playback is stopped after system suspend #1311
Description
When we do a system suspend, the playback does not restart on system resume. The dmesg log shows a trigger stop is sent immediately.
console log
root@jf-icl-rvp-hda-8:~# modprobe snd-sof-pci
root@jf-icl-rvp-hda-8:~# speaker-test -Dhw:0,0 -c2 -r48000
speaker-test 1.1.3
Playback device is hw:0,0
Stream parameters are 48000Hz, S16_LE, 2 channels
Using 16 octaves of pink noise
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 96 to 16368
Period size range from 48 to 4080
Using max buffer size 16368
Periods = 4
was set period_size = 3312
was set buffer_size = 16368
0 - Front Left
1 - Front Right
Time per period = 5.592228
0 - Front Left
1 - Front Right
Time per period = 5.934952
0 - Front Left
1 - Front Right
Write error: -86,Streams pipe error
Write error: -5,Input/output error
xrun_recovery failed: -5,Input/output error
Transfer failed: Input/output error
The expected behavior is that the playback restarts (possibly with an error message indicating an underflow)
Kernel: integration/soundwire-latest 19df577
Additional traces on top
pm-traces.diff.txt
firmware: master
dmesg log (only tracking after rtcwake -m freeze -s 3)
dmesg_aplay_suspend_stop_on_resume.log
Activity
ranj063 commentedon Oct 12, 2019
@plbossart it looks like the BE hw_params isnt getting called here.
In the prepare() callback for the SDW BE ops, I think we should set the hw_params if it is resumed from suspend.
plbossart commentedon Oct 12, 2019
@ranj063 yes. I suspect that the stream is still configured as 'PREPARED' so we don't do anything.
ranj063 commentedon Oct 12, 2019
@plbossart in the HDA case, we call the hw_params() routine from our prepare() routine if the link is not prepared. The link is marked as not prepared in the stop/suspend triggers.
I am wondering if we need to use a similar logic in the SDW BE dai ops ie have intel_prepare() called intel_hw_params() upon resuming from system suspend.
plbossart commentedon Oct 12, 2019
It's definitively a problem with the .prepare callback.
I added some traces on top of integration/soundwire-latest (https://github.com/plbossart/sound/tree/fix/soundwire-suspend-aplay-resume) and I can see the prepare returns as 'already configured'
but later on we still do a trigger
Full log here:
dmesg_aplay_suspend_already_prepared.log
It's very likely that since we don't reprogram the transport parameters, the enable does not do anything during the bank switch and there is no data transfer on the bus.
plbossart commentedon Oct 12, 2019
Update: the issue is due to the stream management, the state machine is inconsistent.
I fixed it in the updated branch: https://github.com/plbossart/sound/tree/fix/soundwire-suspend-aplay-resume
As @ranj063 suggested it, the issue is that on system resume, we call the .prepare() callback, but it's in the .hw_params() that we notify firmware of the ALH stream ID. So when we do trigger, nothing will happen since the firmware was not re-configured.
See trace in attached file (search for marker "<<" to follow the sequence)
dmesg_aplay3.log
@slawblauciak, couple of questions for you:
a. shouldn't we return an error when we trigger and there is no ALH configuration that's passed to the firmware?
b. is this ok if we pass the ALH configuration during the prepare step, which means that the firmware might receive the configuration multiple times, e.g. if an underrun happens?
@bardliao @RanderWang please check how we can modify the intel_prepare() callback so as to pass the right information to firmware.
dengyangchao commentedon Oct 14, 2019
no matter s2idle or deep suspend mode will cause I/O error in below two scenarios, except HDMI/DP playback.
scenario1: aplay 0,0/2/3 (or arecord ) --> pause --> s3/s2 --> wake up -->resume --> I/O error
scenario2: aplay 0,0/2/3 (or arecord )-->s3/s2 -->wake up --> I/O error
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 19df577
sof: https://github.com/thesofproject/sof/commits/master commit: c7d0149
platforms: cml rt700 rvp, icl 3-in-1 rvp.
dmesg.log
logger.log
bardliao commentedon Oct 14, 2019
@plbossart Please check https://github.com/bardliao/linux/tree/fix/soundwire-suspend-aplay-resume.
soundwire: intel: stream deprepare on TRIGGER_STOP/SUSPEND/PAUSE_PUSH will change stream status from DISABLED to DEPREPARED which will against the status check of sdw_enable_stream(). So I revert the commit and do deprepare in intel_prepare(). Also, I store hw_params and pdi information in sdw_intel {} so we can configure the stream after deprepare. I did some suspend/resume and pulse/release test and all of them works.
plbossart commentedon Oct 14, 2019
@bardliao thanks for this suggestion.
I don't have strong objections but we need to keep the state machine consistent. With the changes I did, I added this state check:
With your patch, are we saying that on enable we have to be in PREPARED state, and the transition from DISABLED to ENABLED is not allowed?
Or are we just saying that if prepare() is called while the state was DISABLED, we have to deprepare and prepare again for consistency?
plbossart commentedon Oct 14, 2019
@bardliao also the issue with your solution is that it will not work when we transition to the multi-cpu dai solution. I think we need to have a flag that is explicitly set on trigger_suspend, and we test against that in the prepare, without using the stream state.
bardliao commentedon Oct 15, 2019
@plbossart I think the issue is that the stream status is actually not DISABLED (some configuration are lost) in system suspended (though the stream->status is DISABLED). So, in such case the transition from DISABLED to ENABLED doesn't work. However, in other cases the transition from DISABLED to ENABLED works fine.
plbossart commentedon Oct 15, 2019
please retest with #1320
YvonneYang2 commentedon Oct 16, 2019
Test it with #1320 on icl 3-in-1 rvp, system boot up with PA on, dmesg shows
log:
boot_up_PAon_dmesg.log
Aplay 0,0 (RT711)will fail and show the same dmesg logs as above. But aplay0,2/3 (RT1308) can work.
Aplay0,2 --> pause --> s3 --> wake up --> resume --> fail console shows I/O error
logs :
pause_s3_resume_dmesg.log
pause_s3_resume_logger.log
Test it with #1320 + bardliao@d0247d3, system boot up with PA on or aplay 0,0 still has same dmesg logs as above.
But no suspend/resume relevant issue occurred.
Test it with https://github.com/bardliao/linux/tree/integration/soundwire-20191015 , Not occurred issues mentioned above, but all arecord volume always shows 0 with PA on.
logs:
arecord_volume0_dmesg.log
arecord_volume0_logger.log
plbossart commentedon Oct 16, 2019
Thanks @YvonneYang2
The trace below essentially tells us we are trying to deprepare a PREPARED stream.
That's not currently allowed by the state machine, but it should be as discussed with @bardliao. I guess this happens with PulseAudio trying to open the device and set the hw_params, then close the devices without ever triggering.
I will fix this, this is a nice bug :-)
ranj063 commentedon Oct 16, 2019
@plbossart pulse audio also tries to open and close device without setting the hw_params too.
bardliao commentedon Oct 18, 2019
Yeah, so prepare <-> deprepare should be a valid transfer :)
dengyangchao commentedon Oct 18, 2019
issue still can reproduce on CML RVP with codec ALC700 in SDW mode
reproduce rate from 100% to 40% (2/5)
scenario: aplay 0,0(or arecord)-->s3/s2 -->wake up --> I/O error
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest d88ee7d + PR1327
sof: https://github.com/thesofproject/sof/commits/master 81cc31b
plbossart commentedon Oct 18, 2019
can you please share logs @dengyangchao ? It's impossible to follow-up without dmesg traces...
dengyangchao commentedon Oct 18, 2019
run a stress test and reproduce it at 1/33
Dmesg
s3_test_33_logger_all.log
test_33.log
bardliao commentedon Oct 18, 2019
Looks like it is a different issue. Would it be better to create a new issue for it?
plbossart commentedon Oct 18, 2019
YvonneYang2 commentedon Oct 21, 2019
Original issue is not reproduced with test recipe as below. One new issue after #1327 merged will be tracked in #1340
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 29debf8
FW: https://github.com/thesofproject/sof/commits/master commit: 3d5d314
tplg: Same with FW branch, sof-icl-rt711-rt1308-rt715-hdmi.tplg rename to sof-icl-rt711-rt1308-rt715.tplg
platform: ICL RVP, with codec ALC711 -RT1308, RT715 in SDW mode
YvonneYang2 commentedon Oct 21, 2019
Close for not reproduced and track new behavior in #1344