Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Service not detected by BlueZ for a specific device #438

Closed
bdr99 opened this issue Dec 12, 2022 · 17 comments
Closed

Service not detected by BlueZ for a specific device #438

bdr99 opened this issue Dec 12, 2022 · 17 comments

Comments

@bdr99
Copy link

bdr99 commented Dec 12, 2022 •
edited
Loading

Operating System: Ubuntu 22.04 (Linux 5.15.0-56-generic)
BlueZ version: latest master

I have a certain device (Eufy Smart Scale P2) which exposes three BLE services. The issue I'm having is that BlueZ can only see the first two, and the third one (UUID 0xFFF0) is not visible. When I ran sudo bluetoothd --debug --nodetach to get the debug output, I noticed that all three services are shown in the debug output. But when I run bluetoothctl info to check the services, I only see two services.

I'm pretty new to BlueZ so please let me know what info I can provide to help debug this issue.

Here is a screenshot of nRF connect on my phone, showing all three services:

image

Here is the output when I run bluetoothctl info on the device (notice the FFF0 service is not shown):

Device CF:E6:08:09:01:02 (public)
        Name: eufy T9148
        Alias: eufy T9148
        Paired: no
        Trusted: no
        Blocked: no
        Connected: yes
        LegacyPairing: no
        UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
        UUID: Battery Service           (0000180f-0000-1000-8000-00805f9b34fb)
        ManufacturerData Key: 0xff5f
        ManufacturerData Value:
  cf e6 08 09 01 02 cf 00 00 3a 02 00 00 00 01 01  .........:......
  00 00 f7                                         ...
        Battery Percentage: 0x5f (95)

Here is the debug log output of bluetoothd when connecting to the device: bluetoothd_latest_master.log

I previously thought this was being caused by a segfault I was seeing in bluetoothd, but that turned out to be a red herring, since the segfault was fixed in the latest release but the issue still persists.
@Vudentz
Copy link
Contributor

Vudentz commented Dec 12, 2022

@bdr99 try running bluetoothd with valgrind to generate a backtrace.

@bdr99
Copy link
Author

bdr99 commented Dec 12, 2022 •
edited
Loading

@Vudentz Sure, here are the logs when running with valgrind:

valgrind.log

Also, running bluetoothd with valgrind actually fixes the issue, I assume because it allows bluetoothd to continue despite the segfault. Note that the FFF0 service is now showing in bluetoothctl info.

➜  ~ bluetoothctl info CF:E6:08:09:01:02
Device CF:E6:08:09:01:02 (public)
        Name: eufy T9148
        Alias: eufy T9148
        Paired: no
        Trusted: no
        Blocked: no
        Connected: yes
        LegacyPairing: no
        UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
        UUID: Battery Service           (0000180f-0000-1000-8000-00805f9b34fb)
        UUID: Unknown                   (0000fff0-0000-1000-8000-00805f9b34fb)

@bdr99 bdr99 mentioned this issue Dec 12, 2022
Closed
@Vudentz
Copy link
Contributor

Vudentz commented Dec 12, 2022

@bdr99 please install the debug symbols otherwise valgrind can't decode them:


