PCM client delay reporting for A2DP sink profile

This feature will not work unless there will be a proper delay reporting
implementation in BlueZ (for A2DP sink profile).

src/ba-transport-pcm.c

@@ -24,6 +24,7 @@
 #include <string.h>
 #include <unistd.h>
 
+#include <gio/gio.h>
 #include <glib.h>
 
 #include "audio.h"
@@ -631,7 +632,9 @@ void ba_transport_pcm_volume_set(
 
 }
 
-int ba_transport_pcm_volume_update(struct ba_transport_pcm *pcm) {
+/**
+ * Synchronize PCM volume level with remote Bluetooth device. */
+int ba_transport_pcm_volume_sync(struct ba_transport_pcm *pcm) {
 
 	struct ba_transport *t = pcm->t;
 
@@ -684,8 +687,6 @@ int ba_transport_pcm_volume_update(struct ba_transport_pcm *pcm) {
 	}
 
 final:
-	/* notify connected clients (including requester) */
-	bluealsa_dbus_pcm_update(pcm, BA_DBUS_PCM_UPDATE_VOLUME);
 	return 0;
 }
 
@@ -716,20 +717,73 @@ int ba_transport_pcm_get_hardware_volume(
 	return 0;
 }
 
-int ba_transport_pcm_get_delay(const struct ba_transport_pcm *pcm) {
+/**
+ * Get PCM playback/capture cumulative delay. */
+int ba_transport_pcm_delay_get(const struct ba_transport_pcm *pcm) {
 
 	const struct ba_transport *t = pcm->t;
+	int delay = 0;
 
-	int delay = pcm->codec_delay_dms + pcm->processing_delay_dms;
+	delay += pcm->codec_delay_dms;
+	delay += pcm->processing_delay_dms;
 
-	if (t->profile & BA_TRANSPORT_PROFILE_MASK_A2DP)
+	/* Add delay reported by BlueZ but only for A2DP Source profile. In case
+	 * of A2DP Sink, the BlueZ delay value is in fact our client delay. */
+	if (t->profile & BA_TRANSPORT_PROFILE_A2DP_SOURCE)
 		delay += t->a2dp.delay;
-	if (t->profile & BA_TRANSPORT_PROFILE_MASK_SCO)
+	/* HFP/HSP profiles do not provide any delay information. However, we can
+	 * assume some arbitrary value here - for now it will be 10 ms. */
+	else if (t->profile & BA_TRANSPORT_PROFILE_MASK_AG)
 		delay += 10;
 
 	return delay;
 }
 
+/**
+ * Synchronize PCM playback delay with remote Bluetooth device. */
+int ba_transport_pcm_delay_sync(struct ba_transport_pcm *pcm) {
+
+	struct ba_transport *t = pcm->t;
+	int delay = 0;
+
+	delay += pcm->codec_delay_dms;
+	delay += pcm->processing_delay_dms;
+	delay += pcm->client_delay_dms;
+
+	/* In case of A2DP Sink, update the delay property of the BlueZ media
+	 * transport interface. BlueZ should forward this value to the remote
+	 * device, so it can adjust audio/video synchronization. */
+	if (t->profile == BA_TRANSPORT_PROFILE_A2DP_SINK &&
+			t->a2dp.delay_reporting &&
+			abs(delay - t->a2dp.delay) >= 100 /* 10ms */) {
+
+		GError *err = NULL;
+		t->a2dp.delay = delay;
+		g_dbus_set_property(config.dbus, t->bluez_dbus_owner, t->bluez_dbus_path,
+				BLUEZ_IFACE_MEDIA_TRANSPORT, "Delay", g_variant_new_uint16(delay), &err);
+
+		if (err != NULL) {
+			if (err->code == G_DBUS_ERROR_UNKNOWN_PROPERTY)
+				/* Theoretically, we could check for the delay reporting support
+				 * just after accepting transport. However, it's not that simple,
+				 * because not every version of BlueZ expose it in an obvious way.
+				 * So, instead of that we will use try/catch approach here. */
+				t->a2dp.delay_reporting = false;
+			else if (err->code == G_DBUS_ERROR_PROPERTY_READ_ONLY)
+				/* Even though BlueZ documentation says that the Delay property is
+				 * read-write, it might not be true. In case when the delay write
+				 * operation fails with "not writable" error, we should not try to
+				 * update the delay report value any more. */
+				t->a2dp.delay_reporting = false;
+			warn("Couldn't set A2DP transport delay: %s", err->message);
+			g_error_free(err);
+		}
+
+	}
+
+	return 0;
+}
+
 const char *ba_transport_pcm_channel_to_string(
 		enum ba_transport_pcm_channel channel) {
 	switch (channel) {

src/ba-transport-pcm.h

@@ -247,15 +247,18 @@ void ba_transport_pcm_volume_set(
 		const bool *soft_mute,
 		const bool *hard_mute);
 
-int ba_transport_pcm_volume_update(
+int ba_transport_pcm_volume_sync(
 		struct ba_transport_pcm *pcm);
 
 int ba_transport_pcm_get_hardware_volume(
 		const struct ba_transport_pcm *pcm);
 
-int ba_transport_pcm_get_delay(
+int ba_transport_pcm_delay_get(
 		const struct ba_transport_pcm *pcm);
 
+int ba_transport_pcm_delay_sync(
+		struct ba_transport_pcm *pcm);
+
 const char *ba_transport_pcm_channel_to_string(
 		enum ba_transport_pcm_channel channel);
 

src/ba-transport.h

@@ -127,6 +127,8 @@ struct ba_transport {
 			/* selected audio codec configuration */
 			a2dp_t configuration;
 
+			/* delay reporting support */
+			bool delay_reporting;
 			/* delay reported by BlueZ */
 			uint16_t delay;
 			/* volume reported by BlueZ */

src/bluealsa-dbus.c

@@ -281,7 +281,7 @@ static GVariant *ba_variant_new_pcm_codec_config(const struct ba_transport_pcm *
 }
 
 static GVariant *ba_variant_new_pcm_delay(const struct ba_transport_pcm *pcm) {
-	return g_variant_new_uint16(ba_transport_pcm_get_delay(pcm));
+	return g_variant_new_uint16(ba_transport_pcm_delay_get(pcm));
 }
 
 static GVariant *ba_variant_new_pcm_client_delay(const struct ba_transport_pcm *pcm) {
@@ -962,6 +962,7 @@ static bool bluealsa_pcm_set_property(const char *property, GVariant *value,
 
 	if (strcmp(property, "ClientDelay") == 0) {
 		pcm->client_delay_dms = g_variant_get_int16(value);
+		ba_transport_pcm_delay_sync(pcm);
 		bluealsa_dbus_pcm_update(pcm, BA_DBUS_PCM_UPDATE_CLIENT_DELAY);
 		return TRUE;
 	}
@@ -1017,7 +1018,8 @@ static bool bluealsa_pcm_set_property(const char *property, GVariant *value,
 
 		pthread_mutex_unlock(&pcm->mutex);
 
-		ba_transport_pcm_volume_update(pcm);
+		ba_transport_pcm_volume_sync(pcm);
+		bluealsa_dbus_pcm_update(pcm, BA_DBUS_PCM_UPDATE_VOLUME);
 		return true;
 	}
 

src/bluez.c

@@ -455,6 +455,7 @@ static void bluez_endpoint_set_configuration(GDBusMethodInvocation *inv, void *u
 	enum bluez_a2dp_transport_state state = 0xFFFF;
 	char *device_path = NULL;
 	a2dp_t configuration = { 0 };
+	bool delay_reporting = true;
 	uint16_t volume = 127;
 	uint16_t delay = 150;
 
@@ -505,6 +506,10 @@ static void bluez_endpoint_set_configuration(GDBusMethodInvocation *inv, void *u
 				g_variant_validate_value(value, G_VARIANT_TYPE_STRING, property)) {
 			state = bluez_a2dp_transport_state_from_string(g_variant_get_string(value, NULL));
 		}
+		else if (strcmp(property, "DelayReporting") == 0 &&
+				g_variant_validate_value(value, G_VARIANT_TYPE_BOOLEAN, property)) {
+			delay_reporting = g_variant_get_boolean(value);
+		}
 		else if (strcmp(property, "Delay") == 0 &&
 				g_variant_validate_value(value, G_VARIANT_TYPE_UINT16, property)) {
 			delay = g_variant_get_uint16(value);
@@ -566,6 +571,7 @@ static void bluez_endpoint_set_configuration(GDBusMethodInvocation *inv, void *u
 	}
 
 	t->a2dp.bluez_dbus_sep_path = dbus_obj->path;
+	t->a2dp.delay_reporting = delay_reporting;
 	t->a2dp.delay = delay;
 	t->a2dp.volume = volume;
 
@@ -1331,8 +1337,8 @@ static void bluez_signal_interfaces_added(GDBusConnection *conn, const char *sen
 
 				}
 				g_variant_unref(value);
-
 			}
+
 		}
 		g_variant_iter_free(properties);
 	}

test/test-rfcomm.c

@@ -325,7 +325,7 @@ CK_START_TEST(test_rfcomm_hfp_ag) {
 	ba_transport_pcm_volume_set(&pcm->volume[0], &level, NULL, NULL);
 	pthread_mutex_unlock(&pcm->mutex);
 	/* use internal API to update volume */
-	ba_transport_pcm_volume_update(pcm);
+	ba_transport_pcm_volume_sync(pcm);
 	ck_assert_rfcomm_recv(fd, "\r\n+VGS:7\r\n");
 
 	ba_transport_destroy(sco);

test/test-utils-ctl.c

@@ -264,7 +264,7 @@ CK_START_TEST(test_client_delay) {
 
 	struct spawn_process sp_ba_mock;
 	ck_assert_int_ne(spawn_bluealsa_mock(&sp_ba_mock, NULL, true,
-				"--profile=a2dp-source",
+				"--profile=a2dp-sink",
 				NULL), -1);
 
 	char output[4096];
@@ -276,21 +276,21 @@ CK_START_TEST(test_client_delay) {
 
 	/* check default client delay */
 	ck_assert_int_eq(run_bluealsactl(output, sizeof(output),
-				"client-delay", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsrc/sink",
+				"client-delay", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsnk/source",
 				NULL), 0);
 	ck_assert_ptr_ne(strstr(output, "ClientDelay: 0.0 ms"), NULL);
 
 	/* check setting client delay */
 	ck_assert_int_eq(run_bluealsactl(output, sizeof(output),
-				"client-delay", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsrc/sink", "-7.5",
+				"client-delay", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsnk/source", "-7.5",
 				NULL), 0);
 
 	/* check that setting client delay does not affect delay */
 	ck_assert_int_eq(run_bluealsactl(output, sizeof(output),
-				"info", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsrc/sink",
+				"info", "/org/bluealsa/hci11/dev_12_34_56_78_9A_BC/a2dpsnk/source",
 				NULL), 0);
 	ck_assert_ptr_ne(strstr(output, "ClientDelay: -7.5 ms"), NULL);
-	ck_assert_ptr_ne(strstr(output, "Delay: 10.0 ms"), NULL);
+	ck_assert_ptr_ne(strstr(output, "Delay: 0.0 ms"), NULL);
 
 	spawn_terminate(&sp_ba_mock, 0);
 	spawn_close(&sp_ba_mock, NULL);

utils/aplay/Makefile.am

@@ -1,5 +1,5 @@
 # BlueALSA - Makefile.am
-# Copyright (c) 2016-2023 Arkadiusz Bokowy
+# Copyright (c) 2016-2024 Arkadiusz Bokowy
 
 if ENABLE_APLAY
 
@@ -12,6 +12,7 @@ bluealsa_aplay_SOURCES = \
 	../../src/shared/ffb.c \
 	../../src/shared/log.c \
 	../../src/shared/nv.c \
+	../../src/shared/rt.c \
 	alsa-mixer.c \
 	alsa-pcm.c \
 	dbus.c \

utils/aplay/aplay.c

@@ -40,6 +40,7 @@
 #include "shared/ffb.h"
 #include "shared/log.h"
 #include "shared/nv.h"
+#include "shared/rt.h"
 #include "alsa-mixer.h"
 #include "alsa-pcm.h"
 #include "dbus.h"
@@ -563,8 +564,7 @@ static void *io_worker_routine(struct io_worker *w) {
 				w->ba_pcm.pcm_path, softvol ? "software" : "pass-through");
 		if (softvol != w->ba_pcm.soft_volume) {
 			w->ba_pcm.soft_volume = softvol;
-			if (!ba_dbus_pcm_update(&dbus_ctx, &w->ba_pcm,
-						BLUEALSA_PCM_SOFT_VOLUME, &err)) {
+			if (!ba_dbus_pcm_update(&dbus_ctx, &w->ba_pcm, BLUEALSA_PCM_SOFT_VOLUME, &err)) {
 				error("Couldn't set BlueALSA source PCM volume mode: %s", err.message);
 				dbus_error_free(&err);
 				goto fail;
@@ -593,6 +593,12 @@ static void *io_worker_routine(struct io_worker *w) {
 	size_t pcm_open_retry_pcm_samples = 0;
 	size_t pcm_open_retries = 0;
 
+	/* The time-stamp for delay update rete limitting. */
+	struct timespec pcm_delay_update_ts = { 0 };
+	/* Window buffer for calculating delay moving average. */
+	snd_pcm_sframes_t pcm_delay_frames[16];
+	size_t pcm_delay_frames_i = 0;
+
 	size_t pause_retry_pcm_samples = pcm_1s_samples;
 	size_t pause_retries = 0;
 
@@ -745,10 +751,13 @@ static void *io_worker_routine(struct io_worker *w) {
 			io_worker_mixer_open(w, mixer_device, mixer_elem_name, mixer_elem_index);
 			io_worker_mixer_volume_sync_setup(w);
 
-			/* reset retry counters */
+			/* Reset retry counters. */
 			pcm_open_retry_pcm_samples = 0;
 			pcm_open_retries = 0;
 
+			/* Reset moving delay window buffer. */
+			memset(pcm_delay_frames, 0, sizeof(pcm_delay_frames));
+
 			if (verbose >= 2) {
 				info("Used configuration for %s:\n"
 						"  ALSA PCM buffer time: %u us (%zu bytes)\n"
@@ -803,9 +812,44 @@ static void *io_worker_routine(struct io_worker *w) {
 				goto close_alsa;
 			}
 
-		/* move leftovers to the beginning and reposition tail */
+		/* Move leftovers to the beginning and reposition tail. */
 		ffb_shift(&buffer, frames * w->ba_pcm.channels);
 
+		int ret;
+		if ((ret = snd_pcm_delay(w->snd_pcm,
+						&pcm_delay_frames[pcm_delay_frames_i++ % ARRAYSIZE(pcm_delay_frames)])) != 0)
+			warn("Couldn't get PCM delay: %s", snd_strerror(ret));
+		else {
+
+			struct timespec ts_now;
+			/* Rate limit delay updates to 1 update per second. */
+			struct timespec ts_delay = { .tv_sec = 1 };
+
+			gettimestamp(&ts_now);
+			timespecadd(&pcm_delay_update_ts, &ts_delay, &ts_delay);
+
+			snd_pcm_sframes_t pcm_delay_frames_avg = 0;
+			for (size_t i = 0; i < ARRAYSIZE(pcm_delay_frames); i++)
+				pcm_delay_frames_avg += pcm_delay_frames[i];
+			pcm_delay_frames_avg /= ARRAYSIZE(pcm_delay_frames);
+
+			const int delay = pcm_delay_frames_avg * 10000 / w->ba_pcm.rate;
+			if (difftimespec(&ts_now, &ts_delay, &ts_delay) < 0 &&
+					abs(delay - w->ba_pcm.client_delay) >= 100 /* 10ms */) {
+
+				pcm_delay_update_ts = ts_now;
+
+				w->ba_pcm.client_delay = delay;
+				if (!ba_dbus_pcm_update(&dbus_ctx, &w->ba_pcm, BLUEALSA_PCM_CLIENT_DELAY, &err)) {
+					error("Couldn't update BlueALSA PCM client delay: %s", err.message);
+					dbus_error_free(&err);
+					goto fail;
+				}
+
+			}
+
+		}
+
 		continue;
 
 close_alsa: