[BUG] DMIC capture failed to start

[yongzhi1]

Describe the bug

Launch arecord on DMIC Raw, and observe error returned immediately.

To Reproduce
Steps to reproduce the behavior: (e.g. list commands or actions used to reproduce the bug)

arecord -Dhw:0,99 /tmp/test.wav -c4 -r48000 -fs32_le -d10 

Reproduction Rate
100%

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel: {https://chromium.googlesource.com/chromiumos/third_party/kernel/+log/refs/heads/chromeos-6.1/sound}
   • SOF: {a8db157b9a2dee8}
2. Name of the topology file
   • Topology: {sof-mtl-max98357a-rt5682-ssp2-ssp0.tplg}
3. Name of the platform(s) on which the bug is observed.
   • Platform: {MTL/Rex}

Screenshots or console output
If applicable, add a screenshot (drag-and-drop an image), or console logs

mtrace-main-dmic.txt
dmesg-dmic-err.txt

[lgirdwood]

@singalsu can you check this on main, any thoughts ?

[lgirdwood]

@yongzhi1 can you confirm if stereo is working with your device, i.e. is issue only with 4 channels and 32bit data ? Thanks

[singalsu]

Seems there's no data coming to host. Do you know if this is a regression?

[singalsu]

The <err> dai_intel_dmic_nhlt: seen in mtrace from DMIC is not an error but wrong log function usage. I will create a PR to change it to LOG_INF().

[abonislawski]

Reverting this PR can help in this scenario:
#8084

@ujfalusi can you take a quick look if we are missing something obvious?

[yongzhi1]

@yongzhi1 can you confirm if stereo is working with your device, i.e. is issue only with 4 channels and 32bit data ? Thanks

To confirm, stereo playback works fine, 2xch raw capture (with modified tplg from 4ch -> 2ch, with or without GOOGLE_RTC_AEC_SUPPORT) fails for same reason. AEC mock capture is also broken when tested with LL and on core0.

[kv2019i]

@abonislawski @ujfalusi "-61" is -ENODATA and this is only returned in very specific cases, notably for echo reference stream when the associated playback is not running at all. So I wonder if we have a regression in pipeline-stream.c:pipeline_should_report_enodata_on_trigger() that triggers in this specific case?

[ujfalusi]

Based on the kernel log:
1st we move the pipelines to RUNNING state, which involves two steps:
PAUSED state

[   45.079369] sof-audio-pci-intel-mtl 0000:00:1f.3: trigger cmd: 1 state: 4
[   45.079375] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x13000003|0x1 [data size: 12]
[   45.079753] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x33000000|0x1
[   45.079781] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0x13000003|0x1 [data size: 12]
[   45.079789] Message payload: 00000000: 00000002 00000000 00000001

Success
Followed by RUNNING state:

[   45.079793] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x13000004|0x1 [data size: 12]
[   45.090475] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x330000a4|0x1
[   45.090486] sof-audio-pci-intel-mtl 0000:00:1f.3: FW reported error: 164 - Unknown
[   45.090796] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc error for msg 0x13000004|0x1
[   45.090814] Message payload: 00000000: 00000002 00000000 00000001

This fails with -ENODATA as @kv2019i pointed out.
Since the pipelines failed to start the kernel is trying to stop the stream:
Set the pipelines to RESET state:

[   45.091007] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x13000002|0x1 [data size: 12]
[   45.091454] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x33000007|0x1
[   45.091467] sof-audio-pci-intel-mtl 0000:00:1f.3: FW reported error: 7 - Unsupported operation requested
[   45.091566] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc error for msg 0x13000002|0x1
[   45.091581] Message payload: 00000000: 00000002 00000001 00000000

This fails as the failed pipeline remained in PREPARED state, from which taking the RESET state is not allowed by the state machine.

I don't know why reverting #8084 helps, we should be failing in a same way?

[kv2019i]

@abonislawski and note, if we revert 8084, we'll get a known issue back -> #8084 (comment)

[kv2019i]

I think the AEC is in the pipeline is somehow breaking the ENODATA logic. The ENODATA condition should not be returned for this pipeline, so something goes wrong. I don't see immediate connection to 8084, it might be the problem has been masked before (not confirmed yet though). I recreated a similar branched raw dmic pipeline tplg, and the bug does not occur with latest SOF main.