Occasional crashes when streaming from iPhone to bluealsa

[maxmitti]

Problem

My setup consists of bluealsa as a sink with bluealsa-aplay for playback through speakers.

bluealsa randomly crashes with segmentation fault. Streaming is usually done from an iPhone. Since the last update, the crashes happen daily.

Reproduction steps

bluealsa and bluealsa-aplay are run via systemd.

bluealsa -p a2dp-source -p a2dp-sink --a2dp-volume
bluealsa-aplay -Ddefault:CARD=RPiCirrus --single-audio --pcm-buffer-time=50000 --pcm-period-time=10000 --mixer-device=default:CARD=RPiCirrus "--mixer-name=Speaker Digital"

No manual ALSA configuration was done.

The iPhone is playing music via YouTube when the crash happens.

Setup

• Arch Linux ARM 32 Bit on Raspberry Pi 3, updated on 2024-02-13
• bluealsa --version v4.1.1 commit b6b4412 (master)

    ./configure --prefix=/usr --sysconfdir=/etc 
                  --enable-aac
                  --enable-cli
                  --enable-debug
                  --enable-manpages
                  --enable-ofono
                  --enable-systemd
                  --enable-upower

• bluetoothd --version 5.72
• aplay --version 1.2.11

Additional context

Log before the crash:

07:31:40 D: ba-transport.c:1049: Starting transport: A2DP Sink (AAC)
07:31:40 D: ba-transport-pcm.c:286: Created BT socket duplicate: [14]: 17
07:31:40 D: ba-transport-pcm.c:365: Created new IO thread [ba-a2dp-aac]: A2DP Sink (AAC)
07:31:40 D: a2dp-aac.c:386: PCM IO loop: START: a2dp_aac_dec_thread: A2DP Sink (AAC)
07:31:40 D: a2dp-aac.c:435: Fragmented RTP packet [1]: LATM len: 42
07:31:40 D: a2dp-aac.c:435: Fragmented RTP packet [2]: LATM len: 42
07:31:40 W: a2dp-aac.c:418: Activating RTP mark bit quirk workaround
07:31:41 D: bluealsa-dbus.c:933: Setting volume: 61 [-10.57 dB] <> 61 [-10.57 dB]
07:34:13 E: a2dp-aac.c:446: AAC decode frame error: Unsupported gain control data
07:35:31 W: rtp.c:145: Missing RTP packets [9796 != 9787]: 9
07:35:31 E: a2dp-aac.c:446: AAC decode frame error: Transport sync error
07:35:31 W: rtp.c:145: Missing RTP packets [9872 != 9868]: 4
07:35:56 systemd[1]: bluealsa.service: Main process exited, code=dumped, status=11/SEGV

Backtrace:

(gdb) bt
#0  0xb6e2d4b8 in ??? () at /usr/lib/libfdk-aac.so.2
#1  0xb6e30e5c in ??? () at /usr/lib/libfdk-aac.so.2
#2  0xb6e8b6d8 in ??? () at /usr/lib/libfdk-aac.so.2
#3  0xb6e8bb24 in ??? () at /usr/lib/libfdk-aac.so.2
#4  0xb6e8c108 in ??? () at /usr/lib/libfdk-aac.so.2
#5  0xb6e8f1a0 in ??? () at /usr/lib/libfdk-aac.so.2
#6  0xb6e31c38 in aacDecoder_DecodeFrame () at /usr/lib/libfdk-aac.so.2
#7  0x0045c440 in a2dp_aac_dec_thread (t_pcm=0x0) at a2dp-aac.c:445
#8  0xb68ac140 in ??? () at /usr/lib/libc.so.6
#9  0xb692dd1c in ??? () at /usr/lib/libc.so.6

Coredump is available, in case further information is wanted.

[arkq]

Can you provide logs when the iPhone is just connected? I'd like to see selected A2DP configuration - log lines with A2DP peer capabilities blob: xxxx and A2DP selected configuration blob: xxxx.

EDIT: And also line with: FDK-AAC decoder capabilities:

[maxmitti]

peer capabilities:

15:44:23 D: bluez.c:1367: Adding new Stream End-Point: 70:F0:87:A1:71:19: SRC: SBC
15:44:23 D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SelectConfiguration() on /org/bluez/hci0/A2DP/AAC/sink/1
15:44:23 D: bluez.c:452: A2DP peer capabilities blob [len=6]: 80010483e800
15:44:23 D: bluez.c:1296: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_70_F0_87_A1_71_19/player0/NowPlaying/item184467440>
15:44:23 D: bluez.c:1296: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_70_F0_87_A1_71_19/sep3/fd10, ...)
15:44:23 D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SetConfiguration() on /org/bluez/hci0/A2DP/AAC/sink/1
15:44:23 D: storage.c:123: Loading storage: /var/lib/bluealsa/70:F0:87:A1:71:19
15:44:23 D: bluez.c:593: A2DP Sink (AAC) configured for device 70:F0:87:A1:71:19
15:44:23 D: bluez.c:596: A2DP selected configuration blob [len=6]: 800104835b60
15:44:23 D: bluez.c:598: PCM configuration: channels: 2, sampling: 44100
15:44:23 D: dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_70_F0_87_A1_71_19/a2dpsnk/source

