linux LNL SDW "signal too weak" alsabat capture failure

Originally posted by @marc-hb in https://github.com/thesofproject/linux/issues/4681#issuecomment-2125436314

"signal too weak" failure in daily test run 41404?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599, see logs below.

EDIT: also in https://sof-ci.01.org/sofpr/PR9159/build4831/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-821

cc:

thesofproject/linux#4681
thesofproject/sof#9164
https://github.com/thesofproject/sof/issues/8809

2024-05-22 14:27:58 UTC [REMOTE_COMMAND] alsabat -Phw:CODEC,0 --standalone -n 240000 -r 48000 -c 2 -f S16_LE -F 599 -k 2.1
2024-05-22 14:27:59 UTC [REMOTE_COMMAND] alsabat -Chw:sofsoundwire,1 -c 2 -r 48000 -f S16_LE -F 599 -k 2.1
WARNING: Signal too weak!
 FAIL: Peak freq too low 7.32 Hz
 FAIL: Peak freq too low 13.18 Hz
 FAIL: Peak freq too low 16.11 Hz
 FAIL: Peak freq too low 17.58 Hz
 FAIL: Peak freq too low 24.90 Hz
 FAIL: Peak freq too low 42.48 Hz
 FAIL: Peak freq too low 56.40 Hz
 FAIL: Peak freq too low 65.19 Hz
 FAIL: Peak freq too low 68.12 Hz
 FAIL: Peak freq too low 71.04 Hz
alsa-utils version 1.2.6

Entering capture thread (ALSA).
Get period size: 3000  buffer size: 24000
Recording ...
Capture completed.

BAT analysis: signal has 65536 frames at 48000 Hz, 2 channels, 2 bytes per sample.

Channel 1 - Checking for target frequency 599.00 Hz
Amplitude: 1.1; Percentage: [0]
Detected peak at 7.32 Hz of 3.97 dB
 Total 4.0 dB from 7.32 to 7.32 Hz
Detected peak at 13.18 Hz of 4.88 dB
 Total 9.1 dB from 13.18 to 13.92 Hz
Detected peak at 16.11 Hz of 4.13 dB
 Total 10.3 dB from 16.11 to 16.11 Hz
Detected peak at 17.58 Hz of 8.03 dB
 Total 12.3 dB from 17.58 to 17.58 Hz
Detected peak at 24.90 Hz of 9.65 dB
 Total 19.1 dB from 19.78 to 27.10 Hz
Detected peak at 42.48 Hz of 11.11 dB
 Total 25.1 dB from 29.30 to 53.47 Hz
Detected peak at 56.40 Hz of 10.20 dB
 Total 25.8 dB from 55.66 to 60.79 Hz
Detected peak at 65.19 Hz of 9.45 dB
 Total 26.3 dB from 62.26 to 66.65 Hz
Detected peak at 68.12 Hz of 10.30 dB
 Total 26.5 dB from 68.12 to 69.58 Hz
Detected peak at 71.04 Hz of 7.98 dB
 Total 26.6 dB from 71.04 to 71.78 Hz
Detected at least 10 signal(s) in total

Return value is -1003

May 23 '24 17:05 marc-hb

Again in https://sof-ci.01.org/sofpr/PR9159/build4831/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-821

https://sof-ci.01.org/linuxpr/PR5009/build3170/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

https://sof-ci.01.org/sofpr/PR9174/build4946/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

https://sof-ci.01.org/sofpr/PR9168/build4905/devicetest/index.html

May 23 '24 17:05 marc-hb

Still happening with B0 and April BIOS: https://sof-ci.01.org/softestpr/PR1203/build477/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

Jun 04 '24 20:06 marc-hb

In this run, alsabat playback failed first: https://sof-ci.01.org/softestpr/PR1204/build488/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-playback-997

Underrun: Broken pipe(-32)

Then all capture failed too but not as "usual". The playback failure seems to have left a bad state behind.

Jun 06 '24 05:06 marc-hb

@singalsu @plbossart could this be DC ? 50/60Hz peaks could also be mains power ?

Jun 07 '24 17:06 lgirdwood

I'd like to park this issue until we've solved the more important Controller Timeout and initialization failed. Walk then run, etc.

Jun 07 '24 20:06 plbossart

