From: Luiz Augusto von Dentz <[email protected]>
This prints the owner name when it exits/quits/crash or releases a
transport.
---
- Looks like there is a bug/race on codec switch it appears the likes of
pipewire attempts to call Release in the process which stops the
acquire/resume:
bluetoothd[1774429]: profiles/audio/transport.c:transport_set_state() State
changed /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8: TRANSPORT_G
bluetoothd[1774429]: profiles/audio/transport.c:media_request_create()
Request created: method=Acquire id=50
bluetoothd[1774429]: profiles/audio/transport.c:media_owner_add() Owner
:1.133105 Request Acquire
bluetoothd[1774429]: profiles/audio/transport.c:media_transport_set_owner()
Transport /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8 Owner :1.5
bluetoothd[1774429]: profiles/audio/transport.c:release() Owner :1.133105
bluetoothd[1774429]: profiles/audio/transport.c:media_owner_remove() Owner
:1.133105 Request Acquire
profiles/audio/transport.c | 4 ++++
1 file changed, 4 insertions(+)
diff --git a/profiles/audio/transport.c b/profiles/audio/transport.c
index a4696154aba5..5395985b990f 100644
--- a/profiles/audio/transport.c
+++ b/profiles/audio/transport.c
@@ -531,6 +531,8 @@ static void media_owner_exit(DBusConnection *connection, void *user_data)
{
struct media_owner *owner = user_data;
+ DBG("Owner %s", owner->name);
+
owner->watch = 0;
media_owner_remove(owner);
@@ -742,6 +744,8 @@ static DBusMessage *release(DBusConnection *conn, DBusMessage *msg,
if (owner == NULL || g_strcmp0(owner->name, sender) != 0)
return btd_error_not_authorized(msg);
+ DBG("Owner %s", owner->name);
+
if (owner->pending) {
const char *member;
--
2.43.0
Hi Pauli,
On Wed, Jan 17, 2024 at 5:23 PM Luiz Augusto von Dentz
<[email protected]> wrote:
>
> From: Luiz Augusto von Dentz <[email protected]>
>
> This prints the owner name when it exits/quits/crash or releases a
> transport.
> ---
> - Looks like there is a bug/race on codec switch it appears the likes of
> pipewire attempts to call Release in the process which stops the
> acquire/resume:
>
> bluetoothd[1774429]: profiles/audio/transport.c:transport_set_state() State
> changed /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8: TRANSPORT_G
> bluetoothd[1774429]: profiles/audio/transport.c:media_request_create()
> Request created: method=Acquire id=50
> bluetoothd[1774429]: profiles/audio/transport.c:media_owner_add() Owner
> :1.133105 Request Acquire
> bluetoothd[1774429]: profiles/audio/transport.c:media_transport_set_owner()
> Transport /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8 Owner :1.5
> bluetoothd[1774429]: profiles/audio/transport.c:release() Owner :1.133105
> bluetoothd[1774429]: profiles/audio/transport.c:media_owner_remove() Owner
> :1.133105 Request Acquire
I wonder if we have a regression on BlueZ or PW for A2DP, since I
recall this used to work just fine while switching codecs back and
forth, but today it didn't work at all for me and I had to reconnect a
couple of times to get it working:
>pipewire --version
pipewire
Compiled with libpipewire 1.0.0
Linked with libpipewire 1.0.0
pw.node: (bluez_output.94_DB_56_F7_F2_88.1-70) running -> error
(Received error event)
> profiles/audio/transport.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/profiles/audio/transport.c b/profiles/audio/transport.c
> index a4696154aba5..5395985b990f 100644
> --- a/profiles/audio/transport.c
> +++ b/profiles/audio/transport.c
> @@ -531,6 +531,8 @@ static void media_owner_exit(DBusConnection *connection, void *user_data)
> {
> struct media_owner *owner = user_data;
>
> + DBG("Owner %s", owner->name);
> +
> owner->watch = 0;
>
> media_owner_remove(owner);
> @@ -742,6 +744,8 @@ static DBusMessage *release(DBusConnection *conn, DBusMessage *msg,
> if (owner == NULL || g_strcmp0(owner->name, sender) != 0)
> return btd_error_not_authorized(msg);
>
> + DBG("Owner %s", owner->name);
> +
> if (owner->pending) {
> const char *member;
>
> --
> 2.43.0
It seems you PW calls Release after Acquire, not sure if it didn't
like our response to Acquire or something.
--
Luiz Augusto von Dentz
Hi,
ke, 2024-01-17 kello 17:36 -0500, Luiz Augusto von Dentz kirjoitti:
> On Wed, Jan 17, 2024 at 5:23 PM Luiz Augusto von Dentz
> <[email protected]> wrote:
> >
> > From: Luiz Augusto von Dentz <[email protected]>
> >
> > This prints the owner name when it exits/quits/crash or releases a
> > transport.
> > ---
> > - Looks like there is a bug/race on codec switch it appears the likes of
> > pipewire attempts to call Release in the process which stops the
> > acquire/resume:
> >
> > bluetoothd[1774429]: profiles/audio/transport.c:transport_set_state() State
> > changed /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8: TRANSPORT_G
> > bluetoothd[1774429]: profiles/audio/transport.c:media_request_create()
> > Request created: method=Acquire id=50
> > bluetoothd[1774429]: profiles/audio/transport.c:media_owner_add() Owner
> > :1.133105 Request Acquire
> > bluetoothd[1774429]: profiles/audio/transport.c:media_transport_set_owner()
> > Transport /org/bluez/hci0/dev_94_DB_56_F7_F2_88/sep1/fd8 Owner :1.5
> > bluetoothd[1774429]: profiles/audio/transport.c:release() Owner :1.133105
> > bluetoothd[1774429]: profiles/audio/transport.c:media_owner_remove() Owner
> > :1.133105 Request Acquire
>
> I wonder if we have a regression on BlueZ or PW for A2DP, since I
> recall this used to work just fine while switching codecs back and
> forth, but today it didn't work at all for me and I had to reconnect a
> couple of times to get it working:
>
> > pipewire --version
> pipewire
> Compiled with libpipewire 1.0.0
> Linked with libpipewire 1.0.0
I don't think there are any recent related changes on Pipewire side
recently. I've also not been able to reproduce the above (w/ bluez 5.72
or current master) or seen other similar reports. Maybe there is some
old bug that surfaces only in some cases.
From the above log I don't get what is going wrong, maybe if you have
the full bluetoothd log that shows what happened after connect with
timestamps that could help.
> pw.node: (bluez_output.94_DB_56_F7_F2_88.1-70) running -> error
> (Received error event)
This should only appear if:
1. Acquire DBus call returns error
2. Acquire DBus call results to NoReply timeout error
3. BlueZ initiates a transition back to inactive state for a transport
that was previously acquired
Due to the last one, the full log would be useful.
>
> > profiles/audio/transport.c | 4 ++++
> > 1 file changed, 4 insertions(+)
> >
> > diff --git a/profiles/audio/transport.c b/profiles/audio/transport.c
> > index a4696154aba5..5395985b990f 100644
> > --- a/profiles/audio/transport.c
> > +++ b/profiles/audio/transport.c
> > @@ -531,6 +531,8 @@ static void media_owner_exit(DBusConnection *connection, void *user_data)
> > {
> > struct media_owner *owner = user_data;
> >
> > + DBG("Owner %s", owner->name);
> > +
> > owner->watch = 0;
> >
> > media_owner_remove(owner);
> > @@ -742,6 +744,8 @@ static DBusMessage *release(DBusConnection *conn, DBusMessage *msg,
> > if (owner == NULL || g_strcmp0(owner->name, sender) != 0)
> > return btd_error_not_authorized(msg);
> >
> > + DBG("Owner %s", owner->name);
> > +
> > if (owner->pending) {
> > const char *member;
> >
> > --
> > 2.43.0
>
> It seems you PW calls Release after Acquire, not sure if it didn't
> like our response to Acquire or something.
>
--
Pauli Virtanen