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

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:

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.
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

@RDharageswari

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?

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

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

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

@RDharageswari

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

@stolx

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

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.

@slawblauciak

@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:

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

@stolx

@stolx usually the input format come from the ALSA PCM param while the output format could inherit from the BE DAI so they can be different, you need to check if you have made the BE DAI in your tplg file fixed, if so, you might need to add a format converter (e.g. volume) around your codec component.

Could this also be linked to #4104

I dont think so since this fails before we get to playback stage. But I think I have an idea what might be happening here. I have two possible theories. Unfortunately the author of the idc module is no longer around to answer.

my theories

Caches not being invalidated when handling params. Looking through the code I don't see any cache coherency when running params callbacks. Given it looks like params are inferred from buffers this seems like a possible problem.
idc sync on params order. I have to run more tests on this one, but if idc is not blocking downstream components from running their callback till upstream components on separate cores are done then they will pull bad params from the buffer.

From what I have seen, changing a whole pipeline removes the above issues which would align with the nature of the bugs. Still need to do more testing on the whole pipeline change though.

@slawblauciak

@slawblauciak @mwasko fyi - lets get in for rc3 and TGL13 once @mrajwa is back from vacation.

@dbaluta

@dbaluta @mrajwa @mwasko @RDharageswari any update here ? Have we solved this in TGL13 or in main ?

@dbaluta

@dbaluta can you re-test this with tgl-013-drop-stable branch?

@stolx

@stolx FYI

@stolx

@stolx @RDharageswari please hep to re-try as we don't have a way to reproduce it.

I can try either today or monday hopefully

forgot to write here as well my results, initial tests look promising

forgot to write here as well my results, initial tests look promising

Thanks for the feedback, waiting for your final result.

@cujomalainey

@cujomalainey please help to close it if it doesn't reproduce with tgl-013-drop-stable.

In my testing so far this has been good, i think its safe to close unless we see it pop up again, but i think it might be worth adding single core components into the testing pipeline to detect this in CI in the future

@cujomalainey

Thanks @cujomalainey , yes component level multi-core will be next declared support, maybe delivered with Zephyr together.

Navigation Menu

Repository navigation

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

11 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

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

Description

Activity

keyonjie commented on Mar 29, 2021

RDharageswari commented on Mar 29, 2021

RDharageswari commented on Mar 29, 2021

RDharageswari commented on Mar 30, 2021

keyonjie commented on Mar 30, 2021

slawblauciak commented on Mar 30, 2021

juimonen commented on Mar 30, 2021

stolx commented on Mar 30, 2021

keyonjie commented on Mar 30, 2021

11 remaining items

lgirdwood commented on May 10, 2021

cujomalainey commented on May 12, 2021

lgirdwood commented on May 20, 2021

lgirdwood commented on May 27, 2021

keyonjie commented on Jun 2, 2021

cujomalainey commented on Jun 2, 2021

keyonjie commented on Jun 4, 2021

cujomalainey commented on Jun 4, 2021

cujomalainey commented on Jun 8, 2021

keyonjie commented on Jun 8, 2021

keyonjie commented on Jun 11, 2021

cujomalainey commented on Jun 11, 2021

keyonjie commented on Jun 11, 2021

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions