arkq
No sound from Onkyo receiver
Problem
No sound from Onkyo receiver with bluealsa. Onkyo receiver works fine with blueman and gnome bluetooth settings. With blueman had to change sound from AAC to SBC to enable sound. No changes required for gnome settings. Attempts to play sound through the bluealsa device and bluealsa plugin always crashes the playback program and the playback program requires kill -KILL to stop the program other methods to stop the program do not work. Bluealsa works fine with several different bluetooth speakers.
Reproduction steps
1) Started bluealsa service
2) Used bluetootctl to connect onkyo receiver.
3) Attempted play audio with speaker-test. Also tried other programs
no success.
There is no .asoundrc file installed.
Setup
the OS distribution and version
Arch Linux (update rolling release)
the version of BlueALSA (bluealsa --version -- v4.1.1)
the version of BlueZ (bluetoothd --version -- 5.69)
the version of ALSA (aplay --version -- 1.2.9)
the version of speaker-test 1.2.9
if self-built from source, please state the branch and commit
(git log -1 --oneline), and the used configure options.
Note: Built for the AUR for arch linux with debugging support.
git log -1 --oneline -- 78a74d6 Update to 4.1.1
From the PKGBUILD file from the AUR for arch linux.
optdepends=( 'lame: build with mp3 support'
'libbsd: build with hcitop tool'
'libopenaptx-git: build with libopenaptx for apt-X'
'mpg123: build with mpg123 decoding support'
'ncurses: build with hcitop tool'
'readline: build with bluealsa-rfcomm tool'
'spandsp: build mSBC codec support'
'enable-debug: build debugging support' )
Add any other context about the problem here, e.g. log messages printed by
bluealsa and/or client application.
Used two different bluetooth devices on two different computers:
Bus 001 Device 003: ID 8087:0a2a Intel Corp. Bluetooth wireless interface
Bus 001 Device 005: ID 0bda:2550 Realtek Semiconductor Corp. Bluetooth Radio
bluealsa -S --keep-alive=5 -p a2dp-sink
bluealsa: [26110] D: a2dp-aac.c:141: FDK-AAC lib capabilities: dec:0x1a4ffff enc:0x410b1
buealsa: [26110] D: storage.c:84: Initializing persistent storage: /usr/var/lib/bluealsa
bluealsa: [26110] W: storage.c:87: Couldn't create storage directory: No such file or directory
bluealsa: [26110] D: main.c:604: Starting main dispatching loop
bluealsa: [26110] D: main.c:114: Acquired D-Bus service name: org.bluealsa
bluealsa: [26110] D: bluealsa-dbus.c:392: Registering D-Bus manager: /org/bluealsa
bluealsa: [26110] D: bluez.c:783: Registering battery provider: /org/bluez/hci0/battery
bluealsa: [26110] D: bluez.c:803: BlueZ battery provider support not available
bluealsa: [26110] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26110] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26110] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26110] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26110] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26110] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26110] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26110] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26110] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26110] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: SBC
bluealsa: [26110] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26110] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: AAC
bluealsa: [26110] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SelectConfiguration() on /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26110] D: bluez.c:280: A2DP peer capabilities blob [len=4]: ffff0228
bluealsa: [26110] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26110] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SetConfiguration() on /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26110] D: a2dp.c:383: Selected A2DP SBC bit-pool range: [2, 40]
bluealsa: [26110] D: storage.c:117: Loading storage: /usr/var/lib/bluealsa/00:09:B0:1C:CD:D4
bluealsa: [26110] D: bluez.c:420: A2DP Source (SBC) configured for device 00:09:B0:1C:CD:D4
bluealsa: [26110] D: bluez.c:423: A2DP selected configuration blob [len=4]: 11150228
bluealsa: [26110] D: bluez.c:425: PCM configuration: channels: 2, sampling: 48000
bluealsa: [26110] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/3
bluealsa: [26110] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/3
bluealsa: [26129] D: dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink
bluealsa: [26129] D: ba-transport.c:741: New A2DP transport: 18
bluealsa: [26129] D: ba-transport.c:742: A2DP socket MTU: 18: R:672 W:672
bluealsa: [26110] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26110] D: ba-transport.c:1528: Starting transport: A2DP Source (SBC)
bluealsa: [26110] D: ba-transport.c:448: Created BT socket duplicate: [18]: 19
bluealsa: [26110] D: ba-transport.c:1949: Created new IO thread [ba-a2dp-sbc]: A2DP Source (SBC)
bluealsa: [26130] D: codec-sbc.c:262: SBC setup: 48000 Hz JointStereo allocation=SNR blocks=16 sub-bands=8 bit-pool=40 => 279000 bps
bluealsa: [26130] D: a2dp-sbc.c:222: IO loop: START: a2dp_sbc_enc_thread: A2DP Source (SBC)
bluealsa: [26110] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26110] D: ba-transport.c:1838: PCM drain: 14
bluealsa: [26117] D: ba-transport.c:610: PCM clients check keep-alive: 0 ms
bluealsa: [26110] D: ba-transport.c:1858: PCM drained
bluealsa: [26110] D: ba-transport.c:1866: PCM drop: 14
bluealsa: [26110] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26110] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26130] D: ba-transport.c:462: Closing BT socket duplicate [18]: 19
bluealsa: [26130] D: ba-transport.c:795: Closing A2DP transport: 18
bluealsa: [26130] D: ba-transport.c:1983: Exiting IO thread [ba-a2dp-sbc]: A2DP Source (SBC)
bluealsa: [26141] D: a2dp-aac.c:141: FDK-AAC lib capabilities: dec:0x1a4ffff enc:0x410b1
bluealsa: [26141] D: storage.c:84: Initializing persistent storage: /usr/var/lib/bluealsa
bluealsa: [26141] W: storage.c:87: Couldn't create storage directory: No such file or directory
bluealsa: [26141] D: main.c:604: Starting main dispatching loop
bluealsa: [26141] D: main.c:114: Acquired D-Bus service name: org.bluealsa
bluealsa: [26141] D: bluealsa-dbus.c:392: Registering D-Bus manager: /org/bluealsa
bluealsa: [26141] D: bluez.c:783: Registering battery provider: /org/bluez/hci0/battery
bluealsa: [26141] D: bluez.c:803: BlueZ battery provider support not available
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/2
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/2
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/sink/1
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/sink/1
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/sink/2
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/sink/2
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26141] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26141] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: SBC
bluealsa: [26141] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26141] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: AAC
bluealsa: [26141] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SelectConfiguration() on /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26141] D: bluez.c:280: A2DP peer capabilities blob [len=6]: cffffc800000
bluealsa: [26141] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26141] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SetConfiguration() on /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26141] D: storage.c:117: Loading storage: /usr/var/lib/bluealsa/00:09:B0:1C:CD:D4
bluealsa: [26141] D: bluez.c:420: A2DP Source (AAC) configured for device 00:09:B0:1C:CD:D4
bluealsa: [26141] D: bluez.c:423: A2DP selected configuration blob [len=6]: 400014035b60
bluealsa: [26141] D: bluez.c:425: PCM configuration: channels: 2, sampling: 96000
bluealsa: [26141] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/3
bluealsa: [26141] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/3
bluealsa: [26161] D: dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink
bluealsa: [26161] D: ba-transport.c:741: New A2DP transport: 18
bluealsa: [26161] D: ba-transport.c:742: A2DP socket MTU: 18: R:672 W:672
bluealsa: [26141] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26141] D: ba-transport.c:1528: Starting transport: A2DP Source (AAC)
bluealsa: [26141] D: ba-transport.c:448: Created BT socket duplicate: [18]: 19
bluealsa: [26141] D: ba-transport.c:1949: Created new IO thread [ba-a2dp-aac]: A2DP Source (AAC)
bluealsa: [26162] D: a2dp-aac.c:339: IO loop: START: a2dp_aac_enc_thread: A2DP Source (AAC)
bluealsa: [26141] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26141] D: ba-transport.c:1838: PCM drain: 14
bluealsa: [26148] D: ba-transport.c:610: PCM clients check keep-alive: 0 ms
bluealsa: [26141] D: ba-transport.c:1858: PCM drained
bluealsa: [26141] D: ba-transport.c:1866: PCM drop: 14
bluealsa: [26141] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26141] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26162] D: ba-transport.c:462: Closing BT socket duplicate [18]: 19
bluealsa: [26162] D: ba-transport.c:795: Closing A2DP transport: 18
bluealsa: [26162] D: ba-transport.c:1983: Exiting IO thread [ba-a2dp-aac]: A2DP Source (AAC)
/usr/bin/bluealsa -p a2dp-source -p a2dp-sink
/usr/bin/bluealsa -p a2dp-source -p a2dp-sink
bluealsa: [26176] D: a2dp-aac.c:141: FDK-AAC lib capabilities: dec:0x1a4ffff enc:0x410b1
bluealsa: [26176] D: storage.c:84: Initializing persistent storage: /usr/var/lib/bluealsa
bluealsa: [26176] W: storage.c:87: Couldn't create storage directory: No such file or directory
bluealsa: [26176] D: main.c:604: Starting main dispatching loop
bluealsa: [26176] D: main.c:114: Acquired D-Bus service name: org.bluealsa
bluealsa: [26176] D: bluealsa-dbus.c:392: Registering D-Bus manager: /org/bluealsa
bluealsa: [26176] D: bluez.c:783: Registering battery provider: /org/bluez/hci0/battery
bluealsa: [26176] D: bluez.c:803: BlueZ battery provider support not available
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/2
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/2
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/sink/1
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/sink/1
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/sink/2
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/sink/2
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/1
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/2
bluealsa: [26176] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26176] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: SBC
bluealsa: [26176] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26176] D: bluez.c:1290: Adding new Stream End-Point: 00:09:B0:1C:CD:D4: SNK: AAC
bluealsa: [26176] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SelectConfiguration() on /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26176] D: bluez.c:280: A2DP peer capabilities blob [len=6]: cffffc800000
bluealsa: [26176] D: bluez.c:1199: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
bluealsa: [26176] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SetConfiguration() on /org/bluez/hci0/A2DP/AAC/source/1
bluealsa: [26176] D: storage.c:117: Loading storage: /usr/var/lib/bluealsa/00:09:B0:1C:CD:D4
bluealsa: [26176] D: bluez.c:420: A2DP Source (AAC) configured for device 00:09:B0:1C:CD:D4
bluealsa: [26176] D: bluez.c:423: A2DP selected configuration blob [len=6]: 400014035b60
bluealsa: [26176] D: bluez.c:425: PCM configuration: channels: 2, sampling: 96000
bluealsa: [26176] D: bluez.c:598: Creating media endpoint object: /org/bluez/hci0/A2DP/AAC/source/3
bluealsa: [26176] D: bluez.c:509: Registering media endpoint: /org/bluez/hci0/A2DP/AAC/source/3
bluealsa: [26185] D: dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink
bluealsa: [26185] D: ba-transport.c:741: New A2DP transport: 18
bluealsa: [26185] D: ba-transport.c:742: A2DP socket MTU: 18: R:672 W:672
bluealsa: [26176] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26176] D: ba-transport.c:1528: Starting transport: A2DP Source (AAC)
bluealsa: [26176] D: ba-transport.c:448: Created BT socket duplicate: [18]: 19
bluealsa: [26176] D: ba-transport.c:1949: Created new IO thread [ba-a2dp-aac]: A2DP Source (AAC)
bluealsa: [26186] D: a2dp-aac.c:339: IO loop: START: a2dp_aac_enc_thread: A2DP Source (AAC)
bluealsa: [26176] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26176] D: ba-transport.c:1838: PCM drain: 14
bluealsa: [26182] D: ba-transport.c:610: PCM clients check keep-alive: 0 ms
bluealsa: [26176] D: ba-transport.c:1858: PCM drained
bluealsa: [26176] D: ba-transport.c:1866: PCM drop: 14
bluealsa: [26176] D: ba-transport.c:1822: PCM resume: 14
bluealsa: [26176] D: bluez.c:1407: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State
bluealsa: [26186] D: ba-transport.c:462: Closing BT socket duplicate [18]: 19
bluealsa: [26186] D: ba-transport.c:795: Closing A2DP transport: 18
bluealsa: [26186] D: ba-transport.c:1983: Exiting IO thread [ba-a2dp-aac]: A2DP Source (AAC)
^Cbluealsa: [26176] D: ba-transport.c:1891: Closing PCM: 14
Also tried
bluealsa -S -c-AAC --keep-alive=5 -p a2dp-sink
same results as above.
bluetoothctl --agent=NoInputNoOutput
hci0 new_settings: powered bondable ssp br/edr le secure-conn
Agent registered
[bluetooth]# default-agent
Default agent request successful
[bluetooth]# info 00:09:B0:1C:CD:D4
Device 00:09:B0:1C:CD:D4 (public)
Name: Onkyo TX-NR676 EE6F60
Alias: Onkyo TX-NR676 EE6F60
Class: 0x00240400 (2360320)
Icon: audio-card
Icon: audio-card
Paired: yes
Bonded: yes
Trusted: yes
Blocked: no
Connected: no
LegacyPairing: no
UUID: Audio Sink (0000110b-0000-1000-8000-00805f9b34fb)
UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
UUID: A/V Remote Control (0000110e-0000-1000-8000-00805f9b34fb)
UUID: PnP Information (00001200-0000-1000-8000-00805f9b34fb)
UUID: Generic Access Profile (00001800-0000-1000-8000-00805f9b34fb)
UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
Modalias: usb:v1D6Bp0246d0525
[bluetooth]# connect 00:09:B0:1C:CD:D4
Attempting to connect to 00:09:B0:1C:CD:D4
hci0 00:09:B0:1C:CD:D4 type BR/EDR connected eir_len 23
[CHG] Device 00:09:B0:1C:CD:D4 Connected: yes
[NEW] Endpoint /org/bluez/hci0/dev_00_09_B0_1C_CD_D4/sep1
[NEW] Endpoint /org/bluez/hci0/dev_00_09_B0_1C_CD_D4/sep2
[NEW] Transport /org/bluez/hci0/dev_00_09_B0_1C_CD_D4/sep2/fd2
Connection successful
[CHG] Device 00:09:B0:1C:CD:D4 ServicesResolved: yes
[Onkyo TX-NR676 EE6F60]#
bluealsa-aplay -L
bluealsa:DEV=00:09:B0:1C:CD:D4,PROFILE=a2dp,SRV=org.bluealsa
Onkyo TX-NR676 EE6F60, trusted audio-card, playback
A2DP (SBC): S16_LE 2 channels 48000 Hz
speaker-test 1.2.9
Playback device is bluealsa
Stream parameters are 48000Hz, S16_LE, 2 channels
Using 16 octaves of pink noise
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 960 to 262144
Period size range from 480 to 131073
Using max buffer size 262144
Periods = 4
was set period_size = 65536
was set buffer_size = 262144
0 - Front Left
[26183] D: bluealsa-pcm.c:620:
/org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[26183] D: bluealsa-pcm.c:629:
/org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail
min: 131072 -> 1
[26183] D: bluealsa-pcm.c:620:
/org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[26183] D: bluealsa-pcm.c:629:
/org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail
min: 1 -> 131072
[26183] D: bluealsa-pcm.c:667: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Draining
[26183] D: bluealsa-pcm.c:374: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting
[26187] D: bluealsa-pcm.c:229: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting IO loop: 7
[26187] D: bluealsa-pcm.c:238: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Pausing IO thread
[26183] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
[26187] D: bluealsa-pcm.c:165: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: IO thread cleanup
[26183] D: bluealsa-pcm.c:661: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Prepared
1 - Front Right
[26183] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[26183] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 131072 -> 1
[26183] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[26183] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 1 -> 131072
[26183] D: bluealsa-pcm.c:667: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Draining
[26183] D: bluealsa-pcm.c:374: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting
[26189] D: bluealsa-pcm.c:229: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting IO loop: 7
[26183] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
speaker-test hangs at this point. I have to kill the program or stop
bluealsa.
Onkyo TX-NR676 EE6F60 receiver
BLUETOOTH Specs
Communication system
BLUETOOTH Specification version 4.1+LE
Frequency band
2.4 GHz band
Modulation method
FHSS (Freq Hopping Spread Spectrum)
Compatible BLUETOOTH profiles
A2DP 1.2
AVRCP 1.3
HOGP-Host (Client)
HOGP-HID Device (Server)
HID Service (HIDS)
Supported Codecs
SBC
AAC
20 Hz - 20 kHz (Sampling frequency 44.1 kHz)
Maximum communication range
Line of sight approx. 15 m
`
Looking at the server logs, it appears that the Onkyo is dropping the A2DP transport soon after it has been acquired. Perhaps it has a timeout waiting for the first codec frames to arrive after acquisition, or perhaps it just does not like Bluez. Perhaps the bluetooth logs will give more clues as to why that is happening.
The speaker-test log is slightly worrying. I have no idea why it hangs. The final "Stopping" message shows that the BlueALSA plugin has sent the thread cancel signal to its IO thread, but the lack of "IO thread cleanup" after that may indicate that the signal is not received. I cannot explain how that can happen; but, whatever, I think that this is a consequence of the above transport failure and not a cause of it.
Thanks for the response. I thought I would report this in case anyone else runs across this problem. If there is any more information needed or you think that is helpful please let me now.
Have you had success with this receiver when sending music from a phone or other OS (mac/windows)? If so, it would be useful to test it with pulseaudio or pipewire to see if they have more success than BlueALSA.
I reported that it worked perfectly with other devices in the initial bug report. It works perfectly with ios, android 12/13, gnome Bluetooth setting on PC, and mate (blueman) on PC. On the PC with blueman that worked with the receiver I compiled bluealsa with debugging turned on and had the same result as the pi2. Blueman worked with sound setup for SBC or AAC. Did a quick search - found how to turn on debugging information for blueman and attached is the blueman and bluetooth debug log. Also repeated the bluealsa logs. Had the same results as on the pi2 - could not play any sound thru the bluealsa device to the Onkyo receiver. System was arch linux setup with pipewire. Pipewire was NOT running while running bluealsa (killed the x-server and used the console).
blueman_bluetooth.log
blueman.log
bluealsa_bluetooth.log
bluealsa_service.log
bluealsa_speaker-test.log
Files uploaded blueman.log -- blueman-applet --loglevel debug blueman_bluetooth.log -- bluetoothd -d (while blueman debug was running) speaker-test worked fine with blueman running.
bluealsa_speaker-test.log - bluetoothctl, bluealsa-aplay -L, and speaker-test
speaker-test locked hard only could stop with pkill -KILL speaker-test
bluealsa_service.log - bluealsa running in debug mode -
/usr/bin/bluealsa -S -p a2dp-source -p a2dp-sink
bluealsa_bluetooth.log - bluetoothd -d while running bluealsa.
It works perfectly with ios, android 12/13, gnome Bluetooth setting on PC, and mate (blueman) on PC
blueman is just a graphical bluetootctl, but the underlying Bluetooth audio application might be either PulseAudio or PipeWire. I don't know how to debug them (in order to get meaningful information about differences between them and BlueALSA), but you might try to dump BlueZ communication. Please attach logs collected with such command (from the setup which works with Onkyo):
sudo dbus-monitor --system "sender=org.bluez" "destination=org.bluez"
Also, you might do the same thing on system with BlueALSA (it will be easier to search for potential differences). If potential issues with A2DP setup will be rulled out, then we will have to look into some differences with RTP audio packets.
I think I can explain the application lockups.
When Bluez unexpectedly changes the transport state to "idle", the BlueALSA daemon releases the Bluetooth socket and stops the encoder I/O thread, but it does not release the client socket and FIFO.
So the plugin I/O thread continues to write samples to the FIFO until the FIFO becomes full, at which point the I/O thread becomes blocked. Meanwhile, the application calls snd_pcm_drain(), which waits for the I/O thread to empty the buffer - but that never happens because the I/O thread is blocked. So the application is now blocked in the call to snd_pcm_drain().
What happens now depends on the application. In the case of speaker-test a SIGINT from pressing Ctrl-C is caught, and the handler sets a flag which terminates the main loop on its next iteration. But the mainloop is blocked, so never gets as far as checking the termination flag.
@arkq Perhaps the poll() within bluealsa_drain() needs to include a timeout so that the plugin has an opportunity to abort the drain if requested by the application (eg if an application thread or signal handler calls snd_pcm_abort() during the call to snd_pcm_drain()). I'm not sure what condition to test for here yet, I need to do some more reading.
[EDIT]
~~It is also possible for the plugin call to bluealsa_dbus_pcm_ctrl_send_drain() to block forever if the server encoder IO thread is not running, because the server dbus client thread waits for the IO thread to signal a condition variable.~~
oops, that's not true - the "PCM drain" log message is skipped, but the client reply is still sent. So the only block forever condition I can find is the poll() call within the plugin bluealsa_drain()
If I'm right about the cause of the application lockups, then the following simple patch should fix it for speaker-test, aplay etc that use snd_pcm_abort() in their signal handlers. Other applications may not be so lucky ...
diff --git a/src/asound/bluealsa-pcm.c b/src/asound/bluealsa-pcm.c
index 5556cb3..7a51b9d 100644
--- a/src/asound/bluealsa-pcm.c
+++ b/src/asound/bluealsa-pcm.c
@@ -691,7 +691,11 @@ static int bluealsa_drain(snd_pcm_ioplug_t *io) {
struct pollfd pfd = { pcm->event_fd, POLLIN, 0 };
while (bluealsa_pointer(io) >= 0 && io->state == SND_PCM_STATE_DRAINING) {
if (poll(&pfd, 1, -1) == -1) {
- if (errno == EINTR)
+ /* It is not well documented by ALSA, but if the application
+ * has requested that the PCM should be aborted by a signal
+ * then the ioplug nonblock flag is set to the special value 2.
+ */
+ if (errno == EINTR && io->nonblock != 2)
continue;
break;
}
Of course this does nothing to address the main issue here, which is the failed A2DP transport with the Onkyo receiver.
Interesting. I will give this a try in 2-3 days and get back with you the results. Have to deal with life now.
Thanks for looking into this problem.
@arkq - Will also give that a try in 2-3 days. Thanks for the information!
No improvement with patch. Same behavior. Here are the logs added aplay and bluez logs. Had to kill aplay and speaker-test and no sound. Thanks again for looking into this matter.
aplay.log speaker-test.log bluez-dbus-monitor.log bluetooth.service.log bluealsa.service.log
@borine borine mentioned this issue Sep 25, 2023 Improve PCM plugin drain #667
Should I try this patch? If I try this patch should I remove the other patch?
Thanks.
Had to kill aplay and speaker-test and no sound.
The "no sound" problem is most likely somewhere in the BlueALSA server, so my patch was not expected to fix that. The patch is supposed to enable you to kill aplay/speaker-test using ctrl-C instead of needing kill -KILL. It applies to the plugin shared library, so it is necessary to make install so that the patched shared library is placed into the correct directory for aplay or speaker-test to find it. Perhaps I should have placed an extra debug message in there so that we could see if the revised signal handling code is being called when ctrl-C is used. I will try to set up some different tests here to look at it again in case I have made a mistake in the code.
Improve PCM plugin drain #667 Should I try this patch? If I try this patch should I remove the other patch?
Sure, you can try it if you wish, it would be good to have feedback from a real test case. You would need to remove the other patch first, and make sure that the new plugin shared library is installed. Again, that PR does not attempt to fix the "no sound" problem. The idea is that the client application can not be stuck in a drain, so that after a certain amount of time the drain will stop and the application will "wake up" without needing to be killed. For speaker-test that may be a couple of seconds, because it uses a very large period size, but for aplay it should be less than half a second. The PR also includes the attempted ctrl-C fix from the first patch, so it should be easy to interrupt speaker-test instead of just waiting for it to finish.
I'm not very experienced at reading the Bluez logs, so that will need to wait until @arkq has time to go through them.
bluez-dbus-monitor.log
@spamtree, it seems that you've recorded D-Bus communication when using BlueALSA. Can you please record the same thing in a setup where audio works, e.g. on gnome?
Okay I applied the patches from the Improve PCM plugin drain 667 and ran the tests again.
The most interesting development is that sound played for about 5 seconds and stopped. Also ctrl-c worked perfectly.
Attached are the logs - if the filename starts with bluealsa the files are the bluealsa logs and filename starts with gnome the files are the gnome logs. Sound worked perfectly with gnome. Thanks for looking into the problem.
gnome-bluez.log gnome-bluetooth.service.log
bluealsa.service.log bluealsa-speaker-test.log bluealsa-bluetooth.service.log bluealsa-bluez-dbus-monitor.log
@spamtree I will have to review all the dump files you've provided (thanks for that). I've looked at the D-Bus monitor logs, and there is one difference. Can you please try to run bluealsa system service with --a2dp-force-audio-cd option enabled? This will force 44100 Hz sampling rate. Also, check with and without --codec=-aac.
Absolutely will do. May take a while for some reason cannot connect Onkyo receiver anymore. Will have to sort that out.
Here are the logs with --a2dp-force-audio-cd. No sound with speaker-test. Had to hit ctrl-c three times to stop speaker-test. Had to reboot to restart bluetooth.service.
bluealsa-bluetooth.service.log bluealsa.service.log speaker-test.log bluealsa-bluez.log
Below are the log files with the --codec=-aac and --a2dp-force-audio-cd options. Unable to connect to onkyo receiver. Bluetoothctl was disconnecting.
bluetoothctl-no-acc.log btmon-no-acc.log bluealsa-bluez-no-acc.log bluealsa-bluetooth.service.no-aac.log bluealsa.service.no-acc.log
I have noted that when bluealsa does connect to the onkyo it always connects with AAC codec and in gnome I must select the SBC codec to enable sound. Removing the AAC codec from bluealsa causes a disconnection with the onkyo receiver. Actually if I select AAC codec in gnome the sound stops and the connection is broken to the onkyo. I have to clear the bluetooth pairing in onkyo receiver and repair again in order to connect the bluetooth after it crashes with AAC codec. Looks like to me the real problem is the onkyo receiver bluetooth is buggy. That is my opinion.
bluealsa-aplay -L
bluealsa:DEV=00:09:B0:1C:CD:D4,PROFILE=a2dp,SRV=org.bluealsa
Onkyo TX-NR676 EE6F60, trusted audio-card, playback
A2DP (AAC): S16_LE 2 channels 44100 Hz
If something is wrong with AAC then you can switch to SBC with CODEC option for PCM device. See bluealsa-plugins manual for reference. Start bluealsa service with AAC enabled.
Thanks for the suggestion. Got it working see bluealsa-aplay -L
Did not work but it did connect. bluealsa locked completely and had to kill -KILL. Same results.
# bluealsa-aplay -L
bluealsa:DEV=00:09:B0:1C:CD:D4,PROFILE=a2dp,SRV=org.bluealsa
Onkyo TX-NR676 EE6F60, trusted audio-card, playback
A2DP (SBC): S16_LE 2 channels 44100 Hz
speaker-test -D bluealsa -f 44100 -c 2
speaker-test 1.2.10
Playback device is bluealsa
Stream parameters are 48000Hz, S16_LE, 2 channels
Using 16 octaves of pink noise
[2347] D: bluealsa-pcm.c:1423: Getting BlueALSA PCM: PLAYBACK 00:00:00:00:00:00 a2dp
[2347] D: bluealsa-pcm.c:1176: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Setting constraints
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 960 to 570653
Period size range from 480 to 285327
Using max buffer size 570652
Periods = 4
[2347] D: bluealsa-pcm.c:546: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing HW
[2347] D: bluealsa-pcm.c:495: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Attempting to fix hw params buffer size
[2347] D: bluealsa-pcm.c:584: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: FIFO buffer size: 1024 frames
[2347] D: bluealsa-pcm.c:589: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Selected HW buffer: 4 periods x 524284 bytes == 2097136 bytes
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:661: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Prepared
was set period_size = 142663
was set buffer_size = 570652
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
0 - Front Left
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 131071 -> 1
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 1 -> 131071
[2347] D: bluealsa-pcm.c:667: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Draining
[2347] D: bluealsa-pcm.c:374: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting
[2350] D: bluealsa-pcm.c:229: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting IO loop: 7
ALSA lib bluealsa-pcm.c:730:(bluealsa_drain) Drain timed out - possible Bluetooth transport failure
^C[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
[2350] D: bluealsa-pcm.c:165: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: IO thread cleanup
^C[2347] D: bluealsa-pcm.c:661: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Prepared
1 - Front Right
Time per period = 118.025413
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 131071 -> 1
[2347] D: bluealsa-pcm.c:620: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Initializing SW
[2347] D: bluealsa-pcm.c:629: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Changing SW avail min: 1 -> 131071
[2347] D: bluealsa-pcm.c:667: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Draining
[2347] D: bluealsa-pcm.c:374: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Starting
^C[2347] D: bluealsa-pcm.c:385: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Couldn't start PCM: Resource temporarily unavailable
[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
^C[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
^C[2347] D: bluealsa-pcm.c:599: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Freeing HW
[2347] D: bluealsa-pcm.c:457: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Closing
bluealsa locked completely and had to kill -KILL.
By bluealsa you mean the system service (bluealsa application)? If yes, if such lockup happens, can you please try to get backtrace of all threads in that process? Simply try to connects to it with gdb -p <PID-of-the-process> and type thread apply all bt.
Also, I would suggest to keep the --a2dp-force-audio-cd option all the time. In you first comment you've posted Onkyo receiver spec which says "20 Hz - 20 kHz (Sampling frequency 44.1 kHz)". Why would they mention sampling frequency here? I guess it might be better to stick with 44.1 kHz.
Thanks will do. Have to get some work done but will get back to you. Yes the bluealsa.service and can't restart with systemctl restart bluealsa.service. Will get a backtrace. Thank you very much.
Just quickly scanning through https://repairalmostanything.com/thread/767/never-wanted-onkyo-firmware I see that Onkyo receivers use Linux on the chip that performs audio decoding, networking and USB. So it is possible that Bluetooth functionality is provided by Bluez (although other Linux Bluetooth solutions exist). Now Bluez historically has a number of issues related to cacheing of codec infromation. AFAIK they are fixed in Bluez release 5.65, but if your Onkyo is using Bluez then it is very likely to be an older version than that.
The Onyo documentation should mention what open-source software it is using (if any) to comply with the licensing requirements. If it does use Bluez then I think some of the behaviour you see may be because the Onkyo has cached codec info from the first time your computer was paired with it (using Gnome or Blueman), so when you later change the audio agent on your computer you get different available codecs and different codec configurations, but the broken Blluez cache does not pick up on those changes so the transport fails. There may be a workaround, but it would require cllearing the Bluez cache. Unpairing and/or re-pairing a device does not clear the cache on broken releases of Bluez.
BTW
speaker-test -D bluealsa -f 44100 -c 2
You need to use
speaker-test -D bluealsa -r 44100 -c 2
to force the output sample rate to 44100
Here's my interpretation of what is happening in the last speaker-test log above.
Stream parameters are 48000Hz, S16_LE, 2 channels
Using 16 octaves of pink noise
speaker-test is generating pink noise sampled at 48000Hz
Using max buffer size 570652
Periods = 4
speaker-test has set a period size of 570652 / 4 = 142663 frames. This translates to 2972 milliseconds at 48000Hz, so bluealsa will use a drain timeout of just over 3 seconds.
ALSA lib bluealsa-pcm.c:730:(bluealsa_drain) Drain timed out - possible Bluetooth transport failure
The bluealsa plugin is unable to drain the buffer because the bluealsa server is not responding. It blocks for the timeout period (just over 3 seconds in this case) then reports that error.
^C
I think if you wait 3 seconds here then the ^C is not necessary; but as a result of this speaker-test sets a flag so that its mainloop is stopped on the next iteration, and future ALSA blocking calls (write, drain) to this PCM return immediately with the error EINTR.
[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
As a result of the drain timeout, the bluealsa plugin now stops the PCM
^C
not necessary - the first ctrl-c told speaker-test to set its stop flag, this one and subsequent presses of ctrl-c have no effect.
1 - Front Right
speaker-test ignores the error code returned by the drain function and proceeds to send noise to the second channel. This time it does not call drain() because its stopping flag is set. Had you not pressed ctrl-c earlier, then it is possible speaker-test may become blocked at this point because the attempt to write will block if the buffer is full. If so ctrl-c here will unblock it (but I don't think the buffer would have filled yet).
Time per period = 118.025413
The speaker-test prints timing statistics before leaving its mainloop.
^C
same as above
[2347] D: bluealsa-pcm.c:385: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Couldn't start PCM: Resource temporarily unavailable
speaker-test tries to drain the PCM one last time before exiting. The bluealsa plugin tries to send a control message to the server to resume the PCM; but the server is no longer reading control messages, and that error results.
[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
So now the plugin makes sure that the PCM is stopped, which is a no-op because it is not currently running
^C
same as above
[2347] D: bluealsa-pcm.c:410: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Stopping
Finally speaker-test closes the PCM. So again the plugin makes sure the PCM is stopped (still a no-op)
^C
Same as above
[2347] D: bluealsa-pcm.c:599: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Freeing HW
[2347] D: bluealsa-pcm.c:457: /org/bluealsa/hci0/dev_00_09_B0_1C_CD_D4/a2dpsrc/sink: Closing
the bluealsa plugin cleans up its resources and then speaker-test exits with exit code 0
I will try to address the questions and I followed the recommendations. Changed settings on speaker-test and bluealsa as recommended. No information in the onkyo manual about open source for bluetooth.
speaker-test has stopped for 30 minutes with the last message being ->
ALSA lib bluealsa-pcm.c:730:(bluealsa_drain) Drain timed out - possible Bluetooth transport failure
Had to hit Ctrl-C four times to stop speaker test and was able to restart bluealsa.service after killing the bluealsa process (kill -KILL bluealsa_process).
dmesg log showed that bluetooth killed the connection to the onkyo.
Bluetooth: hci0: killing stalled connection 00:09:b0:1c:cd:d4
I have to clear the bluetooth pairing on the onkyo and the laptop in order to connect again to the onkyo.
attached are logs.
dmesg_hci0.log bluez.log bluetooth.service.log bluealsa.log speaker-test.log gdb.log
Thanks for the gdb.log. Unfortunately, there are no debug symbols there.... Please check if binary was built with debug symbols (with debug_info, not stripped), e.g.:
$ file build/src/bluealsa
build/src/bluealsa: ELF 64-bit [...] for GNU/Linux 3.2.0, with debug_info, not stripped
If it's not, please try to add -g to CFLAGS before compiling. If executable has got symbols, please go to the directory from which you've run make and from this directory run gdb -p ..... This should allow gdb to load symbols and source files to generate verbose backtrace.
Had to hit Ctrl-C four times to stop speaker test
@arkq - it looks like the server glib client event loop may be locked up, the speaker-test log above appears to indicate that the plugin is stuck waiting for a reply from the server for the Drop command, then again for the Resume command,etc. Do you think there should be a timeout in the client code when waiting for a command reply? If so I could push another commit to PR #669
Do you think there should be a timeout in the client code when waiting for a command reply?
To be honest I'm not sure. I don't know how long we should wait, 1 second or maybe less? I'd like to try to fix the server first, so such lockup will not happen. But anyway, maybe timeout on the client side is a good idea as well... dunno :D