FDK-AAC capabilities:

09:41:18 D: a2dp-aac.c:653: FDK-AAC encoder capabilities: aac=0x410b1 sbr=0x22
09:41:18 D: a2dp-aac.c:739: FDK-AAC decoder capabilities: aac=0x1a4ffff sbr=0x1bf dmx=0x7f
09:41:18 D: storage.c:90: Initializing persistent storage: /var/lib/bluealsa
09:41:18 D: main.c:632: Starting main dispatching loop

[arkq]

Since the last update, the crashes happen daily.

The selected configuration (and capabilities) should not interfere with recent update in bluealsa code in respect to AAC support. What kind of update you have in mind? Update of bluealsa or whole distribution? Because it is possible that the bug is in the fdk-aac library... Can you post the version of the library (on Debian you can use dpkg -s libfdk-aac2?

Also (if possible) I'd like to have the faulty stream (If the crash happens quickly after connecting the device). Then I could replay it on my side in order to preproduce the issue. Please, collect Bluetooth traffic with (start this command BEFORE you connect phone with your host):

sudo tcpdump -i bluetooth0 -w /tmp/bluealsa-aac-crash.pcap  

[maxmitti]

Sorry for the unclear wording. For a long time I was using v4.0, where the crashes also happened, but less frequently. Recently I updated to v4.1.1 and then the mentioned commit. Both versions seem to crash more frequently now.

The libfdk-aac version is 2.0.3. Before the update it was 2.0.2.

I have to look into capturing the stream another time.

[borine]

I'm getting a SIGSEGV failure in the bluealsa server when using AAC with a2dp-source profile. I'm assuming this is the same underlying fault as reported here for a2dp-sink.

git bisect reveals that the fault first occurs with commit 4495c7c "Adopt AAC encoder/decoder to A2DP spec v1.4". The previous commit 70249cf does not have this fault (@maxmitti could you try building bluealsa at commit 70249cf to see if that works for you?)

My system is Ubuntu 22.04.4 LTS libfdk-aac 2.0.2 bluez 5.64

Server log for connection configuration:

bluealsa: [69408] D: ../../src/bluez.c:452: A2DP peer capabilities blob [len=6]: dfffff835b60
...
bluealsa: [69408] D: ../../src/bluez.c:596: A2DP selected configuration blob [len=6]: 040014035b60
bluealsa: [69408] D: ../../src/bluez.c:598: PCM configuration: channels: 2, sampling: 9600

Server log playing audio with aplay -D bluealsa:

bluealsa: [105699] D: ../../src/dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_5C_F3_70_9B_FB_1A/a2dpsrc/sink
bluealsa: [105699] D: ../../src/ba-transport.c:319: New A2DP transport: 18
bluealsa: [105699] D: ../../src/ba-transport.c:320: A2DP socket MTU: 18: R:672 W:672
bluealsa: [105584] D: ../../src/bluez.c:1485: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [105584] D: ../../src/ba-transport.c:1055: Starting transport: A2DP Source (AAC)
bluealsa: [105584] D: ../../src/ba-transport-pcm.c:286: Created BT socket duplicate: [18]: 19
bluealsa: [105584] D: ../../src/ba-transport-pcm.c:365: Created new IO thread [ba-a2dp-aac]: A2DP Source (AAC)
bluealsa: [105700] D: ../../src/a2dp-aac.c:230: PCM IO loop: START: a2dp_aac_enc_thread: A2DP Source (AAC)
bluealsa: [105584] D: ../../src/ba-transport-pcm.c:472: PCM resume: 14
Segmentation fault

gdb shows:

Thread 9 "ba-a2dp-aac" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff623a640 (LWP 115020)]
0x00007ffff7f0ba09 in FDKsbrEnc_PSEnc_ParametricStereoProcessing (samplesBufSize=3685, sendHeader=1, qmfScale=<synthetic pointer>, sbrSynthQmf=0x7fffe0004c38, downsampledOutSignal=0x7fffe0000e60, downmixedImagQmfData=0x7fffe000efa8, downmixedRealQmfData=0x7fffe000eea8, hQmfAnalysis=0x7fffe000dae0, samples=0x7ffff6237d10, hParametricStereo=0x3dd03aa0387037a) at libSBRenc/src/ps_main.cpp:481
481	libSBRenc/src/ps_main.cpp: No such file or directory.
(gdb) bt
#0  0x00007ffff7f0ba09 in FDKsbrEnc_PSEnc_ParametricStereoProcessing(T_PARAMETRIC_STEREO*, short**, unsigned int, QMF_FILTER_BANK**, int**, int**, short*, QMF_FILTER_BANK*, signed char*, int)
    (samplesBufSize=3685, sendHeader=1, qmfScale=<synthetic pointer>, sbrSynthQmf=0x7fffe0004c38, downsampledOutSignal=0x7fffe0000e60, downmixedImagQmfData=0x7fffe000efa8, downmixedRealQmfData=0x7fffe000eea8, hQmfAnalysis=0x7fffe000dae0, samples=0x7ffff6237d10, hParametricStereo=0x3dd03aa0387037a) at libSBRenc/src/ps_main.cpp:481
