search

bluez / bluez

Main BlueZ tree
https://bluez.github.io/bluez/
GNU General Public License v2.0
705 stars 267 forks source link

MIDI connection problems leading to ALSA sequencer connection leaks and ALSA backend crash #225

Open Jajcus opened 2 years ago

Jajcus commented 2 years ago

These are probably at least two bugs. One, which causes the connection problems (might be outside of bluez) and the other which is bluetoothd not handling the errors gracefully.

I am trying to use Bluetooth for communication between Raspberry Pi Zero W and Vox Adio Air GT amplifier. I have no problem connecting to the amplifier via BT from my Linux laptop. (no problem on laptop as MIDI support is not compiled-in in the Ubuntu package) Android phone also connects, though I am not able to verify if the connection works there.

On the Raspberry Pi, though, connection attempt ends in a connect/disconnect loop. bluetoothd tries the connection again and again, creating a new ALSA sequencer client on each attempt. Eventually bluetoothd freezes and the whole ALSA sequencer stack stops working.

The logs below are from bluez 5.54-1~bpo10+1 (self compiled package from buster-backports, as the Debian binary won't work), but I had the same problem with the 5.50-1.2~deb10u2+rpt1 package from Raspbian.

bluetoothd logs excerpt:

Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 10:98:C3:55:19:B1 type 1 status 0x5
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_complete() bonding (nil) status 0x05
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_failed() status 5
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:resume_discovery()
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:dev_disconnected() Device 10:98:C3:55:19:B1 disconnected, reason 2
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:adapter_remove_connection()
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 10:98:C3:55:19:B1 type 1 status 0xe
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_failed() status 14
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:resume_discovery()
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: MIDI I/O: Failed to read initial request
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:att_disconnected_cb()
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/device.c:att_disconnected_cb() Software caused connection abort (103)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x2810c0: device 10:98:C3:55:19:B1 profile gap-profile state changed: connected -> disconnecting (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x2810c0: device 10:98:C3:55:19:B1 profile gap-profile state changed: disconnecting -> disconnected (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286cd8: device 10:98:C3:55:19:B1 profile deviceinfo state changed: connected -> disconnecting (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286cd8: device 10:98:C3:55:19:B1 profile deviceinfo state changed: disconnecting -> disconnected (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286fb8: device 10:98:C3:55:19:B1 profile MIDI GATT Driver state changed: connected -> disconnecting (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: profiles/midi/midi.c:midi_disconnect() MIDI GATT Driver profile disconnect (10:98:C3:55:19:B1)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286fb8: device 10:98:C3:55:19:B1 profile MIDI GATT Driver state changed: disconnecting -> disconnected (0)
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/gatt-database.c:btd_gatt_database_att_disconnected()
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: attrib/gattrib.c:g_attrib_unref() 0x27aa20: g_attrib_unref=0
Oct 31 16:33:07 vaafootswitch bluetoothd[360]: src/adapter.c:connected_callback() hci0 device 10:98:C3:55:19:B1 connected eir_len 21
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: attrib/gattrib.c:g_attrib_ref() 0x29e2b0: g_attrib_ref=1
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:gap_accept() GAP profile accept (10:98:C3:55:19:B1)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:handle_characteristic() Unsupported characteristic: 00002a02-0000-1000-8000-00805f9b34fb
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:handle_characteristic() Unsupported characteristic: 00002a04-0000-1000-8000-00805f9b34fb
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x2810c0: device 10:98:C3:55:19:B1 profile gap-profile state changed: disconnected -> connected (0)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/deviceinfo/deviceinfo.c:deviceinfo_accept() deviceinfo profile accept (10:98:C3:55:19:B1)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported characteristic: 00002a29-0000-1000-8000-00805f9b34fb
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported characteristic: 00002a24-0000-1000-8000-00805f9b34fb
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286cd8: device 10:98:C3:55:19:B1 profile deviceinfo state changed: disconnected -> connected (0)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/midi/midi.c:midi_accept() MIDI GATT Driver profile accept (10:98:C3:55:19:B1)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/midi/midi.c:handle_midi_io() MIDI I/O handle: 0x001b
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/service.c:change_state() 0x286fb8: device 10:98:C3:55:19:B1 profile MIDI GATT Driver state changed: disconnected -> connected (0)
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:read_device_name_cb() GAP Device Name: Adio Air GT MIDI
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x0080
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 10:98:C3:55:19:B1 type 1 status 0x5
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_complete() bonding (nil) status 0x05
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_failed() status 5
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:resume_discovery()
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:dev_disconnected() Device 10:98:C3:55:19:B1 disconnected, reason 2
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:adapter_remove_connection()
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 10:98:C3:55:19:B1 type 1 status 0xe
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/device.c:device_bonding_failed() status 14
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: src/adapter.c:resume_discovery()
Oct 31 16:33:08 vaafootswitch bluetoothd[360]: MIDI I/O: Failed to read initial request

aplaymidi -l report before the stack crashed:

 Port    Client name                      Port name
 14:0    Midi Through                     Midi Through Port-0
128:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
129:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
130:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
131:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
132:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
133:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
134:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
135:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
136:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
137:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
138:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
139:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
140:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
141:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth
142:0    Adio Air GT MIDI                 Adio Air GT MIDI Bluetooth

Eventually bluetoothd stops with:

Oct 31 16:51:28 vaafootswitch bluetoothd[360]: profiles/midi/midi.c:midi_accept() MIDI GATT Driver profile accept (10:98:C3:55:19:B1)
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: Could not open ALSA Sequencer: Cannot allocate memory (-12)
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: MIDI GATT Driver profile accept failed for 10:98:C3:55:19:B1
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:btd_gatt_client_ready() GATT client ready
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:create_services() Exporting objects for GATT services: 10:98:C3:55:19:B1
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service000c
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service000c/char000d
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service000c/char000d/desc000f
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0010
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0010/char0011
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0010/char0013
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0015
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0015/char0016
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_10_98_C3_55_19_B1/service0015/char0016/desc0018
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:btd_gatt_client_ready() Features 0x00
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/gatt-client.c:btd_gatt_client_ready() Update Features 0x00
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_10_98_C3_55_19_B1 err 0
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: src/device.c:gatt_debug() Registered handler for "Service Changed": 1
Oct 31 16:51:28 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:read_device_name_cb() GAP Device Name: Adio Air GT MIDI
Oct 31 16:51:29 vaafootswitch bluetoothd[360]: profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x0080

And aplaymidi fails with:

ALSA lib seq_hw.c:466:(snd_seq_hw_open) open /dev/snd/seq failed: Cannot allocate memory
Cannot open sequencer - Cannot allocate memory

I wonder if such a MIDI connection attempt can be initiate from outside. If so, then this is a possible DoS attack vector.

bluetoothd-logs.txt pi-connect.btsnoop.gz

Jajcus commented 2 years ago

Update: my mistake. The problem is not limited to Raspberry Pi. The same happens on Ubuntu laptop when the bluez package is built with MIDI support.