I'd like to park this issue until we've solved the more important Controller Timeout and initialization failed.

"Signal too weak" just spotted after the SDW clock fix was merged:

https://sof-ci.01.org/softestpr/PR1205/build514/devicetest/index.html

Jun 17 '24 23:06 marc-hb

If you look at instances seen today in PR testing like this: https://sof-ci.01.org/softestpr/PR931/build518/devicetest/index.html

There's a seemingly a fairly clean reference sine tone recorded, it's just very weak signal just barely above noise floor (so the test fails as it should). Another alsabat did pass just on the same machine and all alsamixer settings were the same. Cannot immediately explain how this could happen.

If we compare to other open alsabat cases like https://github.com/thesofproject/sof/issues/9164 (on HDA), this looks distinctly different. The occurence rate seems higher, and the failure looks (and sounds) very different.

Jun 18 '24 08:06 kv2019i

This starts to look like a codec/setup issue with rt711. I logged on to one CI machine that triggers the issue and run the tests manually. I can obverse:

I can reproduce the error, very weak signal in captured by "sofsoundwire,1" (rt711 headset codec)
if I run the test in the loop, sometimes test passes, sometimes not (DUT not rebooted, drivers not reloaded, only thing is a runtime suspend to both codec and DSP in between succesful and failing cases)
if I boost rt711 ADC gains when the error happens, I can see increased gain in captured signal by the DSP, so seems the DSP is working properly... codec is just not providing correct data
I tried playing with "GE49 selected mode" control when the error happens, but this has not impact (at least when modifying the value during streaming)

Jun 18 '24 10:06 kv2019i

Seems there is connection to headset detection. In failing cases, the rt711_sdca_headset_detect() function is called twice. The results are the same, but in failing case this is just done twice upon codec runtime resume.

fail:
[ 8970.354034] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x0
[ 8970.829012] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x5
[ 8970.865427] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x5

success:
[ 9042.534222] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x0
[ 9042.927780] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x5

Jun 18 '24 12:06 kv2019i

https://sof-ci.01.org/softestpr/PR931/build518/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

June 18th: https://sof-ci.01.org/softestpr/PR1206/build536/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

June 20th: https://sof-ci.01.org/softestpr/PR1180/build552/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-821

Jun 18 '24 17:06 marc-hb

The kernel patch seems to help:

https://github.com/thesofproject/linux/pull/5075 https://sof-ci.01.org/linuxpr/PR5075/build3762/devicetest/index.html

This confirms the hypothesis, so moving the bug to kernel.

Jun 20 '24 10:06 kv2019i

I noticed that ba-twln-rvp-sdw-01 fails all alsabat tests 100% of the time in daily runs with "Signal too weak". It uses RT711 too.

Latest daily run today: 43530?model=TWLN_RVP_SDW-ipc4&testcase=check-alsabat-headset-capture-599

July 12th reproduction: https://sof-ci.01.org/sofpr/PR9298/build6450/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-playback-599

Jul 05 '24 21:07 marc-hb

TWL is 2 generations older than LNL, this should be a different issue.

Jul 15 '24 10:07 plbossart

Today's failure. Same or different bug?

  Overrun: Broken pipe(-32)
 FAIL: Peak freq too low 388.18 Hz
 FAIL: Peak freq too low 400.63 Hz
 FAIL: Peak freq too low 588.13 Hz
 FAIL: Peak freq too high 612.30 Hz

https://sof-ci.01.org/sofpr/PR9305/build6540/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

Same in Aug 6th daily 44550?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-997

EDIT: still failing in August 12th daily run 44671?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-capture-599

August 14th https://sof-ci.01.org/sofpr/PR9351/build6997/devicetest/index.html?model=LNLM_SDW_AIOC&testcase=check-alsabat-headset-playback-599

Jul 16 '24 18:07 marc-hb

Tested alsabat on another LNL system with a headset-codec <-> dmic acoustic loop, and I could not reproduce these failures. I was using sof-dev as of today and SOF2.10 FW release. The DUT configuration is different, so this is not fully comparable to the original setup, but at least one positive test setup with USB-audio excluded from test setup. FYI @ssavati @jsarha

Aug 23 '24 15:08 kv2019i

Not seen in PR/daily tests for a week, closing.

Dec 13 '24 11:12 kv2019i