On Wed, 2023-06-14 at 19:00 +0200, Joakim Tjernlund wrote:
> On Wed, 2023-06-14 at 09:53 -0700, Luiz Augusto von Dentz wrote:
> > Hi Joakim,
> >
> > On Wed, Jun 14, 2023 at 9:32 AM Joakim Tjernlund
> > <Joakim.Tjernlund@xxxxxxxxxxxx> wrote:
> > >
> > > On Wed, 2023-06-14 at 09:25 -0700, Luiz Augusto von Dentz wrote:
> > > > Hi Joakim,
> > > >
> > > > On Wed, Jun 14, 2023 at 5:36 AM Joakim Tjernlund
> > > > <Joakim.Tjernlund@xxxxxxxxxxxx> wrote:
> > > > >
> > > > > commit bap: Add broadcast source support, 3030883, in bluez.git
> > > > >
> > > > > A co-worker see this SEGV when connecting a headset:
> > > > >
> > > > > Jun 13 13:38:15 systemd-coredump[3941]: Process 1897 (bluetoothd) of user 0 dumped core.
> > > > > Module bluetoothd without build-id.
> > > > > #0 0x0000556bea93277a a2dp_resume_complete (bluetoothd + 0x3e77a)
> > > > > #1 0x0000556bea9210a2 finalize_resume (bluetoothd + 0x2d0a2)
> > > > > #2 0x0000556bea92afaf avdtp_start_resp (bluetoothd + 0x36faf)
> > > > > #6 0x0000556bea9dcc85 mainloop_run (bluetoothd + 0xe8c85)
> > > > > #7 0x0000556bea9dd0dc mainloop_run_with_signal (bluetoothd + 0xe90dc)
> > > > > #8 0x0000556bea91a4ef main (bluetoothd + 0x264ef)
> > > > > #11 0x0000556bea91ace1 _start (bluetoothd + 0x26ce1)
> > > > > Jun 13 13:38:15 systemd[1]: bluetooth.service: Main process exited, code=dumped, status=11/SEGV
> > > > >
> > > > >
> > > > > Crash seems to be at:
> > > > >
> > > > > 342 static void a2dp_resume_complete(struct avdtp *session, int err,
> > > > > 343 void *user_data)
> > > > > 344 {
> > > > > 345 struct media_owner *owner = user_data;
> > > > > 346 struct media_request *req = owner->pending;
> > > > > 347 struct media_transport *transport = owner->transport;
> > > > > 348 struct a2dp_sep *sep = media_endpoint_get_sep(transport->endpoint);
> > > > >
> > > > > A good start(but does NOT fix the problem) might be:
> > > > >
> > > > > --- bluez-9999/profiles/audio/transport.c.org 2023-06-13 18:38:14.542137531 +0200
> > > > > +++ bluez-9999/profiles/audio/transport.c 2023-06-13 18:48:32.542527882 +0200
> > > > > @@ -345,7 +345,7 @@
> > > > > struct media_owner *owner = user_data;
> > > > > struct media_request *req = owner->pending;
> > > > > struct media_transport *transport = owner->transport;
> > > > > - struct a2dp_sep *sep = media_endpoint_get_sep(transport->endpoint);
> > > > > + struct a2dp_sep *sep;
> > > > > struct avdtp_stream *stream;
> > > > > int fd;
> > > > > uint16_t imtu, omtu;
> > > > > @@ -355,7 +355,10 @@
> > > > >
> > > > > if (err)
> > > > > goto fail;
> > > > > + if (!transport)
> > > > > + goto fail;
> > > > >
> > > > > + sep = media_endpoint_get_sep(transport->endpoint);
> > > > > stream = a2dp_sep_get_stream(sep);
> > > > > if (stream == NULL)
> > > > > goto fail;
> > > > >
> > > > > bluez-5.66 Works fine though.
> > > > >
> > > > > Headset: WH-1000XM3
> > > > >
> > > > > Jocke
> > > >
> > > > Weird, I don't think much has changed for A2DP, but perhaps there is
> > > > some BAP related changes affecting A2DP for some reason, any chance to
> > > > bisect the patch that introduces this problem? Or it is not always
> > > > reproducible?
> > >
> > > It is reproducible but on an remote laptop used for daily work so would disturb quite a lot.
> > > Can I turn off BAP somehow to see if it is interfering ?
> > >
> > > Any chance it is related to https://github.com/bluez/bluez/issues/533 ?
> >
> > Right, yeah that is possible since it appears to be some unbalanced
> > reference count issue, that said that was a very old version, not sure
> > if we haven't fixed that.
>
> It is not fixed in unref code discussed in that issue on master
>
> Jocke
Managed to get a bt:
Core was generated by `/usr/libexec/bluetooth/bluetoothd'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 a2dp_resume_complete (session=0x55e437429c40, err=0, user_data=0x55e437456c90) at profiles/audio/transport.c:354
warning: Source file is more recent than executable.
354 req->id = 0;
(gdb) bt full
#0 a2dp_resume_complete (session=0x55e437429c40, err=0, user_data=0x55e437456c90) at profiles/audio/transport.c:354
owner = 0x55e437456c90
req = 0x0
transport = 0x0
sep = <optimized out>
stream = <optimized out>
fd = 0
imtu = 0
omtu = 0
ret = <optimized out>
#1 0x000055e4367f30a2 in finalize_resume (data=0x55e43745fc90) at profiles/audio/a2dp.c:352
cb = 0x55e437472f10
s = 0x55e43745fc90
l = 0x0
#2 0x000055e4367fcfaf in avdtp_start_resp (resp=0x55e437429cb3, size=0, stream=0x55e437455690, session=0x55e437429c40) at profiles/audio/avdtp.c:2868
sep = 0x55e437411660
#3 avdtp_parse_resp (transaction=<optimized out>, size=0, buf=0x55e437429cb3, signal_id=<optimized out>, stream=0x55e437455690,
session=0x55e437429c40) at profiles/audio/avdtp.c:2988
next = 0x0
get_all = 0x55e4368c19a8 ""
next = <optimized out>
get_all = <optimized out>
__func__ = "avdtp_parse_resp"
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
__btd_debug_desc = {file = 0x55e4368b3f97 "profiles/audio/avdtp.c", flags = 0}
#4 session_cb (chan=<optimized out>, cond=<optimized out>, data=0x55e437429c40) at profiles/audio/avdtp.c:2286
session = 0x55e437429c40
header = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
size = <optimized out>
fd = <optimized out>
__func__ = "session_cb"
#5 0x00007fb64c271acf in g_main_dispatch (context=0x55e43740c870) at /var/tmp/portage/dev-libs/glib-2.76.2/glib-2.76.2/glib/gmain.c:3460
dispatch = 0x7fb64c2ca330 <g_io_unix_dispatch>
prev_source = 0x0
begin_time_nsec = 0
was_in_call = 0
user_data = 0x55e437429c40
callback = 0x55e4367fae60 <session_cb>
cb_funcs = <optimized out>
cb_data = 0x55e437448570
need_destroy = <optimized out>
source = 0x55e437456e50
current = 0x55e437416a00
i = 0
current = <optimized out>
i = <optimized out>
__func__ = "g_main_dispatch"
source = <optimized out>
_g_boolean_var_163 = <optimized out>
was_in_call = <optimized out>
user_data = <optimized out>
callback = <optimized out>
cb_funcs = <optimized out>
cb_data = <optimized out>
need_destroy = <optimized out>
dispatch = <optimized out>
prev_source = <optimized out>
begin_time_nsec = <optimized out>
_g_boolean_var_164 = <optimized out>
#6 g_main_context_dispatch (context=context@entry=0x55e43740c870) at /var/tmp/portage/dev-libs/glib-2.76.2/glib-2.76.2/glib/gmain.c:4200
No locals.
#7 0x00007fb64c271ea8 in g_main_context_iterate (context=0x55e43740c870, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>)
at /var/tmp/portage/dev-libs/glib-2.76.2/glib-2.76.2/glib/gmain.c:4276
max_priority = 2147483647
timeout = 5952
--Type <RET> for more, q to quit, c to continue without paging--
some_ready = 1
nfds = <optimized out>
allocated_nfds = 35
fds = 0x55e437439090
begin_time_nsec = 0
#8 0x00007fb64c27215f in g_main_loop_run (loop=0x55e43740c9e0) at /var/tmp/portage/dev-libs/glib-2.76.2/glib-2.76.2/glib/gmain.c:4479
self = <optimized out>
__func__ = "g_main_loop_run"
#9 0x000055e4368afb55 in mainloop_run () at src/shared/mainloop-glib.c:66
No locals.
#10 0x000055e4368affac in mainloop_run_with_signal (func=func@entry=0x55e43682f6a0 <signal_callback>, user_data=user_data@entry=0x0)
at src/shared/mainloop-notify.c:188
data = 0x55e437416820
io = 0x55e437416840
ret = <optimized out>
#11 0x000055e4367ec4ff in main (argc=<optimized out>, argv=<optimized out>) at src/main.c:1450
context = <optimized out>
err = 0x0
sdp_mtu = 0
sdp_flags = <optimized out>
gdbus_flags = <optimized out>
__func__ = "main"
So req is NULL and:
print *owner
$2 = {transport = 0x0, pending = 0x0, name = 0x55e437473f70 ":1.41", watch = 0}
print *session
$3 = {ref = 3, version = 259, lseps = 0x55e437425990, device = 0x55e4374313d0, state = AVDTP_SESSION_STATE_CONNECTED, io = 0x55e437458370,
io_id = 380, seps = 0x55e4374559e0 = {0x55e437455a40, 0x55e43742bb80, 0x55e43742c1f0, 0x55e43745dad0, 0x55e43745e060}, streams = 0x55e43745db70 = {
0x55e437455690}, req_queue = 0x0, prio_queue = 0x0, pending_open = 0x0, pending_open_io = 0x0, phy = 511, imtu = 672, omtu = 895, in = {
active = 0, no_of_packets = 1, transaction = 3 '\003', message_type = 2 '\002', signal_id = 7 '\a',
buf = "\004\005\334\b\030\b\f\b\b\b", '\000' <repeats 1013 times>, data_size = 0 '\000'},
buf = 0x55e43742a0f0 "2\a\024", <incomplete sequence \334>, discover = 0x0, req = 0x55e437455b70, dc_timer = 0, dc_timeout = 1, stream_setup = 0}
