PC streams music over low-quality HFP/SCO connection, instead of A2DP/AVDTP

[brianrho]

This is a "mirror" of a Bluez issue already raised here -- someone suggested I raise it here to run it by the maintainers.

The Problem

Basically, in every new remotely-initiated connection, Bluez competes with the remote device to connect A2DP first. Conventionally, one should instead allow the ACL-initiating device to also connect the profiles, or at least give it enough time to do so -- at least 2s according to the timeout in policy.c:

bluez/plugins/policy.c

Lines 37 to 38 in cec1ef6

	#define SOURCE_RETRY_TIMEOUT 2
	#define SINK_RETRY_TIMEOUT SOURCE_RETRY_TIMEOUT

Some headsets do not handle Bluez's contention well, and for my headset at least, this manifests as it taking several seconds to respond to AVDTP commands. Because of these delays, A2DP media takes a long time to get setup. During that interim, PulseAudio either uses HFP/SCO for routing the PC audio or (on Impish Indri) the delays are actually long enough to trigger A2DP watchdog timeouts and all the profiles get dropped.

Even in the best case, when A2DP media gets finally connected, the PC audio still doesn't switch to this new transport automatically -- it keeps on using SCO until I manually select A2DP in Blueman.

Proposed solution

Upon a successful ACL connection, there are 2 state transitions in ext_connect() -- the first IF block sends the (usually-HFP) service into CONNECTING and very shortly after, the last IF block sends the service into CONNECTED. That first transition looks to be at fault here:

bluez/src/profile.c

Lines 1125 to 1134 in cec1ef6

	if (conn->service && service_set_connecting(conn->service) < 0)
	goto drop;
	if (send_new_connection(ext, conn))
	return;
	drop:
	if (conn->service)
	btd_service_connecting_complete(conn->service,
	err ? -err->code : -EIO);

It forces every successful connection to appear like it was locally-initiated, and state-change-listeners like policy.c hs_cb() innocently take its word and kick off A2DP connection immediately because they (correctly) assume that CONNECTING == locally-initiated == they have right-of-way and can do as they like. When they would otherwise have waited for >=2s before starting their attempt.

bluez/plugins/policy.c

Lines 314 to 323 in cec1ef6

	case BTD_SERVICE_STATE_CONNECTED:
	/* Check if service initiate the connection then proceed
	* immediately otherwise set timer
	*/
	if (old_state == BTD_SERVICE_STATE_CONNECTING)
	policy_connect(data, sink);
	else if (btd_service_get_state(sink) !=
	BTD_SERVICE_STATE_CONNECTED)
	policy_set_sink_timer(data);
	break;

To solve this, that CONNECTING transition (or the entire IF block) should be removed from ext_connect() so that incoming connections simply move from DISCONNECTED to CONNECTED:

• Clearly distinguishing them from outgoing/locally-initiated connections for the sake of listeners
• ext_connect() is too late in the chain to be the one to declare if a connection was locally-initiated or not -- others before it like btd_service_connect() should've done that CONNECTING transition already, way earlier
• It also feels like a more-natural transition considering the "sudden" nature of incoming connections

I've just tried to summarize here -- logs, traces and more detailed analysis can be found at the other ticket, if needed and all this makes sense.

[brianrho]

On a related note, a similar fix may be needed in service_accept() which seems to handle incoming LE GATT connections (?), but I'm not sure since I haven't studied it in any depth and this one doesn't seem as important as the BR/EDR issue anyways:

bluez/src/service.c

Lines 206 to 209 in cec1ef6

	done:
	if (service->state == BTD_SERVICE_STATE_DISCONNECTED)
	change_state(service, BTD_SERVICE_STATE_CONNECTING, 0);
	return 0;

[Vudentz]

On a related note, a similar fix may be needed in service_accept() which seems to handle incoming LE GATT connections (?), but I'm not sure since I haven't studied it in any depth and this one doesn't seem as important as the BR/EDR issue anyways:

bluez/src/service.c

Lines 206 to 209 in cec1ef6

	done:
	if (service->state == BTD_SERVICE_STATE_DISCONNECTED)
	change_state(service, BTD_SERVICE_STATE_CONNECTING, 0);
	return 0;

Yes, service_accept is for GATT only.

Btw, Ive sent a set introducing btd_service_is_initiator, but it still don't switch to A2DP:

Sep 16 11:44:53 bluetoothd[84425]: plugins/policy.c:policy_connect() /org/bluez/hci0/dev_XX_XX_XX_XX_XX_XX profile a2dp-sink
Sep 16 11:44:51 bluetoothd[84425]: plugins/policy.c:service_cb() Added Headset Voice gateway reconnect 0

Well that with PulseAudio so perhaps it is worth checking with Pipewire if it does switch to A2DP if it connects later, anyway it happens on outgoing connections as well so I suspect there is something preferring HFP over A2DP for some reason.

[i-garrison]

Original report on launchpad https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1941977 is missing pulseaudio log, but I would suspect it just timed out waiting for A2DP profile after it received NewConnection callback. The timeout is 3 seconds.

Quoting from launchpad comment https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1941977/comments/5

• From the Headset-Initiated snoop, we can see where the headset connected the ACL (23:54:47 UTC), followed shortly by connecting HFP (successfully).
• Very soon after the headset connected HFP, the PC/bluez initiated an AVDTP connection, a bid to connect A2DP -- this is unfriendly behaviour, since the general convention is: whomever created the ACL gets to create the profiles. Or at least is given enough time to connect them, before the other end starts its own attempt.

@Vudentz could you please comment on the statement about convention regarding which side creates the profiles? If that convention holds, bluez should probably take care of giving the connection initiator side more time to complete it's connections. As far as I can see pulseaudio has no means to affect the described behavior, because none of it's dbus callbacks is called for this device yet.

[brianrho]

Btw, Ive sent a set introducing btd_service_is_initiator, but it still don't switch to A2DP:

Ah, you mean you can reproduce the issue on your end as well, with the headset streaming music over SCO? Or that the issue is now fixed? Can you provide snoop or syslogs maybe?

[Vudentz]

I end up merging the btd_service_is_initiator changes but the original problem seems to still persist, at least with the headsets I have it doesn't switch to A2DP:

Even in the best case, when A2DP media gets finally connected, the PC audio still doesn't switch to this new transport automatically -- it keeps on using SCO until I manually select A2DP in Blueman.

[brianrho]

Okay, how about providing some logs/traces so we can confirm A2DP now connects without delays and also observe the overall issue? Perhaps including PulseAudio logs this time.

[Vudentz]

Okay, how about providing some logs/traces so we can confirm A2DP now connects without delays and also observe the overall issue? Perhaps including PulseAudio logs this time.

Read the problem again, the reason some headsets don't connect properly was because we initiate A2DP connection immediately instead of waiting the device to connect if had initiated the ACL. The fact that PA doesn't seems to coping with A2DP connecting later seems to be some regression on its end.

[i-garrison]

Hi Brian, do you have an option to run bluez with this change? If you can confirm that timeout issue is fixed for your headset I would expect pulseaudio to connect A2DP first, since A2DP has higher internal priority in pulseaudio.