bluez-alsa: E: Invalid BT socket & W: Couldn't register oFono

  • Are these warning relevant?
  • Why are they always arising?

I have still very long delay for sent out audio on Raspberry zero W (buster) and Raspberry zero 2 (bullseye) with ofono see also #385 Could this be the reason?

raspberry zero 2 W:

root@rpi:/home/pi# bluealsa -p hfp-ofono
bluealsa: I: main.c:479: Disabling native HFP support due to enabled oFono profile
bluealsa: D: main.c:534: Starting main dispatching loop
bluealsa: D: main.c:111: Acquired D-Bus service name: org.bluealsa
bluealsa: D: bluealsa-dbus.c:426: Registering D-Bus manager: /org/bluealsa
bluealsa: D: bluez.c:669: Registering battery provider: /org/bluez/hci0/battery
bluealsa: D: bluez.c:689: BlueZ battery provider support not available
bluealsa: D: bluez.c:483: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: D: bluez.c:392: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: D: bluez.c:483: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: D: bluez.c:392: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: D: bluez.c:918: Creating hands-free profile object: /org/bluez/HSP/AudioGateway
bluealsa: D: bluez.c:842: Registering hands-free profile: /org/bluez/HSP/AudioGateway
bluealsa: D: ofono.c:466: Registering oFono audio agent: /org/bluez/HFP/oFono
bluealsa: D: ofono.c:247: Adding new oFono card: /card_1
bluealsa: D: ba-transport.c:1151: Starting transport: HFP Hands-Free (CVSD)
bluealsa: E: ba-transport.c:278: Invalid BT socket: -1
bluealsa: E: ba-transport.c:278: Invalid BT socket: -1
bluealsa: D: ofono.c:466: Registering oFono audio agent: /org/bluez/HFP/oFono
bluealsa: W: ofono.c:521: Couldn't register oFono: GDBus.Error:org.ofono.Error.InUse: The resource is currently in use

raspberry zero w:

root@pilot1:/home/pilot/bluez-alsa# export LIBASOUND_THREAD_SAFE=0
root@pilot1:/home/pilot/bluez-alsa# bluealsa -p hfp-ofono
bluealsa: I: main.c:479: Disabling native HFP support due to enabled oFono profile
bluealsa: D: main.c:534: Starting main dispatching loop
bluealsa: D: main.c:111: Acquired D-Bus service name: org.bluealsa
bluealsa: D: bluealsa-dbus.c:426: Registering D-Bus manager: /org/bluealsa
bluealsa: D: bluez.c:669: Registering battery provider: /org/bluez/hci0/battery
bluealsa: D: bluez.c:689: BlueZ battery provider support not available
bluealsa: D: bluez.c:483: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: D: bluez.c:392: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/1
bluealsa: D: bluez.c:483: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: D: bluez.c:392: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/source/2
bluealsa: D: bluez.c:918: Creating hands-free profile object: /org/bluez/HSP/AudioGateway
bluealsa: D: bluez.c:842: Registering hands-free profile: /org/bluez/HSP/AudioGateway
bluealsa: D: ofono.c:466: Registering oFono audio agent: /org/bluez/HFP/oFono
bluealsa: D: ofono.c:466: Registering oFono audio agent: /org/bluez/HFP/oFono
bluealsa: W: ofono.c:521: Couldn't register oFono: GDBus.Error:org.ofono.Error.InUse: The resource is currently in use

raspberry zero 2 W:

root@rpi:/home/pi# hciconfig -a 
hci0:	Type: Primary  Bus: UART
	BD Address: xx:xx:xx:xx:xx:xx ACL MTU: 1021:7  SCO MTU: 64:1
	UP RUNNING 
	RX bytes:4890 acl:56 sco:0 events:160 errors:0
	TX bytes:5069 acl:48 sco:0 commands:124 errors:0
	Features: 0xbf 0xfe 0xcf 0xfe 0xdb 0xff 0x7b 0x87
	Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 
	Link policy: RSWITCH SNIFF 
	Link mode: SLAVE ACCEPT 
	Name: 'rpi'
	Class: 0x200000
	Service Classes: Audio
	Device Class: Miscellaneous, 
	HCI Version: 4.2 (0x8)  Revision: 0x5c
	LMP Version: 4.2 (0x8)  Subversion: 0x410c
	Manufacturer: Broadcom Corporation (15)

raspberry zero W:

