Closed JorgePe closed 2 years ago
This was with internal HCI (Dell Laptop) so added a USB dongle (CSR8510 A10) as hci1 and disabled hci0. Same. also restarted 'bluetoothd'
BT really never pairs:
Can you use Wireshark to capture the Bluetooth traffic while you do this? https://bleak.readthedocs.io/en/latest/troubleshooting.html#linux
will try... now I'm trying reboot because after some up/downs my device doesn't turn up (but I did reboot since Friday attempt with Technic Hub)
sudo hciconfig hci1 up
Can't init device hci1: Operation not possible due to RF-kill (132)
Also, be sure to remove the "Pybricks Hub" Bluetooth device before doing the capture. This will make sure we get to see everything.
Which hub is this?
Move Hub
Ubuntu 21.04?
Yes
I installed an Ubuntu 21.04 VM (VirtualBox) and could not reproduce the problem. In the logs, I see that something is reading the new PnP ID characteristic that we added in the v3.1.0a1 firmware. This is happening before Pybricks Code should be doing it, so I'm guessing there is something else on the OS doing it.
Have you changed any Bluetooth config or bluetoothd
command line options? Are there other apps running that might be using Bluetooth?
Can you confirm that pybricks.version
is ('movehub', '3.1.0a1', '3ab93ae on 2021-06-23')
?
this is (finally) my new laptop and have been trying not to brake anything as I soon found out that Teams could not share my desktop now (found today that it is Wayland's fault, login in with X fixes that) so the only thing I really changed was installing python 3.8 for pybricksdev to work
I confirm pybricks.version
perhaps something on bluez?
Old laptop works: Chrome 90.0.4430.72 kernel 5.4.0-72 bluetoothctl 5.53
doing 'apt upgrade' now to see if something brakes
just minor updates, still works... I will try a VM soon
VM with Ubuntu same kernel, same BlueZ, same Chrome with same flags... and it works. I'm clueless... but at least I can work now with devices using the new firmware.
sorry to insist... installed pybricksdev on the VM and now I cannot connect to the same Move Hub but not quite the same error:
I installed pip, pipx, poetry, pybricksdev and tried pybricksdev as a library with poetry, only big difference to my setup on physical laptop is I have not installed python 3.8
I see that error sometimes, usually right after flashing the firmware, but it always works when I try it again.
If the error is persistent, do a Wireshark capture, then remove the device from BlueZ and try again.
it worked.
bluetoothctl
devices
Device 00:16:53:AE:63:91 Pybricks Hub
remove 00:16:53:AE:63:91
I'm closing this issue, something very particular on my laptop configuration. Thanks for the help, might be useful for future issues.
I was finally able to reproduce this with a SPIKE Prime hub. chrome://device-log/
gives us some hints that this is a Chromium bug.
The recent addition of the PnP ID characteristic seems to trigger the Device Information Service and Pybricks service to be removed and added again for some reason. We can see that Chromium detects this but things there is something wrong with it (Remote GATT service does not belong to this device.
).
After some fiddling around, I am no longer able to reproduce the issue. I have a feeling that there is some sort of race condition between BlueZ and Chromium that triggers this problem. I don't think this made a difference, but I "Forget" the device at chrome://bluetooth-internals/#devices
. Also, using "Inspect" on that page, we can see that Chromium does indeed see the Device Information service (0000180a-0000-1000-8000-00805f9b34fb
).
Very interesting this "chrome://bluetooth-internals/#devices", since "hcitool lescan" no longer works I've been crazy trying to find my BLE ids in a simple way.
I "Forget" the device and it no longer shows up when Pybricks scans for hubs ("No compatible devices found"). But a scan with "chrome://bluetooth-internals/#devices" finds it, just doesn't find any service. After perhaps a dozen scans and Forgets and at least 2 power cycles of the hub... a new scan finds the services and Pybricks pairs with success:
So "Forget" does make a difference. And while having the "chrome://bluetooth..." open, I used "bluetoothctl" to remove the device from BlueZ and it disappear in "chrome://bluetooth" so probably doing the same dozen removes would have made the same?
Are you able to connect to Pybricks Code (beta) now since doing the "Forget" on the computer that has been having the problem?
Not really... the 'chorme://bluetooth...' connects but beta doesn't (nor code, by the way) It connects, blue light stays ON for a short while, then it disconnects:
[CHG] Controller 84:5C:F3:C6:8F:30 Discovering: yes
[NEW] Device 00:16:53:AE:63:91 Pybricks Hub
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 RSSI: -36
[CHG] Device 00:16:53:AE:63:91 TxPower is nil
[CHG] Device 00:16:53:AE:63:91 RSSI is nil
[CHG] Controller 84:5C:F3:C6:8F:30 Discovering: no
[CHG] Device 00:16:53:AE:63:91 Connected: yes
[CHG] Device 00:16:53:AE:63:91 Trusted: yes
[NEW] Primary Service (Handle 0x0bb5)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0001
00001801-0000-1000-8000-00805f9b34fb
Generic Attribute Profile
[NEW] Characteristic (Handle 0xbf04)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0001/char0002
00002a05-0000-1000-8000-00805f9b34fb
Service Changed
[NEW] Descriptor (Handle 0xfae4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0001/char0002/desc0004
00002902-0000-1000-8000-00805f9b34fb
Client Characteristic Configuration
[NEW] Secondary Service (Handle 0x0bb5)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service000c
0000180a-0000-1000-8000-00805f9b34fb
Device Information
[NEW] Characteristic (Handle 0x2114)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service000c/char000d
00002a26-0000-1000-8000-00805f9b34fb
Firmware Revision String
[NEW] Characteristic (Handle 0xebf4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service000c/char000f
00002a28-0000-1000-8000-00805f9b34fb
Software Revision String
[NEW] Characteristic (Handle 0x18e4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service000c/char0011
00002a50-0000-1000-8000-00805f9b34fb
PnP ID
[NEW] Secondary Service (Handle 0x0bb5)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0013
c5f50001-8280-46da-89f4-6d8051e4aeef
Vendor specific
[NEW] Characteristic (Handle 0xf9f4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0013/char0014
c5f50002-8280-46da-89f4-6d8051e4aeef
Vendor specific
[NEW] Descriptor (Handle 0x0e94)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0013/char0014/desc0016
00002902-0000-1000-8000-00805f9b34fb
Client Characteristic Configuration
[NEW] Primary Service (Handle 0x0bb5)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0017
6e400001-b5a3-f393-e0a9-e50e24dcca9e
Nordic UART Service
[NEW] Characteristic (Handle 0x0ae4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0017/char0018
6e400002-b5a3-f393-e0a9-e50e24dcca9e
Nordic UART TX
[NEW] Characteristic (Handle 0x7ce4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0017/char001a
6e400003-b5a3-f393-e0a9-e50e24dcca9e
Nordic UART RX
[NEW] Descriptor (Handle 0x30c4)
/org/bluez/hci0/dev_00_16_53_AE_63_91/service0017/char001a/desc001c
00002902-0000-1000-8000-00805f9b34fb
Client Characteristic Configuration
[CHG] Device 00:16:53:AE:63:91 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Device 00:16:53:AE:63:91 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Device 00:16:53:AE:63:91 UUIDs: 0000180a-0000-1000-8000-00805f9b34fb
[CHG] Device 00:16:53:AE:63:91 UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
[CHG] Device 00:16:53:AE:63:91 UUIDs: c5f50001-8280-46da-89f4-6d8051e4aeef
[CHG] Device 00:16:53:AE:63:91 ServicesResolved: yes
[CHG] Device 00:16:53:AE:63:91 Modalias: bluetooth:v0397p0040d0000
[CHG] Device 00:16:53:AE:63:91 ServicesResolved: no
[CHG] Device 00:16:53:AE:63:91 Connected: no
(this is from blutoothctl while trying with beta)
Me again... this Move Hub still problematic. With beta firmware or official firmware, I no longer can use it. Been trying some code with pybricksdev as library... then tried it with this hub (current official firmware through code.pybricks.com) and can connect to it but not transfer the micropython script:
music.py:
from pybricksdev.connections import BLEPUPConnection
from pybricksdev.connections import PybricksHub
from pybricksdev.ble import find_device
import asyncio
import subprocess
hub = BLEPUPConnection()
async def receiver(remote_hub):
while True:
if len(remote_hub.output) > 0:
line = remote_hub.output[-1]
remote_hub.output = []
value = line.decode()
subprocess.run(["xdotool", "search", "--name", """WD-1 DJ-TRAINER :: Online DJ GAME — Mozilla Firefox""", "key", value])
await asyncio.sleep(0.05)
async def main():
device = await find_device()
await hub.connect(device)
await asyncio.sleep(2)
await asyncio.gather(
hub.run('music/main.py', print_output=True),
receiver(hub)
)
if __name__ == "__main__":
hub = PybricksHub()
loop = asyncio.get_event_loop()
loop.run_until_complete(main())
poetry run python music.py
ERROR:root:A message handler raised an exception: This service is already present in this BleakGATTServiceCollection!.
Traceback (most recent call last):
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/dbus_next/message_bus.py", line 656, in _process_message
result = handler(msg)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/client.py", line 1047, in _parse_msg
self.services.add_service(BleakGATTServiceBlueZDBus(obj, path))
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/service.py", line 125, in add_service
raise BleakError(
bleak.exc.BleakError: This service is already present in this BleakGATTServiceCollection!
ERROR:root:A message handler raised an exception: This characteristic is already present in this BleakGATTServiceCollection!.
Traceback (most recent call last):
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/dbus_next/message_bus.py", line 656, in _process_message
result = handler(msg)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/client.py", line 1056, in _parse_msg
self.services.add_characteristic(
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/service.py", line 160, in add_characteristic
raise BleakError(
bleak.exc.BleakError: This characteristic is already present in this BleakGATTServiceCollection!
ERROR:root:A message handler raised an exception: This characteristic is already present in this BleakGATTServiceCollection!.
Traceback (most recent call last):
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/dbus_next/message_bus.py", line 656, in _process_message
result = handler(msg)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/client.py", line 1056, in _parse_msg
self.services.add_characteristic(
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/service.py", line 160, in add_characteristic
raise BleakError(
bleak.exc.BleakError: This characteristic is already present in this BleakGATTServiceCollection!
ERROR:root:A message handler raised an exception: This descriptor is already present in this BleakGATTServiceCollection!.
Traceback (most recent call last):
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/dbus_next/message_bus.py", line 656, in _process_message
result = handler(msg)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/client.py", line 1066, in _parse_msg
self.services.add_descriptor(
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/service.py", line 196, in add_descriptor
raise BleakError(
bleak.exc.BleakError: This descriptor is already present in this BleakGATTServiceCollection!
0%| | 0.00/267 [00:00<?, ?B/s]
Traceback (most recent call last):
File "music.py", line 31, in <module>
loop.run_until_complete(main())
File "/usr/local/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
return future.result()
File "music.py", line 23, in main
await asyncio.gather(
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/pybricksdev/connections.py", line 791, in run
await self.send_block(chunk)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/pybricksdev/connections.py", line 752, in send_block
await self.client.write_gatt_char(NUS_RX_UUID, bytearray(data), False)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/client.py", line 856, in write_gatt_char
assert_reply(reply)
File "/home/jxpereira/pybricksdev-demo/.venv/lib/python3.8/site-packages/bleak/backends/bluezdbus/utils.py", line 23, in assert_reply
raise BleakDBusError(reply.error_name, reply.body)
bleak.exc.BleakDBusError: [org.bluez.Error.Failed] Failed to initiate write
the same python script works fine with a City Hub.
and finally tried with a WIndows 10 VM instead of one with Ubuntu. Chrome connects at first attempt.
I don’t think Move Hub currently works with pybricksdev, which is a different issue. See https://github.com/pybricks/pybricksdev/issues/19, which also applies to at least some Linux systems even though the post says otherwise.
OK. But I wasn't concerned with the write failing... the "This descriptor is already present in this BleakGATTServiceCollection!" grabbed my attention (also because searching for it with Google gives very few matches, one of them in a Bleach issue where David asks for more details).
Also this is happening with Move Hub with two different firmwares (beta and non-beta). So probably isn't exactly the same issue I had when I opened it as it was happening with Move and Technic but only beta firmware... and now am not so sure if by that time I could use non-beta firmware with Move Hub... going to try older firmwares.
This is the same Move Hub seen by Chrome in Ubuntu and in Windows 10 VM after I flashed it with current firmware (used 'code.pybricks.com' on W10) - I can connect with Pybricks Code from W10, not from Ubuntu:
Same happens with a City Hub:
With this CityHub, I can not use pybricksdev script again until I remove it from BlueZ (I can use same script with another City Hub fine). And I cannot use it with Pybricks Code on Ubuntu, just on W10.
But now a stranger fact: both City Hubs have same firwmare at least according to REPL:
MicroPython 8845360 on 2021-06-08; Powered Up City Hub with STM32F030RC
I suspect the one that is giving me troubles was at least once used with 'beta.pybricks.com' and the other was always used with 'code.pybricks.com'. Move Hub was also used with 'beta.pybricks.com'. Is there something different on 'beta.pybricks.com' that touches the hubs BLE chipset in a way that one of the services gets only visible from Windows?
The screenshots look OK. BlueZ is hiding the GAP service (00001800-0000-1000-8000-00805f9b34fb), but it has always done this.
MicroPython 8845360 on 2021-06-08
Please update the firmware using beta.pybricks.com
.
Move Hub was also used with 'beta.pybricks.com'. Is there something different on 'beta.pybricks.com' that touches the hubs BLE chipset in a way that one of the services gets only visible from Windows?
The only difference is in the hub firmware. (Technically, the beta version is trying to read the PnP ID that the old version did not, but from what you are reporting, the connection is lost well before then.)
I updated both City Hubs with beta.pybricks.com The until-now-good-one is 90:84:2B:06:44:E0... can no long connect Chrome IDE on linux to it even after removing it from BlueZ. But can use my pybricksdev script. And can connect from Win10 VM.
MicroPython 3ab93ae on 2021-06-23; Powered Up City Hub with STM32F030RC
The other City Hub (already giving problems) is '90:84:2B:06:44:CE'. Same behavior.
Flashed the first one with LEGO firmware (Powered Up App 3.6.0). Reflashed it with "code.pybricks.com" (so back to MicroPython 8845360 on 2021-06-08
). Same behavior.
Flashed the second one also with "code.pybricks.com" (directly from beta) and same behavior.
Something chenged in BlueZ and/or Chrome for Linux and/or my laptop is completely crazy. Something that stores somewhere some property about the devices after being flashed to beta firmware and no longer forgets.
and same behavior with release 3.1.0a2... ...except that now I can use my pybricksdev script with Move Hub, thanks!
Should I close this issue again? I am the only one with this problem.
Although I can't reproduce it all of the time, I have been able to reproduce it, so let's keep the issue open.
not sure if this helps... got another Move Hub so never seen by BlueZ. Flashed directly with 3.1.0a2 with code.pybricks.com
and it works fine with the Pybricks IDE right at first attempt.
This is good because until now the only options I had for trying Move Hubs script was using Chrome on the Windows VM or (since yesterday) pybricksdev directly.
I finally got it!
in /var/lib/bluetooth/[hci]/
there is a cache of devices...
The bluetoothctl remove [device]
command should remove all entries here, right?
I removed one of my problematic hubs folder (90:84:2B:06:44:E0
) and also removed it from 'cache' folder.
And now "code.pybricks.com" works again on linux laptop.
So I repeat the procedure with the Move Hub:
bluetoothctl remove 00:16:53:AE:63:91
sudo rm "/var/lib/bluetooth/84:5C:F3:C6:8F:30/cache/00:16:53:AE:63:91"
and same with the other City Hub (90:84:2B:06:44:CE
)
All hubs working fine again. No need to restart bluetooth
service.
Nice find!
https://stackoverflow.com/questions/66039760/how-to-disable-bluez-cache suggests that we can disable the GATT cache. If it seems to make things better, we can start recommending it.
Yes. But what started this? It was working fine until I flashed with previous beta version... unfortunately I didn't backup the content of the cache file, it seems to store just the Name and the handlers for each attribute:
[General]
Name=Pybricks Hub
[Attributes]
0001=2800:0001:00001801-0000-1000-8000-00805f9b34fb
0002=2800:0008:00001800-0000-1000-8000-00805f9b34fb
0003=2803:0004:02:00002a00-0000-1000-8000-00805f9b34fb
0005=2803:0006:02:00002a01-0000-1000-8000-00805f9b34fb
0007=2803:0008:02:00002a04-0000-1000-8000-00805f9b34fb
0009=2800:000d:0000180a-0000-1000-8000-00805f9b34fb
000a=2803:000b:02:00002a26-0000-1000-8000-00805f9b34fb
000c=2803:000d:02:00002a28-0000-1000-8000-00805f9b34fb
000e=2800:0011:c5f50001-8280-46da-89f4-6d8051e4aeef
000f=2803:0010:1c:c5f50002-8280-46da-89f4-6d8051e4aeef
0011=00002902-0000-1000-8000-00805f9b34fb
0012=2800:0017:6e400001-b5a3-f393-e0a9-e50e24dcca9e
0013=2803:0014:04:6e400002-b5a3-f393-e0a9-e50e24dcca9e
0015=2803:0016:10:6e400003-b5a3-f393-e0a9-e50e24dcca9e
0017=00002902-0000-1000-8000-00805f9b34fb
some change on the attributes ID's or in the order of the handlers?
We added a new attributes for the PnP ID characteristic in v3.1.0a1 which shifted all of the attributes after it.
Also, if you switch back to the official LEGO firmware, it uses the same Bluetooth address and has different attributes.
I had some problems when I was beta testing SBrick because I was using just the handlers and a new firmware changed the order, like you said.
pybricksdev
kept working, it uses bleak
and most probably doesn't trust on the handlers like I did... could it be that Chrome Bluetooh backend uses just the handles?
Or does it have some relation to this other flag I have enabled?
I'm pretty sure Chrome just uses BlueZ D-Bus APIs like Bleak. However, I think there is a race condition that affects Chrome sometimes. Now that we know about the attribute caching, I have a theory that BlueZ was giving Chrome the cached attributes first then the new attributes later. If the timing was just right, Chrome would think that services or characteristics were missing because it was right between when BlueZ was removing the old ones and adding the new ones back.
I finally got around to reporting this upstream. It turns out there are quite a few different things that contribute to the issue.
[GATT] Cache = yes
in /etc/bluetooth/main.con
should be a viable workaround, but there is a bug in BlueZ related to UUIDs in advertising data that prevents devices from being discovered in Pybricks Code and pybricksdev.sudo rm
a cache file, which isn't great. A fix to make the remove command also delete this file as been submitted.So for users upgrading from v3.0 to v3.1 or greater, there isn't really anything we can do about this other than document the workaround (bluetoothctl remove ... && sudo rm ...
).
If we think that attributes may change again in a future release, we should implement the ServicesChanged or the Database Hash characteristic now (at a cost of 150-200B of flash memory) to avoid future issues with BlueZ. But if we think attributes will never change again after v3.1, then we can leave it as-is.
The official LEGO firmware has ServicesChanged attributes (checked move hub and city hub) but I don't know if it actually works (the city hub returns a bad value for the Characteristic Configuration descriptor, which isn't a good sign). If it does actually work, this might be the better option to be more compatible with the official LEGO firmware but is probably the most complicated to implement.
I think we can close this now since the issue is well understood to be BlueZ bugs and the workaround is documented at https://github.com/pybricks/support/discussions/270.
Beta firmware doesn't allow Chrome on Ubuntu to pair
"Connected to hub but failed to get Device Information service. Ensure that you are using the most recent firmware. If the problem persists, try removing the "Pybricks Hub" device in your OS Bluetooth settings, then try connecting again."
This happens with Technic Hub and Move Hub after installing firwmare that implements Remote Control Happens with "beta.pybricks.com" and also with "code.pybricks.com"
removed every 'Pybricks Hub' from my BT settings, turned BT off/on, Chrome close/open, hub off/on...
Using my Android phone I can use Chrome and pair with BT
Ubuntu 21.04 - kernel 5.11.0-22-generic bluetoothctl: 5.56 Chrome (Ubuntu): Version 91.0.4472.114 (Official Build) (64-bit)