[BUG] Post Processing XRUN when playing multiple times on same topology

[zrombel]

Describe the bug
In any Post Processing test when trying to play 2 times or more on one topology (new streams are created, topology stays intact) SteamStall caused by XRUN occurs.

Topology

+----------------------------------------------+
| +------+  +---+  +-------+  +---+  +-------+ |
| | Host +->+Buf+->+GenProc+->+Buf+->+SSP Dai+---+
| +------+  +---+  +-------+  +---+  +-------+ | |
+----------------------------------------------+ |
                                                 |
+----------------------------+                   |
| +------+  +---+  +-------+ |                   |
| | Host +<-+Buf+<-+SSP Dai+<--------------------+
| +------+  +---+  +-------+ |
+----------------------------+

To Reproduce
Any python test from groups:
25_00_TestGenericProcessorSimplePlb
25_02_TestGenericProcessorCompMultiCorePlb
25_06_TestGenericProcessorPplMultiCorePlb

with parameters:
--playback_iterations=2

Reproduction Rate
100%

Environment

1. Name of the platform(s) on which the bug is observed.
   • Platform: TGL B0 RVP
2. Firmware branch name and commit
   • Branch: main
   • Hash: between eb45907 (bug free) and 2e6cafa (bugged)
3. Python tests branch name and commit
   • Branch: master
   • Hash: 825533f4e0d3ff5e2425abb50e9785916d7d1044

Logs
25_00_TestGenericProcessorSimplePlb_StreamStall.zip

[lgirdwood]

@dbaluta fyi, have you seen this on your side ? I'm wondering here if we are not correctly tearing down the codec adapter pipeline at stream close.

[lgirdwood]

[  5628978.880208] (       12.760417) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:843  ssp_trigger() cmd 1
[  5628988.880208] (       10.000000) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:631  ssp_pre_start()
[  5628998.281250] (        9.401042) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:760  ssp_start()
[  5629055.442708] (       57.161457) c0 ll-schedule        ./schedule/ll_schedule.c:403  task add 0xbe0a0100 0x1fffa4e0U
[  5629063.984375] (        8.541667) c0 ll-schedule        ./schedule/ll_schedule.c:407  task params pri 0 flags 0 start 0 period 1000
[  5629076.510417] (       12.526042) c0 ll-schedule        ./schedule/ll_schedule.c:313  new added task->start 216160631 at 216156342
[  5629084.921875] (        8.411458) c0 ll-schedule        ./schedule/ll_schedule.c:316  num_tasks 4 total_num_tasks 4
[  5630249.322917] (     1164.401001) c0 codec_adapter 1.0   ......../codec/cadence.c:429  ERROR cadence_codec_process() error ffff80c4: processing failed
[  5630260.208333] (       10.885417) c0 codec_adapter 1.0   ......../codec/generic.c:285  ERROR codec_prepare() error -32572: codec process failed for codec_id cade0101
[  5630271.093750] (       10.885417) c0 codec_adapter 1.0   ......../codec_adapter.c:417  ERROR codec_adapter_copy() error ffff80c4: lib processing failed
[  5630282.578125] (       11.484375) c0 pipe         1.5   ....../pipeline-stream.c:168  ERROR pipeline_copy(): ret = -32572, start->comp.id = 2, dir = 1
[  5630294.739583] (       12.161458) c0 pipe         1.5   ..../pipeline-schedule.c:63   ERROR pipeline_task(): xrun recover failed! pipeline will be stopped!
[  5630305.911458] (       11.171875) c0 ll-schedule        ./schedule/ll_schedule.c:127  task complete 0xbe0a0100 0x1fffa4e0U

[lgirdwood]

Linked to #3966 ?

[dbaluta]

@zrombel I actually did notice that:

• cplay works fine at first run
• cplay gets blocked waiting for DSP to consume the frames if you start the second cplay quick enough (1-2seconds).
• if you start cplay after 2 or more seconds everything works well.

I plan to investigate this. Initially I thought that might have something to do with DRAIN which is not yet implemented.

[zrombel]

if you start cplay after 2 or more seconds everything works well.

I assume that on full stack if pipeline is not used for certain amount of time it's being destroyed and then created again if needed.
I run quick test and when creating/deleting topology each iteration bug doesn't occurs. So all is fine when Processor Component is being destroyed after playback.

[dbaluta]

@zrombel yes, this happens because of PM runtime suspend.

[mrajwa]

@zrombel can you try this -> #4162

[zrombel]

Unfortunately PR #4162 doesn't fix this bug.
Logs from test with 2x playback iterations:
MRajwa_PR4162_25_00_TestGenericProcessorSimplePlb48000Hz32b32b2ch_XRUN.zip