root@rpil:/home/pilot/bluez-alsa# hciconfig -a
hci0:	Type: Primary  Bus: UART
	BD Address: xx:xx:xx:xx:xx:xx  ACL MTU: 1021:8  SCO MTU: 64:1
	UP RUNNING PSCAN 
	RX bytes:28102 acl:603 sco:0 events:869 errors:0
	TX bytes:11546 acl:249 sco:0 commands:363 errors:0
	Features: 0xbf 0xfe 0xcf 0xfe 0xdb 0xff 0x7b 0x87
	Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 
	Link policy: RSWITCH SNIFF 
	Link mode: SLAVE ACCEPT 
	Name: 'rpi'
	Class: 0x200000
	Service Classes: Audio
	Device Class: Miscellaneous, 
	HCI Version: 4.1 (0x7)  Revision: 0x1fc
	LMP Version: 4.1 (0x7)  Subversion: 0x2209
	Manufacturer: Broadcom Corporation (15)
bluealsa-aplay -l 
**** List of PLAYBACK Bluetooth Devices ****
hci0: xx:xx:xx:xx:xx:xx [Galaxy Tab S2], trusted phone
  SCO (CVSD): S16_LE 1 channel 8000 Hz
**** List of CAPTURE Bluetooth Devices ****
hci0: xx:xx:xx:xx:xx:xx [Galaxy Tab S2], trusted phone
  SCO (CVSD): S16_LE 1 channel 8000 Hz

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 39 (5 by maintainers)

Most upvoted comments

Do you know how to integrate … using plain python?

I’m not a python programmer, so can’t give specific advice. I believe the way to do it is to use the subprocess object, and its Popen method to connect each command of the pipeline together. Hopefully googling those terms will find some useful examples.

BTW, I’ve taken a different approach. I run a service that runs continuously (from boot) and waits for PCMs to enter the running state. Mine is actually a shell script that uses aplay, arecord and bluealsa-cli, but I’m sure something similar could be done in Python. When the PCMs leave the running state the script kills the audio pipelines. That way I can have incoming calls working as well as dialling outgoing calls.

I’m working on a re-write of the wiki page, which will include a cut-down version of my script as an example. When its ready, I would really appreciate any feedback if you are able to test and compare with your solution. Might be another week or so before I get the page finshed and uploaded though.

I don’t have echo cancellation yet, but will investigate using your solution when I get that far.

Also, what might be of interest is that I have a bluetooth agent that permits only one audio device to connect at a time, which I think is important for a hands-free device. That too is a shell script, this time using Bluez “simple-agent” test program to implement the d-bus bluez agent API. That one I will share as a separate project eventually.

@dr-ni This issue has been idle for a long time, so if is no longer of interest please let us know and then it will be closed.

In the meantime I’ve been experimenting with HSP-HS and HFP-HF profiles (I don’t use ofono though) and at last I can understand how such a long delay can be created.

When the AG device “connects” to the HF/HS, a the profile configuration is negotiated and BlueALSA creates the PCM objects on the HF/HS. However at this stage no audio connection exists and any ALSA application that opens one of these PCMS will be blocked. After some indeterminate time the AG will open the audio connection at which point the application is unblocked and audio flows in and out of the bluetooth adapter.

Now when the client is a pipeline such as record -f s16_le -c 1 -r 8000 -D mic | aplay -D bluealsa the aplay process is blocked once it has filled the BlueALSA pipe to the daemon, while the arecord process starts capture immediately and runs until all buffers in the total pipeline are filled, at which point it too becomes blocked. So using CVSD with default buffer definitions we can have up to 500ms buffered in arecord, 4096ms buffered in the first pipe, 500ms in aplay and 256ms in the second pipe; giving a total of 5352ms buffered, which translates into a delay of that amount once the audio connection is opened. I see exactly this is my experiments. If arecord is run in its default config it captures in format U8, not S16_LE, and that doubles the number of samples that can be stored in the first pipe giving a total delay of 9448ms. I suspect that is what you are seeing.

The only workaround is to avoid starting the ALSA client before the audio connection has been opened by the AG (i.e. when the SCO transport is “acquired”). Unfortunately so far I have not been able to identify any system events that an application can listen for to know when acquisition has occcured, so I have no idea how to start arecord/aplay at the right time. Perhaps ofono emits some D-Bus event? I don’t know.

I’ve made a small test with oFono and it seems that there is one unnecessary line in the code 😄 Please, remove that and see whether it will help:

https://github.com/Arkq/bluez-alsa/blob/master/src/ofono.c#L277

Are these warning relevant? Why are they always arising?

It was a bug in the master which was introduced some time ago. I’ve just pushed a fix for that, so you should not see this error message any more. However, I’m not sure (honestly I doubt) that it was a cause of a delay you are seeing…