On 04/06, Luiz Augusto von Dentz wrote: > Hi Konrad, > > On Thu, Apr 6, 2017 at 3:51 PM, Konrad Zapalowicz > <konrad.zapalowicz@xxxxxxxxxxxxx> wrote: > > Hey, > > > > I see a regression in 5.44 when testing Sony SBH52 headset. It fails to > > connect profiles but the worst thing is that the bluetoothd crashes > > (logs below). > > > > I have git bisect'ed it down to the commit f2483bbfd. It works fine if > > I remove it. > > That is because the very next patch fix it: > > commit 4a8c33b1f76edf2dfe33b9956014cc2746ae71d8 > Author: Luiz Augusto von Dentz <luiz.von.dentz@xxxxxxxxx> > Date: Mon Nov 14 13:30:09 2016 +0200 > > core/adapter: Fix using wrong address type to listen ATT > > bdaddr_type shall only matter for controllers supporting LE otherwise > it may cause BDADDR_BREDR to be used for things like LE ATT socket > listen breaking reconnections. > Is your suggestion that I might be missing the above patch? I have it included, I'm using regular 5.44 release. > > Stacktrace: > > > > (gdb) c > > Continuing. > > > > Program received signal SIGSEGV, Segmentation fault. > > strlen () at ../sysdeps/x86_64/strlen.S:106 > > 106 ../sysdeps/x86_64/strlen.S: No such file or directory. > > (gdb) bt > > #0 strlen () at ../sysdeps/x86_64/strlen.S:106 > > #1 0x00007f92806179a1 in _IO_vfprintf_internal (s=s@entry=0x557f37ad5520, format=<optimized out>, format@entry=0x557f36cd515c "%s:%s() %s err %d", ap=0x7ffc0b7a86d0) > > at vfprintf.c:1637 > > #2 0x00007f92806dffc6 in ___vfprintf_chk (fp=fp@entry=0x557f37ad5520, flag=flag@entry=1, format=format@entry=0x557f36cd515c "%s:%s() %s err %d", > > ap=ap@entry=0x7ffc0b7a86d0) at vfprintf_chk.c:33 > > #3 0x00007f92806c9028 in __GI___vsyslog_chk (pri=<optimized out>, pri@entry=7, flag=flag@entry=1, fmt=fmt@entry=0x557f36cd515c "%s:%s() %s err %d", > > ap=ap@entry=0x7ffc0b7a86d0) at ../misc/syslog.c:222 > > #4 0x0000557f36c6735b in vsyslog (__ap=0x7ffc0b7a86d0, __fmt=0x557f36cd515c "%s:%s() %s err %d", __pri=7) at /usr/include/x86_64-linux-gnu/bits/syslog.h:47 > > #5 btd_debug (index=index@entry=65535, format=format@entry=0x557f36cd515c "%s:%s() %s err %d") at src/log.c:252 > > #6 0x0000557f36c94d88 in device_svc_resolved (dev=0x557f36c90e60 <browse_request_exit>, bdaddr_type=0 '\000', err=-111) at src/device.c:2214 > > #7 0x0000557f36c97adb in search_cb (user_data=<optimized out>, err=-111, recs=<optimized out>) at src/device.c:4516 > > #8 browse_cb (recs=<optimized out>, err=-111, user_data=<optimized out>) at src/device.c:4549 > > #9 0x0000557f36c73551 in connect_watch (chan=0x557f37ae0350, cond=<optimized out>, user_data=0x557f37ae0060) at src/sdp-client.c:286 > > #10 0x00007f928124f6ea in g_main_context_dispatch () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0 > > #11 0x00007f928124faa0 in ?? () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0 > > #12 0x00007f928124fdc2 in g_main_loop_run () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0 > > #13 0x0000557f36c353cc in main (argc=<optimized out>, argv=<optimized out>) at src/main.c:708 > > (gdb) > > Ok, so this seem to be SDP causing and error, 111 connection refused. > > > Syslog: > > > > bluetoothd: src/device.c:bonding_request_new() Requesting bonding for 68:76:4F:6C:31:E9 > > bluetoothd: src/agent.c:agent_ref() 0x557f37ae5120: ref=3 > > bluetoothd: src/agent.c:agent_unref() 0x557f37ae5120: ref=2 > > bluetoothd: src/adapter.c:suspend_discovery() > > bluetoothd: src/adapter.c:adapter_bonding_attempt() hci0 bdaddr 68:76:4F:6C:31:E9 type 0 io_cap 0x01 > > bluetoothd: src/adapter.c:add_whitelist_complete() 68:76:4F:6C:31:E9 added to kernel whitelist > > bluetoothd: src/adapter.c:connected_callback() hci0 device 68:76:4F:6C:31:E9 connected eir_len 12 > > bluetoothd: src/adapter.c:new_link_key_callback() hci0 new key for 68:76:4F:6C:31:E9 type 4 pin_len 0 store_hint 1 > > bluetoothd: src/device.c:device_set_bonded() > > bluetoothd: src/device.c:device_bonding_complete() bonding 0x557f37acc860 status 0x00 > > bluetoothd: src/device.c:device_bonding_complete() Proceeding with service discovery > > bluetoothd: src/agent.c:agent_unref() 0x557f37ae5120: ref=1 > > bluetoothd: src/adapter.c:resume_discovery() > > bluetoothd: src/adapter.c:pair_device_complete() Success (0x00) > > bluetoothd: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 68:76:4F:6C:31:E9 type 0 status 0x0 > > bluetoothd: src/device.c:device_bonding_complete() bonding (nil) status 0x00 > > bluetoothd: src/adapter.c:resume_discovery() > > bluetoothd: src/gatt-database.c:connect_cb() New incoming BR/EDR ATT connection > > bluetoothd: attrib/gattrib.c:g_attrib_ref() 0x557f37ae4b40: g_attrib_ref=1 > > bluetoothd: src/device.c:load_gatt_db() Restoring 68:76:4F:6C:31:E9 gatt database from file > > bluetoothd: No cache for 68:76:4F:6C:31:E9 > > bluetoothd: src/gatt-client.c:btd_gatt_client_connected() Device connected. > > bluetoothd: src/adapter.c:dev_disconnected() Device 68:76:4F:6C:31:E9 disconnected, reason 3 > > bluetoothd: src/adapter.c:adapter_remove_connection() > > bluetoothd: plugins/policy.c:disconnect_cb() reason 3 > > bluetoothd: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 68:76:4F:6C:31:E9 type 0 status 0xe > > bluetoothd: src/device.c:device_bonding_complete() bonding (nil) status 0x0e > > bluetoothd: src/device.c:device_bonding_failed() status 14 > > bluetoothd: src/adapter.c:resume_discovery() > > bluetoothd: src/device.c:gatt_debug() Primary service discovery failed. ATT ECODE: 0x00 > > bluetoothd: src/device.c:gatt_debug() Failed to initialize gatt-client > > bluetoothd: src/device.c:gatt_client_ready_cb() status: failed, error: 0 > > bluetoothd: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_68_76_4F_6C_31_E9 err -5 > > bluetoothd: src/device.c:att_disconnected_cb() > > bluetoothd: src/device.c:att_disconnected_cb() Connection reset by peer (104) > > bluetoothd: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up. > > bluetoothd: src/device.c:att_disconnected_cb() Automatic connection disabled > > bluetoothd: attrib/gattrib.c:g_attrib_unref() 0x557f37ae4b40: g_attrib_unref=0 > > bluetoothd: src/device.c:btd_device_set_trusted() trusted 1 > > bluetoothd: src/device.c:connect_profiles() /org/bluez/hci0/dev_68_76_4F_6C_31_E9 (all), client :1.256 > > bluetoothd: src/device.c:connect_profiles() Resolving services for /org/bluez/hci0/dev_68_76_4F_6C_31_E9 > > bluetoothd: src/gatt-database.c:connect_cb() New incoming BR/EDR ATT connection > > bluetoothd: attrib/gattrib.c:g_attrib_ref() 0x557f37ae4b40: g_attrib_ref=1 > > bluetoothd: src/device.c:load_gatt_db() Restoring 68:76:4F:6C:31:E9 gatt database from file > > bluetoothd: No cache for 68:76:4F:6C:31:E9 > > bluetoothd: src/gatt-client.c:btd_gatt_client_connected() Device connected. > > bluetoothd: 89:48:53:01:00:27: error updating services: Connection refused (111) > > Interesting, the device is connecting ATT over BR/EDR which is weird > if that is a headset, and we can see the 111, though the address > printed seems wrong, I wonder if that is why it crashes. The address thing is something to check further. I have no such device in a range whatsoever. > > > There is one interestig thing that I have noticed examining the the > > btmon output. The bluez is repeatedly (literally till the end) sending > > the Information Request (Extended Feature Mask) and the headset is > > answering Not Supported. For the same headset bluez 5.43 sends this > > request only once. The bluez 5.44 works fine with a Phillips headset > > that answers Success to this knd of Information Response. > > Well this is the information request is sent by the kernel, so if you > haven't change it between versions that should not change between > daemon versions, but ATT is not a fixed channel on BR/EDR so I wonder > if the information request is actually sent because ATT is being > connected. Could be, good point. > > > Additionaly to Information Request (Ext Feature Mask) bluez 5.44 keeps > > repeating ATT Read By Group Type Request, GATT Primary Service > > Declaration which in case of Phillips device happens only once. Bluez > > 5.43 does not send it whatsoever. > > I suspect it doesn't even connect over ATT in 5.43, anyway that should > only happen once but I can see from the logs that it fails and > disconnects and then connects again. I'll capture some logs with 5.43 and share later this week. This looks interesting to follow. Thanks for your comments, K > > > Let me know if I can in any way help debugging this issue further. > > > > Thanks, > > Konrad > > -- > > To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in > > the body of a message to majordomo@xxxxxxxxxxxxxxx > > More majordomo info at http://vger.kernel.org/majordomo-info.html > > > > -- > Luiz Augusto von Dentz -- To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
