[BUG] [TGL] [tgl-012-drop-stable] Wrong source/sink settings during ALSA conformance test

[RDharageswari]

Name of component: SOF/ALSA

Brief: When doing ALSA test for SOF built sound-open-firmware-private branch, codec_adapter receives wrong source/sink parameters.

Environment:
TGL + tgl-012-drop-stable + WAVES

Detailed:
Usual way of doing alsa conformance test is running python script:
./alsa_conformance_test.py -D hw:0,0 --rate-err-criteria 100 --log-file alsa_test_log.txt
Output of this command is attached: alsa_test_output_.txt.
From alsa_test_log.txt is is clear what sequence of executions of alsa_conformance_test performs python script.
Also it is clear that test snd_pcm_hw_params fails when setting sample format S24_LE and S32_LE, but is passing on S16_LE.

INFO:root:Set format S16_LE
INFO:root:Execute command: alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S16_LE -p 240
INFO:root:pass
INFO:root:Set format S24_LE
INFO:root:Execute command: alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S24_LE -p 240
INFO:root:fail - snd_pcm_hw_params: Input/output error
INFO:root:Set format S32_LE
INFO:root:Execute command: alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S32_LE -p 240
INFO:root:fail - snd_pcm_hw_params: Input/output error

After investigating it for a bit I can tell that:

1. if executing same sequence of calls that python script does, but with 5 seconds time gap between them, there is no smd-pcm-hw-params error.
   So this means when they are executed rapidly one after anothe, something changes.
2. building debug SOF with logs shows exactly the issue, sink and source buffers that arrive to codec_adapter have different format which is not expected.

alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S16_LE -p 240
source and sink are 16 bit
alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S24_LE -p 240
source is 16 bit and sink is 24 bit
alsa_conformance_test -P hw:0,0 -d 0.1 -r 48000 -c 2 -f S32_LE -p 240
source is 16 bit and sink is 32 bit

this looks like a bug, no matter the time difference between alsa_conformance_tests execution, result should be the same, as do the stream parameters that comes to codec_adapter.
alsa_test_log.txt
alsa_test_output.txt

[keyonjie]

Hi @RDharageswari do you know where do the source and sink format come from?

Since it works if start test with waiting more than 5 seconds, it looks to me the the previous playback doesn't stop/reset correctly and the subsequent playback in different format failed at .hw_params().

@RDharageswari can you share the FW SOF log at the failed case?

[RDharageswari]

Following is the update from waves:
This issue is not 100% reproduction rate.
Got sometimes same sink and source format when running alsa test.
Adding logs to volume component didn`t help much because volume is below stream with respect to codec adapter, and after codec adapter failed no logs from Volume
After codec-adapter is removed from topology volume component receives both sink and source buffers with the same format
sof-log.txt
dmesg-log.txt

[RDharageswari]

0001-WIP-Log-volume-source-and-sink-format.patch.txt

[RDharageswari]

Feedback from waves is that the issue is still reproducible with the above patch

[keyonjie]

Hi @RDharageswari someone should be able to debug this as the error is already in the FW logs:

[1903502123.750000] (       22.500000) c1 idc                ......./intel/cavs/idc.c:166  idc_do_cmd()
[1903502142.447917] (       18.697916) c1 codec_adapter 1.1   ......../codec_adapter.c:189  codec_adapter_prepare() start
[1903502164.270833] (       21.822916) c1 codec_adapter 1.1   ........../codec/waves.c:241  ERROR waves_effect_check() source 1 sink 2 sample format mismatch
[1903502188.333333] (       24.062500) c1 codec_adapter 1.1   ........../codec/waves.c:645  ERROR waves_codec_prepare() failed -22
[1903502212.031250] (       23.697916) c1 codec_adapter 1.1   ......../codec/generic.c:227  ERROR codec_prepare() error -22: codec specific prepare failed, codec_id 0x57410100
[1903502235.625000] (       23.593750) c1 codec_adapter 1.1   ......../codec_adapter.c:219  ERROR codec_adapter_prepare() error ffffffea: codec prepare failed
[1903502272.656250] (       37.031250) c0 pipe         1.9       src/audio/pipeline.c:690  ERROR pipeline_prepare(): ret = -5, dev->comp.id = 0
[1903502294.635417] (       21.979166) c0 ipc                       src/ipc/handler.c:285  ERROR ipc: pipe 1 comp 0 prepare failed -5
[1903502316.927083] (       22.291666) c0 pipe         1.9       src/audio/pipeline.c:964  pipe reset

[slawblauciak]

@stolx hi, could you please help to figure this one out if it's an issue with the Waves module?

[juimonen]

so this topology is defining a format range for the pcm like from 16 bit LE to 32 bit LE. So alsa conformance test is testing that it supports all these formats. If there is no any other component before the codec adapter that will do the conversion, the codec adapter needs to accept different formats.

[stolx]

@slawblauciak @juimonen
Waves codec implementation supports all sample formats of SOF 16, 24_4LE and 32.
But we expect the source and sink to have the same format.
The issue is that sometimes during ALSA test we get sink and source of different format and check in our codec_adapter API implementation fails.
The exact place of the check:
https://github.com/thesofproject/sof/blob/main/src/audio/codec_adapter/codec/waves.c#L239

So this bug is actually two independent questions:

1. Why this happens only sometimes during ALSA tests, maybe some race conditions are involved?
2. Should codec that implements codec_adapter interface support source and sink of different format?