alsaloop fails during second HFP call

[david-bouthillier]

Here's my scenario:

1. I use bluetoothctl to connect my phone to my embedded device (Toradex Verdin)
2. I initiate a phone call
3. I run alsaloop to route the phone audio and mic
4. I terminate the call on the phone
5. I ctrl+c the alsaloop script

Everything works fine the first time, but if I attempt to make a second call, there is no audio and I see errors in the logs and from alsaloop

This is the alsaloop script I run:

alsaloop -g /dev/stdin <<EOF
-C bluealsa:SRV=org.bluealsa,DEV=<phone_mac>,PROFILE=sco -P plughw:0 -r 8000 -c 1 -f s16_le -n -t 40000 -T 1
-C plughw:0 -P bluealsa:SRV=org.bluealsa,DEV=<phone_mac>,PROFILE=sco -r 8000 -c 1 -f s16_le -n -t 40000 -T 2
EOF

These are the errors in syslog:

Apr 15 13:31:25 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: E: BT socket disconnected: Connection reset by peer
Apr 15 13:31:25 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: E: BT socket disconnected: Transport endpoint is not connected
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 systemd-journald[196]: Forwarding to syslog missed 3 messages.
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 2): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 1): 3
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 1): 3
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:12 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:32:13 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 1): 3
Apr 15 13:32:13 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:13 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:13 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:14 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:14 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 1): 3
Apr 15 13:32:14 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:14 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:14 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:32:34 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 2): 1
Apr 15 13:32:37 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 3): 1
Apr 15 13:32:57 verdin-imx8mp-15006329 systemd-journald[196]: Forwarding to syslog missed 21 messages.
Apr 15 13:32:57 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 1): 2
Apr 15 13:32:57 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:32:57 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 2): 1
Apr 15 13:32:57 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:32:59 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:32:59 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 1): 2
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 2): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (3 != 2): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (1 != 0): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (0 != 2): 2
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: W: Missing mSBC packets (2 != 1): 1
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: E: BT socket disconnected: Connection reset by peer
Apr 15 13:33:01 verdin-imx8mp-15006329 bluealsa[745]: /usr/bin/bluealsa: E: BT socket disconnected: Transport endpoint is not connected

These are the errors from the second execution of the alsaloop script:

root@verdin-imx8mp-15006329:~# ./alsa-call.sh 
^CALSA lib ../../../git/src/asound/bluealsa-pcm.c:1313:(_snd_pcm_bluealsa_open) Couldn't get BlueALSA PCM: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
ALSA lib ../../../git/src/asound/bluealsa-pcm.c:1313:(_snd_pcm_bluealsa_open) Couldn't get BlueALSA PCM: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
playback bluealsa:SRV=org.bluealsa,DEV=A0:56:F3:97:94:4C,PROFILE=sco open error: No such device
Loopback initialization failure.
capture bluealsa:SRV=org.bluealsa,DEV=A0:56:F3:97:94:4C,PROFILE=sco open error: No such device
Loopback initialization failure.

Bluealsa version is v4.0.0

Toradex info:

Software summary
------------------------------------------------------------
Bootloader:               U-Boot
Kernel version:           5.15.129-6.4.0-devel+git.67c3153d20ff #1 SMP PREEMPT Wed Sep 27 12:30:36 UTC 2023
Kernel command line:      root=PARTUUID=019a2196-02 ro rootwait console=tty1 console=ttymxc2,115200 consoleblank=0 earlycon
Distro name:              NAME="TDX Wayland with XWayland"
Distro version:           VERSION_ID=6.4.0-devel-20231220205908-build.0
Hostname:                 verdin-imx8mp-15006329
------------------------------------------------------------

Hardware info
------------------------------------------------------------
HW model:                 Toradex Verdin iMX8M Plus WB on Verdin Development Board
Toradex version:          0058 V1.1A
Serial number:            15006329
Processor arch:           aarch64
------------------------------------------------------------

Any thoughts? Thanks!

[borine]

In your alsaloop errors:

... the reply timeout expired ...

Looks like the bluealsa daemon has stopped responding - most likely a bug in release 4.0.0

I recommend updating to release 4.1.1, or even better to the latest master branch, so that you get all the available bug fixes. If the problem still exists with the current release, then please raise an issue rather than a discussion so it can be tracked as a potential bug in the current release.

[david-bouthillier]

@borine upgrading to v4.1.1-86-gb7bb861 seems to have fixed my issue! Thanks!