thesofproject / linux

Linux kernel source tree
Other
91 stars 134 forks source link

LNL SDW "signal too weak" alsabat capture failure #5076

Open marc-hb opened 6 months ago

marc-hb commented 6 months ago

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:

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
marc-hb commented 6 months ago

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

marc-hb commented 5 months ago

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

marc-hb commented 5 months ago

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.

lgirdwood commented 5 months ago

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

plbossart commented 5 months ago

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

marc-hb commented 5 months ago

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

kv2019i commented 5 months ago

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.

kv2019i commented 5 months ago

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:

kv2019i commented 5 months ago

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
marc-hb commented 5 months ago

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

kv2019i commented 5 months ago

The kernel patch seems to help:

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

marc-hb commented 4 months ago

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

plbossart commented 4 months ago

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

marc-hb commented 4 months ago

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

kv2019i commented 3 months ago

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