==6843== Invalid read of size 8
==6843==    at 0x1C0F67: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C1647: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1CA687: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C015B: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C4AE8: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x48B9C43: g_main_context_dispatch (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x490E6C7: ??? (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x48B92B2: g_main_loop_run (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x129C6E: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x4A15D8F: (below main) (libc_start_call_main.h:58)
==6843==  Address 0x53a7220 is 0 bytes inside a block of size 128 free'd
==6843==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==6843==    by 0x1C771F: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1D0E3C: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1BC9B2: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C1ABB: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1CA687: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C015B: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C4AE8: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x48B9C43: g_main_context_dispatch (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x490E6C7: ??? (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x48B92B2: g_main_loop_run (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x129C6E: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==  Block was alloc'd at
==6843==    at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==6843==    by 0x1C5646: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C79FD: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1BC8E1: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C1DB2: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1CA687: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C015B: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x1C4AE8: ??? (in /usr/lib/bluetooth/bluetoothd)
==6843==    by 0x48B9C43: g_main_context_dispatch (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x490E6C7: ??? (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x48B92B2: g_main_loop_run (in /usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.7200.4)
==6843==    by 0x129C6E: ??? (in /usr/lib/bluetooth/bluetoothd

Btw, any chance to test with the latest to see if still reproducible with it?

@bdr99
Copy link
Author

bdr99 commented Dec 12, 2022 •
edited
Loading

@Vudentz Sorry, I'm not very familiar with BlueZ and am honestly not sure how to do either of those things. Would you mind briefly summarizing the steps? I'm on an Ubuntu 22.04 system by the way.

I tried these ways of installing the debug symbols, but they didn't work:

➜  ~ sudo apt install bluez-dbgsym
Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
E: Unable to locate package bluez-dbgsym
➜  ~ sudo apt-get install bluez-dbg
Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
E: Unable to locate package bluez-dbg

@bdr99
Copy link
Author

bdr99 commented Dec 12, 2022

@Vudentz With help from @dlech I was able to get the debug symbols installed. Here is the valgrind log with debug symbols:

valgrind_with_symbols.log

I would still need some guidance in order to test with the latest commit.

@dlech
Copy link
Contributor

dlech commented Dec 12, 2022

Instructions to build BlueZ from source are in the main README.

@bdr99
Copy link
Author

bdr99 commented Dec 13, 2022

Thanks again, @dlech.

@Vudentz I tested with the latest master commit, and I am no longer getting a segfault from bluetoothd. However, the original problem still remains, which is that BlueZ does not see the service with UUID 0xFFF0. 5.65 behaves the same as latest master. So, to summarize:

5.64: Segfaults, and service does not show.
5.65: Does not segfault, but service does not show.
latest master: Does not segfault, but service does not show.

Here is the output of bluetoothctl connect and bluetoothctl info with the latest master, showing that only two of the three services are visible:

 ➜  ~ bluetoothctl connect CF:E6:08:09:01:02
Attempting to connect to CF:E6:08:09:01:02
[CHG] Device CF:E6:08:09:01:02 Connected: yes
Connection successful
 ➜  ~ bluetoothctl info CF:E6:08:09:01:02
Device CF:E6:08:09:01:02 (public)
        Name: eufy T9148
        Alias: eufy T9148
        Paired: no
        Bonded: no
        Trusted: no
        Blocked: no
        Connected: no
        LegacyPairing: no
        UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
        UUID: Battery Service           (0000180f-0000-1000-8000-00805f9b34fb)

Here is the debug log from bluetoothd with the latest master commit, which does not segfault:

bluetoothd_latest_master.log

@bdr99 bdr99 changed the title Segfault in bluetoothd when getting services/characteristics for a specific device Service not detected by BlueZ for a specific device Dec 13, 2022
@bdr99
Copy link
Author

bdr99 commented Dec 13, 2022 •
edited
Loading

@Vudentz I bisected the segfault to this commit: e0870ce. I noticed that commit only changed the debug logging, so I tried running bluetoothd without --debug, and it did not segfault. So since the segfault only happens with --debug, it looks like it's not the cause of the issue with the missing service, although it may still be related to it.

I've updated the issue title and description to reflect these findings, and I'd appreciate any input you may have for this issue. Please let me know if I can provide any other info.

@Vudentz
Copy link
Contributor

Vudentz commented Dec 15, 2022

@bdr99 Seems like there is some bugs with the last service:

bluetoothd[46555]: src/shared/gatt-client.c:discover_chrcs_cb() start: 0x0011, end: 0x0012, value: 0x0012, props: 0x08, uuid: 0000fff1-0000-1000-8000-00805f9b34fb
bluetoothd[46555]: src/shared/gatt-client.c:discover_chrcs_cb() start: 0x0013, end: 0x0015, value: 0x0014, props: 0x10, uuid: 0000fff2-0000-1000-8000-00805f9b34fb
bluetoothd[46555]: src/shared/gatt-client.c:discover_chrcs_cb() start: 0x0016, end: 0x0018, value: 0x0017, props: 0x10, uuid: 0000fff4-0000-1000-8000-00805f9b34fb
bluetoothd[46555]: src/shared/gatt-client.c:discovery_op_complete() service disappeared: start 0x0010 end 0x0018
bluetoothd[46555]: src/device.c:gatt_service_removed() start: 0x0010, end: 0x0018

Were you running with:

43d71b8

@bdr99
Copy link
Author

bdr99 commented Dec 15, 2022 •
edited
Loading

@Vudentz Yes, I was testing with the latest commit on the master branch, which includes the change you linked.

I think you're on the right track, since the last service is the one that is getting lost. Is there a way we can determine the reason why it is being removed from the list?

@Vudentz
Copy link
Contributor

Vudentz commented Dec 16, 2022

@bdr99 try with the following change:

https://patchwork.kernel.org/project/bluetooth/patch/20221215234404.2735181-1-luiz.dentz@gmail.com/

@bdr99
Copy link
Author

bdr99 commented Dec 16, 2022

@Vudentz Unfortunately, that patch didn't resolve the issue.

The debug output is the same as before, I still see the "service disappeared" line after the characteristics are discovered.

@BluezTestBot BluezTestBot mentioned this issue Dec 16, 2022
Closed
github-actions bot pushed a commit to BluezTestBot/bluez that referenced this issue Dec 16, 2022
@Vudentz @tedd-an
shared/gatt-client: Fix not marking service as active
bf13dcf 
If there are no characteristics to discover, or for some reason
bt_gatt_discover_descriptors is skiped, the service should be marked as
active.

Fixes: bluez#438
@BluezTestBot BluezTestBot mentioned this issue Dec 16, 2022
Closed
github-actions bot pushed a commit to BluezTestBot/bluez that referenced this issue Dec 16, 2022
@Vudentz @tedd-an
shared/gatt-client: Fix not marking service as active
6a17f47 
If there are no characteristics to discover, or for some reason
bt_gatt_discover_descriptors is skiped, or the last attribute is
actually a included service the service should be marked as
active as there will be no more attributes to be discovered.

Fixes: bluez#438
@Vudentz
Copy link
Contributor

Vudentz commented Dec 16, 2022

@Vudentz Unfortunately, that patch didn't resolve the issue.

The debug output is the same as before, I still see the "service disappeared" line after the characteristics are discovered.

Ive sent a v2:

https://patchwork.kernel.org/project/bluetooth/patch/20221216210611.2990552-1-luiz.dentz@gmail.com/

@bdr99
Copy link
Author

bdr99 commented Dec 16, 2022

@Vudentz That version didn't work either unfortunately. Again, the log output is the same as before, and I don't see the any occurrences of the new Unable to get service data at 0x%04x log that you added.

@Vudentz
Copy link
Contributor

Vudentz commented Dec 16, 2022

@Vudentz That version didn't work either unfortunately. Again, the log output is the same as before, and I don't see the any occurrences of the new Unable to get service data at 0x%04x log that you added.

Hmm, you don't seem to have any included service, not really sure why, can you upload the btmon traces?

@BluezTestBot BluezTestBot mentioned this issue Dec 17, 2022
Closed
github-actions bot pushed a commit to BluezTestBot/bluez that referenced this issue Dec 17, 2022
@Vudentz @tedd-an
shared/gatt-client: Fix not marking service as active
6891d1d 
If there are no characteristics to discover, or for some reason
bt_gatt_discover_descriptors is skiped, or the last attribute is
actually a included service the service should be marked as
active as there will be no more attributes to be discovered.

Fixes: bluez#438
github-actions bot pushed a commit to BluezTestBot/bluez that referenced this issue Dec 17, 2022
@Vudentz @tedd-an
shared/gatt-client: Fix not removing pending services
564c107 
If there are no characteristics to discover, or for some reason
bt_gatt_discover_descriptors is skiped, or the last attribute is
actually a included service the service should be removed from
pending list as there will be no more attributes to be discovered.

Fixes: bluez#438
@bdr99
Copy link
Author

bdr99 commented Dec 17, 2022

I already sent this trace to @Vudentz via Slack, but here it is in case anyone else wants to take a look:
issue438.log

@bdr99
Copy link
Author

bdr99 commented Dec 17, 2022 •
edited
Loading

@Vudentz Your v4 patch seems to have fixed the issue for me!

https://patchwork.kernel.org/project/bluetooth/patch/20221217011059.3087848-1-luiz.dentz@gmail.com/
https://patchwork.kernel.org/project/bluetooth/patch/20221217011059.3087848-2-luiz.dentz@gmail.com/

➜  core git:(dev) ✗ bluetoothctl info CF:E6:08:09:01:02
Device CF:E6:08:09:01:02 (public)
        Name: eufy T9148
        Alias: eufy T9148
        Paired: no
        Bonded: no
        Trusted: no
        Blocked: no
        Connected: yes
        LegacyPairing: no
        UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
        UUID: Battery Service           (0000180f-0000-1000-8000-00805f9b34fb)
        UUID: Unknown                   (0000fff0-0000-1000-8000-00805f9b34fb)
        ManufacturerData Key: 0xff5c
        ManufacturerData Value:
  cf e6 08 09 01 02 cf 00 00 11 03 00 00 00 01 01  ................
  00 00 dd                                         ...
        Battery Percentage: 0x5c (92)

@bdr99 bdr99 mentioned this issue Dec 22, 2022
Closed
@lykkin lykkin mentioned this issue May 27, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
3 participants
@dlech @Vudentz @bdr99