Not consistently recognizing ibeacons #415
Comments
|
OK, there is a lot to unpack here... At the core of the issue is that BlueZ doesn't want to flood the D-Bus with every single advertisement from every device. And in most situations this the correct thing to do. So BlueZ and the Linux kernel deliberately filter repeated advertisements from the same device. BlueZ has On Bluezero this is accessed with python-bluezero/bluezero/adapter.py Lines 230 to 237 in e120285 However, there was/is also filtering done by the Linux kernel which meant that advertisements would still be missed. As a workaround to this I implemented This means that you should never need to call If you are only seeing one advertisement from your iBeacon, have you set logging to import logging
from bluezero import observer
def print_ibeacon_range(data):
print(f'iBeacon data: {data.major}-{data.minor} @ {data.rssi} [{data.tx_pwer}]')
def main():
observer.start_beacon_scan(on_ibeacon=print_ibeacon_range)
if __name__ == '__main__':
observer.logger.setLevel(logging.DEBUG)
main()Implementing a range calculation is bit like saying there should only be one programming language. Which ever one I choose, it would be the wrong one for people depending on what they were trying to do. I'm not sure where you are on this, but if you need an introduction then take a look at: |
|
That's great, thanks for your explanations!
Ok, that should've already been taken care of since I'm calling
Yes - now I see that too, that makes sense.
The device seems to get removed repeatedly, but the callback doesn't necessarily get invoked - shouldn't the device only get removed once until it's re-discovered? I'm also surprised that there are periods of several minutes where the device doesn't get removed - do you have an idea why?
Thanks, that makes sense. I think I've seen that iOS implements ranging functionality, hence the question. |
|
I am not sure I fully understand what the logging output is telling me so time for me to share some theories and maybe you can prove (or disprove) them. Firstly, it seems like there are two entries per logging event. e.g. I suspect this is because Bluezero has If I remove these duplicates and focus on logging from one It does seem odd that it is getting removed 5 times for a single discovery. We probably need to do some more debug as to why this is. The time step between the add and remove is close together and what I would expect. However, the other gaps are massive in comparison. When running your script have separate terminals open with the following running to get more debug information:
|
Yes it's the same device. There's no other beacon (but many other bluetooth devices, many of them peripherals). I did some testing - I believe I mentioned before that it seems to get worse after running for a while, until the next reboot, so I rebooted first for a "clean slate". With
When "it gets worse", the time increases before the device is removed on bluetoothctl and To me this looks like there are two (maybe separate) issues:
Is it possible that (especially) the first issue is related to the very chatty dbus? Or could that also be caused by the second issue somehow? |
|
OK, I think I've been able to reproduce multiple removes for a single discovery. This is what I got:
It seems like a more sophisticated scheme is required to remove the device once it has been processed. Although I guess this doesn't address your main issues, which is you are not seeing all the updates from the beacon. I'm not quite sure where to go with this... any thoughts? |
|
It dawned on me that there should not be a class variable with a set tracking the devices to be removed. I have created a new branch with a fix that works for me. Can you take a look and let me know if it works for you also. By fix, I mean that I see frequent updates of the ibeacons RSSI and the "deletes" match the "founds". e.g. Any thoughts or comments welcome. |
|
Nice, thank you, that looks reasonable. I'm happy to give that a try, but I most likely won't get to it over the weekend. Do you maybe have an idea what I might try work around my other issue with not getting the updates? E.g. like resetting something around bluez/serial or maybe dbus? That also might give some clue about where the problem is. |
Difficult to speculate on this without knowing which step is filtering out the updates. There several layers that it goes through. Starting at the bottom and working up. Use Use Then finally, is making it through to |
|
First off - great, the fix for device removal works for me. I didn't notice multiple removals for the same device 👍 About the lack of discovery, I saw that I receive indeed There are multiple such Manually removing the device ( Earlier I was rebooting the device to "fix" it. I tested some more there, just restarting bluetooth works too (since it's Ubuntu Core I'm restarting adapter.powered = False
adapter.powered = True
adapter.start_discovery()I execute that every minute, but that doesn't really work - from what I can tell, this gets me into yet another "state" 😅 In the ideal case (e.g. after restarting the bluetooth service), I see something like this with bluetoothctl - which gets picked up nicely by bluezero: In my original "bad state", I see this: With my attempt at restarting scanning with the snippet above, I see a mixture of NEW/DEL as well as CHG, but only with RSSI - the CHG appear when restarting scanning, RSSI changes so I assume advertisements are still received from the beacon: This all leaves me more confused, rather than less... do you have other suggestions/tests that I could try? Is there a way I could get those RSSI changes? |
|
OK, there is a lot to unpack there, with a lot of options on what we can try. Let me see if I can do this in a clear and concise way....
Excellent! Thank you for testing. In D-Bus has two signals.
The While to get the So it is possible to work on the If you are going to stop and start things, I would stop discovery before powering off. e.g. adapter.stop_discovery()
adapter.powered = False
adapter.powered = True
adapter.start_discovery()
How are you executing this every minute? Are you using python-bluezero/bluezero/async_tools.py Lines 14 to 27 in e120285 If you want a delay between powering off and back on, then split the above in to two callbacks. With the "off" callback calling the "on" callback. E.g. |
|
Thanks for the suggestions - unfortunately, I couldn't get it to work reliably with I was thinking about that even in the "good state", I only get an update once every ~11s, while I see updates every second on the phone (which corresponds to the configured beacon advertisement interval). From your initial answer, I learned that there are different reasons why one wouldn't see all advertisements in bluezero. But it's not quite clear to me yet, with I wanted to mess around with When I scan using |
|
BlueZ is the official Bluetooth stack for Linux and is split between kernel and userspace There is a good talk on it at: https://youtu.be/VMDyebKT5c4?si=Ek9Gj9Kol5GlGjZE Which is where the following image comes from:
HCI Socket bypasses the All the HCI information is available in the Bluetooth Core Specification which runs to about 3,256 pages for the 5.2 version of the spec. The BlueZ Bluetooth Mamagement API is the next step up and the lowest level that the BlueZ developers recommend. This does still go via The problem for Python users is this bug makes it difficult to access the mgmt socket. There are other duplicate bugs on this in the system. Until they are fixed, this remains off bounds for many Python users. I did do a proof-of-concept library called btsocket which I believe is used in HomeAssistant but I don't really maintain the btsocket library. D-Bus API goes via Bluetooth has features such as device discovery and GATT notifications that are asynchronous. BlueZ uses the GLib mainloop for this and so that needs to be incorporated also depending what you are doing. Things like The issue you seem to be having is that your system is in an unknown state with the kernel or BlueZ userspace throttling the number of advertisements you are seeing. I am not sure how much more I and the Bluezero library can help. You might be at the stage where you are needing to use an RTOS like Zephyr The BlueZ D-Bus API did have I don't know if this would help with any of the issues you are seeing. |
|
Thanks for the video and explanations! That helped putting things together. Now I think I broadly understand what's going on in my setup:
I've stripped down the resetting to this: def restart():
adapter.stop_discovery()
adapter.start_discovery()
add_timer_seconds(2, restart)I omitted the |
|
Seems a sensible workaround. My only other thought was about the version of the kernel and BlueZ you are using. For the record, I'm testing this on: |
|
Hmm with this running a bit longer, I again got into the state where it's not discovering the beacon at all anymore, but I think I'll work around it by restarting bluez, which seems to work. Yes I can see that the bluez version can have something to do with it - I'm only on 5.53, from 2020, unfortunately I can't really update. Another unresolved issue is the |
I haven't been able to reproduce this. The error stack that you included originally points to specific code inside Bluezero that handles the My only thought is around devices using MAC Address Randomization. Bluezero dev_name = "dev_" + value.lower().replace(":", "_")Below I have done a re-implementation of the ibeacon scanning without using Bluezero. This just uses the Bluez D-Bus bindings directly. It uses the pydbus library for the D-Bus bindings as this is a more efficient library if you don't want to create peripherals. It might be worth giving it a try. If nothing else, it might help identify what is a Bluezero issue and what is outside Bluezero's control. import argparse
from gi.repository import GLib
from pydbus import SystemBus
import uuid
DEVICE_INTERFACE = 'org.bluez.Device1'
def stop_scan():
"""Stop device discovery and quit event loop"""
adapter.StopDiscovery()
mainloop.quit()
def clean_beacons(dongle, device_path):
"""
BlueZ D-Bus API does not show duplicates. This is a
workaround that removes devices that have been found
during discovery
"""
try:
dongle.RemoveDevice(device_path)
except GLib.Error as dbus_err:
if dbus_err.get_dbus_name() == 'org.bluez.Error.DoesNotExist':
print(f"Error: Device {device_path} not available to remove")
def process_ibeacon(data, beacon_type='iBeacon'):
"""Print iBeacon data in human-readable format"""
# print('DATA:', data)
beacon_uuid = uuid.UUID(bytes=bytes(data[2:18]))
major = int.from_bytes(bytearray(data[18:20]), 'big', signed=False)
minor = int.from_bytes(bytearray(data[20:22]), 'big', signed=False)
tx_pwr = int.from_bytes([data[22]], 'big', signed=True)
print(f'\t\t{beacon_type}: {beacon_uuid} - {major} - {minor} \u2197 {tx_pwr}')
def on_iface_added(owner, path, iface, signal, interfaces_and_properties):
"""
Event handler for D-Bus interface added.
Test to see if it is a new Bluetooth device
"""
iface_path, iface_props = interfaces_and_properties
if DEVICE_INTERFACE in iface_props:
on_device_found(iface_path, iface_props[DEVICE_INTERFACE])
def on_device_found(device_path, device_props):
"""
Handle new Bluetooth device being discovered.
If it is a beacon of type iBeacon then process it
"""
manufacturer_data = device_props.get('ManufacturerData')
if manufacturer_data:
for mfg_id in manufacturer_data:
# iBeacon 0x004c
if mfg_id == 0x004c and manufacturer_data[mfg_id][0] == 0x02:
process_ibeacon(manufacturer_data[mfg_id])
clean_beacons(adapter, device_path)
if __name__ == '__main__':
parser = argparse.ArgumentParser()
parser.add_argument('-d', '--duration', type=int, default=0,
help='Duration of scan [0 for continuous]')
args = parser.parse_args()
bus = SystemBus()
adapter = bus.get('org.bluez', '/org/bluez/hci0')
bus.subscribe(iface='org.freedesktop.DBus.ObjectManager',
signal='InterfacesAdded',
signal_fired=on_iface_added)
mainloop = GLib.MainLoop()
if args.duration > 0:
GLib.timeout_add_seconds(args.duration, stop_scan)
adapter.SetDiscoveryFilter({'DuplicateData': GLib.Variant.new_boolean(False)})
adapter.StartDiscovery()
try:
print('\n\tUse CTRL-C to stop discovery\n')
mainloop.run()
except KeyboardInterrupt:
stop_scan() |
|
Hi again! I put this aside for a while and am having a fresh look now. Thanks for the hint regarding MAC randomization. I did some statistics - there are some devices that pop up very often as removed, some quite rarely. Only a few of them seem to be randomized (according to this), so I don't think that's my (main) problem. But it does seem to be related to which other devices are around me. Thanks also for the pydbus snippet - that seems to behave largely the same as far as I can tell, so there doesn't seem to be an issue specific to bluezero 👍 One thing I noticed though, is that when "show duplicates" is off (like in the snippet, I don't get the ManufacturerData/ServiceData updates (from below). I did some more digging - maybe you'll humor me some more 😉 I'll describe what I found and have some more questions if you don't mind. I've been looking at the messages I see in Basically, I get a bunch of I modified the My device evidently picks up on additional RSSI updates, but they don't seem to propagate to bluezero (or presumably pydbus, though I didn't try this as well). Finally, I re-read some of your earlier messages:
What did you mean by this? Are you referring here to MAC randomization as well? Because, that's not something I'd expect when my beacons aren't configured to do that (nor is it something I observed). Again, thanks in advance and please let me know if I could also help you in some way (e.g. some tasks for this project) 🙂 |
|
There seems to be something specific to your setup that I'm unable to reproduce at my end. Without being able to reproduce what you are seeing I am somewhat speculating as to what the issues are. I've updated the pydbus example to not remove beacons from the device list. This is to enable the ability to watch for the I've also added printing out of the RSSI value: import argparse
from gi.repository import GLib
from pydbus import SystemBus
import uuid
DEVICE_INTERFACE = 'org.bluez.Device1'
APPLE_MFG_ID = 0x004c
APPLE_BEACON_TYPE = 0x02
class Device:
def __init__(self, device_path):
self.device = bus.get('org.bluez', device_path)
def on_beacon_update(self, iface, changed, invalidated):
print("[CHG]", end=" ")
process_ibeacon(self.device.ManufacturerData[APPLE_MFG_ID], self.device.RSSI)
def stop_scan():
"""Stop device discovery and quit event loop"""
adapter.StopDiscovery()
mainloop.quit()
def clean_beacons(dongle, device_path):
"""
BlueZ D-Bus API does not show duplicates. This is a
workaround that removes devices that have been found
during discovery
"""
try:
dongle.RemoveDevice(device_path)
except GLib.Error as dbus_err:
if dbus_err.get_dbus_name() == 'org.bluez.Error.DoesNotExist':
print(f"Error: Device {device_path} not available to remove")
def process_ibeacon(data, rssi, beacon_type='iBeacon'):
"""Print iBeacon data in human-readable format"""
# print('DATA:', data)
beacon_uuid = uuid.UUID(bytes=bytes(data[2:18]))
major = int.from_bytes(bytearray(data[18:20]), 'big', signed=False)
minor = int.from_bytes(bytearray(data[20:22]), 'big', signed=False)
tx_pwr = int.from_bytes([data[22]], 'big', signed=True)
print(f'\t\t{beacon_type}: {beacon_uuid} - {major} - {minor} \u2197 {tx_pwr} \u2198 {rssi}')
def on_iface_added(owner, path, iface, signal, interfaces_and_properties):
"""
Event handler for D-Bus interface added.
Test to see if it is a new Bluetooth device
"""
iface_path, iface_props = interfaces_and_properties
if DEVICE_INTERFACE in iface_props:
on_device_found(iface_path, iface_props[DEVICE_INTERFACE])
def subscribe_to_device(device_path):
device = Device(device_path)
device.device.onPropertiesChanged = device.on_beacon_update
def on_device_found(device_path, device_props):
"""
Handle new Bluetooth device being discovered.
If it is a beacon of type iBeacon then process it
"""
manufacturer_data = device_props.get('ManufacturerData')
rssi = device_props.get('RSSI')
if manufacturer_data:
for mfg_id in manufacturer_data:
# iBeacon 0x004c
if mfg_id == APPLE_MFG_ID and manufacturer_data[mfg_id][0] == APPLE_BEACON_TYPE:
# print(device_path)
print("[NEW]", end=" ")
process_ibeacon(manufacturer_data[mfg_id], rssi)
# clean_beacons(adapter, device_path)
subscribe_to_device(device_path)
if __name__ == '__main__':
parser = argparse.ArgumentParser()
parser.add_argument('-d', '--duration', type=int, default=0,
help='Duration of scan [0 for continuous]')
args = parser.parse_args()
bus = SystemBus()
adapter = bus.get('org.bluez', '/org/bluez/hci0')
bus.subscribe(iface='org.freedesktop.DBus.ObjectManager',
signal='InterfacesAdded',
signal_fired=on_iface_added)
mainloop = GLib.MainLoop()
if args.duration > 0:
GLib.timeout_add_seconds(args.duration, stop_scan)
adapter.SetDiscoveryFilter({'DuplicateData': GLib.Variant.new_boolean(False)})
adapter.StartDiscovery()
try:
print('\n\tUse CTRL-C to stop discovery\n')
mainloop.run()
except KeyboardInterrupt:
stop_scan()which gave me the following output: Maybe you can give it a try and see if you get better output using the FYI: The reason that I get the |
Hi, I'd like to detect ibeacons with a raspi and ideally range with them. For testing, I'm using two identical beacons, but I'm encountering some issues. Maybe you can help me understand what I'm doing wrong 🙂
Maybe first off - ranging doesn't seem to be implemented here, is there some limitation or is it just a matter of time/priority?
Regardless, I thought I'd start with just reading out some rssi values, to at least get a broad feeling for beacon proximity: using
Scanner.start_beacon_scan(on_ibeacon=...)normally works, but I only get an initial callback invocation, presumably because it's only called on new devices. By the looks of it, that's whatScanner.clean_beaconsis intended for, so I'm calling that every 10s, expecting to get a new rssi every 10s. (The beacons are configured to advertise every 1s.)Now, my main issue is that I'm not consistently seeing the beacons. It seems they start disappearing (not re-appearing after cleaning) after running for a while. I verified that the same device still receives advertisements from the beacons (visible in
bluetoothctl devices) and I also see them on my smartphone with nRF connect. I'm not quite sure when/why the beacons disappear, but I'm seeing two errors in the logs.The first seems to be a race condition in the observer (an advertisement is received while determining devices to remove) - if you want I can submit a patch with some locking:
I "feel like" I've been getting that one more frequently a few days ago (but not so much anymore), so I had also experimented with
Scanner.stop_scanandadapter.quit.The other error still pops up frequently, though not regularly - sometimes it appears several times a few seconds apart, sometimes not for a while. Not sure if it's related to beacons not showing up, since it doesn't necessarily seem to correlate.
Thanks in advance!
The text was updated successfully, but these errors were encountered: