volume pipeline copy failure after resuming from S3 on CML

[keqiaozhang]

This issue happens on HDMI playback after resuming form system S3.

How to reproduce:

1. Open one terminal and run HDMI playback:
   aplay -Dhw:0,2 -f dat -c 2 audio_file.wav
2. Open another terminal and do suspend/resume
   rtcwake -m mem -s 5
3. After resuming, HDMI playback failed with input/output error.

No obvious errors in dmesg.
Trace log:

 CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
 0 2 DMA 1119652.187500 1119652.250000 intel/cavs/hda-dma.c:645 hda-dmac: 5 channel 0 -> stop
 0 2 VOLUME 1119656.354167 4.166667 src/audio/volume.c:453 volume_trigger()
 0 2 DAI 4.20 1119660.520833 4.166667 src/audio/dai.c:527 dai_comp_trigger(), command = 8
 0 2 DAI 4.20 1119664.479167 3.958333 src/audio/dai.c:582 dai_comp_trigger(), XRUN
 0 2 DAI 4.20 1119667.916667 3.437500 src/audio/dai.c:588 dai_comp_trigger(), PAUSE/STOP
 0 2 DMA 1119671.718750 3.802083 intel/cavs/hda-dma.c:645 hda-dmac: 7 channel 0 -> stop
 0 1 PIPE 1119678.177083 6.458333 src/audio/pipeline.c:667 pipeline_copy() error: ret = -5, start->comp.id = 20, dir = 1
 0 1 PIPE 4.21 1119684.531250 6.354167 src/audio/pipeline.c:775 pipeline_xrun_recover()
 0 2 PIPE 4.21 1119689.479167 4.947917 src/audio/pipeline.c:351 pipeline_prepare()
 0 2 HOST 1119693.333333 3.854167 src/audio/host.c:620 host_prepare()
 0 2 COMP 1119697.135417 3.802083 rc/audio/component.c:127 comp_set_state(), state already set to 3
 0 2 PIPE 4.21 1119701.250000 4.114583 src/audio/pipeline.c:526 pipeline_trigger()
 0 2 HOST 1119705.156250 3.906250 src/audio/host.c:281 host_trigger()
 0 2 DMA 1119709.270833 4.114583 intel/cavs/hda-dma.c:549 hda-dmac: 5 channel 0 -> start
 0 2 DMA 1119713.229167 3.958333 intel/cavs/hda-dma.c:396 hda-dmac: 5 channel 0 -> enable
 0 2 VOLUME 1119773.020833 59.791668 src/audio/volume.c:453 volume_trigger()
 0 2 DAI 4.20 1119776.875000 3.854167 src/audio/dai.c:527 dai_comp_trigger(), command = 1
 0 2 DAI 4.20 1119780.312500 3.437500 src/audio/dai.c:535 dai_comp_trigger(), START
 0 1 VOLUME 1120946.145833 1165.833374 src/audio/volume.c:493 volume_copy() error: sink component buffer has not enough free bytes for copy
 0 2 COMP 1120951.510417 5.364583 of/audio/component.h:675 comp_overrun(), ((dev->comp.id << 16) | sink->free) = 1114112, ((min_bytes << 16) | copy_bytes) = 0
 0 2 PIPE 4.21 1120955.468750 3.958333 src/audio/pipeline.c:526 pipeline_trigger()
 0 2 HOST 1120959.531250 4.062500 src/audio/host.c:281 host_trigger()
 0 2 DMA 1120963.958333 4.427083 intel/cavs/hda-dma.c:645 hda-dmac: 5 channel 0 -> stop
 0 2 VOLUME 1120968.385417 4.427083 src/audio/volume.c:453 volume_trigger()
 0 2 DAI 4.20 1120972.656250 4.270833 src/audio/dai.c:527 dai_comp_trigger(), command = 8
 0 2 DAI 4.20 1120976.614583 3.958333 src/audio/dai.c:582 dai_comp_trigger(), XRUN
 0 2 DAI 4.20 1120980.156250 3.541667 src/audio/dai.c:588 dai_comp_trigger(), PAUSE/STOP
 0 2 DMA 1120984.166667 4.010417 intel/cavs/hda-dma.c:645 hda-dmac: 7 channel 0 -> stop
 0 1 PIPE 1120990.729167 6.562500 src/audio/pipeline.c:667 pipeline_copy() error: ret = -5, start->comp.id = 20, dir = 1
 0 1 PIPE 4.21 1120997.239583 6.510417 src/audio/pipeline.c:775 pipeline_xrun_recover()

Test Recipe:
kernel-driver: sof-v4.19-rebase/07d64ca + kernel PR#704
firmware/tplg: cml-003-drop-stable/55ae67b

logger.log
dmesg.log

[tlauda]

I've looked into kernel and FW logs and it seems there is something wrong with HDA stream after resume. From FW perspective it's just stopping and starting the new pipeline, but after resume there is problem with getting new data from host/consuming data on link (cannot tell wchich one), which causes xrun.

[xun2z]

We have resume issue on cml platform before. linux #592

[lgirdwood]

@ranj063 anything in the driver PM resume path that could impact the HDA stream (or has been changed recently) ?

[ranj063]

@lgirdwood resuming link dma after S3 is a known issue. Libin has a patch to get it working but it is still under review.
thesofproject/linux#489
thesofproject/linux#725

[keqiaozhang]

@ranj063 @libinyang
I tested PR725 on WHL, it can reduce the probability of this issue(100% ->~10%). But raise a new issue is that HDMI playback will be muted after resuming.

[libinyang]

This is another issue which I'm debugging on it. It's a codec driver issue. The root cause is the power on sequence has contest inside hdmi codec driver.

[wenqingfu]

This is another issue which I'm debugging on it. It's a codec driver issue. The root cause is the power on sequence has contest inside hdmi codec driver.

please open a new issue and refer to the number here.

[libinyang]

This bug is duplicated with thesofproject/linux#489 , as it's the same root cause.