Re: [PATCH BlueZ 3/3] avdtp: Remove use of G_PRIORITY_LOW

Hi Miao,

On Wed, Feb 17, 2021 at 12:24 PM Miao-chen Chou [off-list ref] wrote:

Hi Luiz,

Thanks for reforming the fix. I tested the series on my DUT and it
works as expected where the paired device persists throughout the
suspend and resume. However I observed the following sequence in the
logs.
Given that this series raises the priority of avdtp's IO, session_cb()
got poked immediately after the index was removed, and that triggers
avdtp_free() early. About ~100ms later, avdtp_unregister_sep was
called with a non-NULL pointer to the sep with A2DP. However, that sep
is no longer valid since avdtp_free() freed all the seps. I wonder if
this can be a potential issue?

Are you referring to the local sep or the remote ones? avdtp_free
should not have free any local ones as it just have a reference to the
queue and that afaik was never meant to be free by avdtp_free.

= Close Index: 5C:3A:45:9C:CF:8A
                            [hci0] 2021-02-17 11:52:02.607860
@ MGMT Event: Index Removed (0x0005) plen 0
                   {0x0003} [hci0] 2021-02-17 11:52:02.607866
...
= Delete Index: 5C:3A:45:9C:CF:8A
                            [hci0] 2021-02-17 11:52:02.607876
= bluetoothd: Unable to get io data for Hands-Free Voice gateway:
getpeername: Transport endpoint is...   2021-02-17 11:52:02.618425
= bluetoothd: src/service.c:change_state() 0x56093254dff0: device
28:11:A5:E1:4F:67 profile Hands-Fre..   2021-02-17 11:52:02.618480
= bluetoothd: src/service.c:btd_service_unref() 0x56093254dff0: ref=2
                                   2021-02-17 11:52:02.618486
= bluetoothd: profiles/audio/avdtp.c:session_cb()
                                   2021-02-17 11:52:02.618497
= bluetoothd: profiles/audio/avdtp.c:avdtp_ref() 0x560932556830: ref=2
                                   2021-02-17 11:52:02.618585
= bluetoothd: profiles/audio/avdtp.c:connection_lost() Disconnected
from 28:11:A5:E1:4F:67                2021-02-17 11:52:02.618594
= bluetoothd: profiles/audio/a2dp.c:abort_cfm() Source 0x5609324c36b0:
Abort_Cfm                          2021-02-17 11:52:02.618600
= bluetoothd: profiles/audio/avdtp.c:avdtp_sep_set_state() stream
state changed: OPEN -> IDLE             2021-02-17 11:52:02.618605
= bluetoothd: src/service.c:change_state() 0x560932552490: device
28:11:A5:E1:4F:67 profile a2dp-sink..   2021-02-17 11:52:02.621466
= bluetoothd: profiles/audio/avdtp.c:avdtp_unref() 0x560932556830:
ref=1                                  2021-02-17 11:52:02.621492
= bluetoothd: profiles/audio/sink.c:sink_set_state() State changed
/org/bluez/hci0/dev_28_11_A5_E1_4F..   2021-02-17 11:52:02.621500
= bluetoothd: profiles/audio/a2dp.c:channel_remove() chan
0x5609324a7930                                  2021-02-17
11:52:02.621539
= bluetoothd: profiles/audio/avdtp.c:avdtp_unref() 0x560932556830:
ref=0                                  2021-02-17 11:52:02.621546
= New Index: 00:00:00:00:00:00 (Primary,USB,hci0)
                            [hci0] 2021-02-17 11:52:02.619195
= bluetoothd: profiles/audio/avdtp.c:avdtp_free() 0x560932556830
                                   2021-02-17 11:52:02.621615
= bluetoothd: Endpoint unregistered: sender=:1.50
path=/org/chromium/Cras/Bluetooth/A2DPSource            2021-02-17
11:52:02.764766
= bluetoothd: profiles/audio/media.c:media_endpoint_destroy()
sender=:1.50 path=/org/chromium/Cras/Bl..   2021-02-17 11:52:02.764792
= bluetoothd: profiles/audio/avdtp.c:avdtp_unregister_sep() SEP
0x5609324c36b0 unregistered: type:0 c..   2021-02-17 11:52:02.764797
= bluetoothd: profiles/audio/media.c:media_player_destroy()
sender=:1.50 path=/org/chromium/Cras/Blue..   2021-02-17
11:52:02.771347

On Tue, Feb 16, 2021 at 3:35 PM Luiz Augusto von Dentz
[off-list ref] wrote:

quoted

From: Luiz Augusto von Dentz <redacted>

G_PRIORITY_LOW was used in order to prioritize the AVDTP media transport
channel over the signalling channel but this has the side effect of
delaying the dispatching of other conditions such as HUP/NVAL, so now
that BtIO use G_PRIORITY_HIGH for its watches we no longer need to
deprioritize session_cb.
---
 profiles/audio/avdtp.c | 13 ++-----------
 1 file changed, 2 insertions(+), 11 deletions(-)

diff --git a/profiles/audio/avdtp.c b/profiles/audio/avdtp.c
index 9ddcd6464..088ca58b3 100644
--- a/profiles/audio/avdtp.c
+++ b/profiles/audio/avdtp.c

@@ -2378,19 +2378,10 @@ static void avdtp_connect_cb(GIOChannel *chan, GError *err, gpointer user_data)
                if (session->io_id)
                        g_source_remove(session->io_id);

-               /* This watch should be low priority since otherwise the
-                * connect callback might be dispatched before the session
-                * callback if the kernel wakes us up at the same time for
-                * them. This could happen if a headset is very quick in
-                * sending the Start command after connecting the stream
-                * transport channel.
-                */
-               session->io_id = g_io_add_watch_full(chan,
-                                               G_PRIORITY_LOW,
+               session->io_id = g_io_add_watch(chan,
                                                G_IO_IN | G_IO_ERR | G_IO_HUP
                                                | G_IO_NVAL,
-                                               (GIOFunc) session_cb, session,
-                                               NULL);
+                                               (GIOFunc) session_cb, session);

                if (session->stream_setup)
                        set_disconnect_timer(session);
--

2.29.2

Regards,
Miao

-- 
Luiz Augusto von Dentz