#1  FDKsbrEnc_EnvEncodeFrame(SBR_ENCODER*, int, short*, unsigned int, unsigned int*, unsigned char*, int)
    (hEnvEncoder=<optimised out>, iElement=<optimised out>, samples=<optimised out>, samplesBufSize=<optimised out>, sbrDataBits=<optimised out>, sbrData=<optimised out>, clearOutput=<optimised out>)
    at libSBRenc/src/sbr_encoder.cpp:1119
#2  0x00007ffff7e9aedb in sbrEncoder_EncodeFrame (sbrData=<optimised out>, sbrDataBits=<optimised out>, samplesBufSize=3685, samples=0x7fffe0000e60, hSbrEncoder=0x7fffe0004800)
    at libSBRenc/src/sbr_encoder.cpp:2392
#3  aacEncEncode(HANDLE_AACENCODER, AACENC_BufDesc const*, AACENC_BufDesc const*, AACENC_InArgs const*, AACENC_OutArgs*)
    (hAacEncoder=<optimised out>, inBufDesc=inBufDesc@entry=0x7ffff6239a70, outBufDesc=outBufDesc@entry=0x7ffff6239aa0, inargs=inargs@entry=0x7ffff62399f8, outargs=outargs@entry=0x7ffff6239a00)
    at libAACenc/src/aacenc_lib.cpp:1934
#4  0x00005555555753b3 in a2dp_aac_enc_thread (t_pcm=0x5555555ca670) at ../../src/a2dp-aac.c:252
#5  0x00007ffff7694ac3 in start_thread (arg=<optimised out>) at ./nptl/pthread_create.c:442
#6  0x00007ffff7726850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
(gdb) 

[borine]

When using commit 4495c7c or later, the selected audio object type is AOT_PS ("parametric stereo"), whereas with commit 70249cf or earlier the audio object type is AOT_AAC_LC ("low complexity").

For a quick test, I checked out the current master branch head (commit 1c1e9c0) and added aot = AOT_AAC_LC; to src\a2dp-aac.c at line 126, and now AAC encoding (playback) is working fine again on master branch. So the problem appears to be with selecting or handling the aac audio object type.

I do not know if the decoder (capture) failure is the same underlying problem, but it is possible since clearly there is some error in BlueALSA's handling of the aac audio object type.

[borine]

Hmm, so I purged the Ubuntu libfdk-aac* packages, and built libfdk-aac myself from source. Now bluealsa AAC encoding works fine. Unistalled my build, re-installed the ubuntu packages, rebuilt bluealsa, Same failure as before. So it looks like my problem was caused by the Ubuntu libfdk-aac 2.0.2 packages, and maybe is not related to this issue at all.

[maxmitti]

@borine since you figured it out and it is also an encoding issue, not decoding, I will not look into this.

@arkq I was considering to record the bluetooth data, however the crashes occur less often now. Would it still be useful if it spanned multiple days of passed time containing hours of active playback?

[arkq]

Would it still be useful if it spanned multiple days of passed time containing hours of active playback?

Maybe, but since borine has also reproduced the issue, I think that the dump is not required. The crash is inside AAC library after feeding in some (corrupted or not) data. That's definitely libraries fault. Encoder should not crash even after feeding it with random bytes. Otherwise, it might be a potential security vulnerability.... I suggest changing (upgrading or downgrading) fdk-aac packet.

[maxmitti]

Sorry for the late reply.

I haven’t tried anything new, but my setup changed and now it seems quite stable.

The whole setup is running on a Raspberry Pi 3. Previously, I was using WiFi for network. Somehow WiFi got very unstable (possibly my configuration fault), which led me to switch to wired network and seems to also have fixed the crashes.

My assumption now is, that WiFi-Bluetooth coexistence issues caused a high rate of transmission errors, which in turn caused the crashes.

[arkq]

My assumption now is, that WiFi-Bluetooth coexistence issues caused a high rate of transmission errors, which in turn caused the crashes.

Yes, that could be the reason. Anyway, the real cause of the crash is definitely fdk-aac decoder. Recently, I've also discovered many issues with encoder (with certain configuration) on my Debian 12 installation, which is shipped with fdk-aac v2.0.2. The solution was to bump fdk-aac to v2.0.3: https://github.com/mstorsjo/fdk-aac/releases/tag/v2.0.3

Since this issue is not directly related to BlueALSA code, I'm closing this issue.

[maxmitti]

Ok.

Just for your information, I have been using fdk-aac v2.0.3 since 2024-01-20, i.e. all the time. Anyway, I have made a new observation. I installed kodi and while it is running crashes are happening much more often. I therefor revised my hypothesis to the chance of crashes being related with high CPU usage.

Is it possible to disable AAC and use a different codec instead?

[arkq]

Is it possible to disable AAC and use a different codec instead?

Yes, you can disable AAC with command line option -c -aac, e.g.: bluealsad -p a2dp-sink -c -aac