Bluetooth related errors when testing with nrf52 dev board
kelada opened this issue · 7 comments
While testing the nrf52 dev board I found it to be inconsistent. The following logs are the most common errors which all appear to point back to the gatt-python/gatt/gatt_linux.py file.
The following exceptions are found the the nuimo_app.log file:
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 274, in _connect
self._object.Connect()
File "/usr/lib/python3.5/site-packages/dbus/proxies.py", line 145, in __call__
**keywords)
File "/usr/lib/python3.5/site-packages/dbus/connection.py", line 651, in call_blocking
message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.UnknownObject: Method "Connect" with signature "" on interface "org.bluez.Device1" doesn't exist
and
File "/usr/lib/python3.5/site-packages/nuimo/nuimo.py", line 135, in connect_failed
self.listener.connect_failed(error)
File "/home/root/senic-hub/senic_hub/nuimo_app/__init__.py", line 38, in connect_failed
self.controller.connect()
File "/usr/lib/python3.5/site-packages/nuimo/nuimo.py", line 130, in connect
super().connect()
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 269, in connect
self._connect()
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 279, in _connect
self.connect_failed(errors.Failed("Device does not exist, check adapter name and MAC address."))
The following exceptions are found the the senic_hub.log file:
2017-11-13 14:18:00,279 ERROR [waitress] Exception when serving /-/confnuimos
Traceback (most recent call last):
File "/usr/lib/python3.5/site-packages/waitress/channel.py", line 338, in service
task.service()
File "/usr/lib/python3.5/site-packages/waitress/task.py", line 169, in service
self.execute()
File "/usr/lib/python3.5/site-packages/waitress/task.py", line 399, in execute
app_iter = self.channel.server.application(env, start_response)
File "/usr/lib/python3.5/site-packages/raven/middleware.py", line 98, in __call__
iterable = self.application(environ, start_response)
File "/usr/lib/python3.5/site-packages/pyramid/router.py", line 236, in __call__
response = self.invoke_subrequest(request, use_tweens=True)
File "/usr/lib/python3.5/site-packages/pyramid/router.py", line 211, in invoke_subrequest
response = handle_request(request)
File "/usr/lib/python3.5/site-packages/pyramid/tweens.py", line 51, in excview_tween
request_iface=request_iface.combined
File "/usr/lib/python3.5/site-packages/pyramid/view.py", line 547, in _call_view
response = view_callable(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/viewderivers.py", line 413, in viewresult_to_response
result = view(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/tweens.py", line 22, in excview_tween
response = handler(request)
File "/usr/lib/python3.5/site-packages/pyramid/router.py", line 158, in handle_request
view_name
File "/usr/lib/python3.5/site-packages/pyramid/view.py", line 547, in _call_view
response = view_callable(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/config/views.py", line 182, in __call__
return view(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/viewderivers.py", line 393, in attr_view
return view(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/viewderivers.py", line 371, in predicate_wrapper
return view(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/viewderivers.py", line 442, in rendered_view
result = view(context, request)
File "/usr/lib/python3.5/site-packages/pyramid/viewderivers.py", line 147, in _requestonly_view
response = view(request)
File "/usr/lib/python3.5/site-packages/cornice/service.py", line 493, in wrapper
response = view_(request)
File "/home/root/senic-hub/senic_hub/backend/views/nuimos.py", line 102, in get_configured_nuimos
config['nuimos'][mac_address]['is_connected'] = controller.is_connected()
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 342, in is_connected
return self._properties.Get('org.bluez.Device1', 'Connected') == 1
File "/usr/lib/python3.5/site-packages/dbus/proxies.py", line 70, in __call__
return self._proxy_method(*args, **keywords)
File "/usr/lib/python3.5/site-packages/dbus/proxies.py", line 145, in __call__
**keywords)
File "/usr/lib/python3.5/site-packages/dbus/connection.py", line 651, in call_blocking
message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.UnknownObject: Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist
UPDATE 1 [1400H:17/11/17]: [BT Device : Nordic]
While attempting to manually add a Nuimo using the bluetoothctl CLI, I executed the following, in order:
scan onand thenscan offpair D6:E2:3F:1E:98:2Dconnect D6:E2:3F:1E:98:2D
When the hub is freshly booted and the above commands are executed, the Nuimo is successfully connected to the Hub. However, since thenuimo_appisn't used to connect to the Nuimo, the Nuimo can't be used to control anything.
However, if the Senic Hub Mobile Application is being used to find Nuimos, thebluetoothctlCLI shows abnormal behaviour, and fails topairwith the Nuimo or any other BT device.
These findings crate my opinion that there may not be any problem with BlueZ (because connecting & pairing works fine when the Senic Hub Application & it's libraries don't interfere, but breaks as soon as the Senic Hub backend makes an attempt to connect to Nuimo)
Also, the bluetoothctl CLI responses show that the BT controller is power offed everytime you tap on the COMPLETE SETUP button on the frontend, and thus forgets all the Nuimos(& other devices it was connected to). This can be verified by using devicescommand in the CLI, and not finding any devices in the list. Repeating the above 3 bulleted steps will again allow you to add the nuimo using CLI
UPDATE 2 [1500H:17/11/17]: [BT Device : Nordic]
Executing power off and power on refreshes the controller & nuimo can again be connected after scan on/off & connect ---. However, the controller or the SH backend is unable to read characteristics.
The errors mentioned above cease to spawn, but the battery level is shown 0%, and gestures aren't received by the nuimo_app (process)
Using gattctl to connect, using :
gattctl --discovergattctl --connect D6:E2:3F:1E:98:2D
throws the following exception:
ERROR:dbus.connection:Exception in handler for D-Bus signal:
Traceback (most recent call last):
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 357, in alias
return self._properties.Get('org.bluez.Device1', 'Alias')
File "/usr/lib/python3.5/site-packages/dbus/proxies.py", line 145, in __call__
**keywords)
File "/usr/lib/python3.5/site-packages/dbus/connection.py", line 651, in call_blocking
message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoReply: Message recipient disconnected from message bus without replying
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/lib/python3.5/site-packages/dbus/connection.py", line 230, in maybe_handle_message
self._handler(*args, **kwargs)
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 167, in _properties_changed
self._device_discovered(path, [interface])
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 177, in _device_discovered
self.device_discovered(device)
File "/usr/lib/python3.5/site-packages/gattctl.py", line 16, in device_discovered
print("[%s] Discovered, alias = %s" % (device.mac_address, device.alias()))
File "/usr/lib/python3.5/site-packages/gatt/gatt_linux.py", line 365, in alias
raise _error_from_dbus_error(e)
gatt.errors.Failed: Message recipient disconnected from message bus without replying
[D6:E2:3F:1E:98:2D] Disconnected
UPDATE 3 [1500H:20/11/17]: [BT Device :EM9304Board]
It was observed using the bluetoothctl CLI command info D6:8B:03:4E:D4:23, and comparing between the expected results & obtained results, that all the services of BLE devices are incompletely obtained by the NEW BT module, while the BT dongle can help successfully read all the services.
Expected Result :
[bluetooth]# info F5:D4:41:9C:86:B0
Device F5:D4:41:9C:86:B0
Name: Nuimo
Alias: Nuimo
Appearance: 0x0180
Paired: no
Trusted: no
Blocked: no
Connected: no
LegacyPairing: no
UUID: Generic Access Profile (00001800-0000-1000-8000-00805f9b34fb)
UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
UUID: Device Information (0000180a-0000-1000-8000-00805f9b34fb)
UUID: Battery Service (0000180f-0000-1000-8000-00805f9b34fb)
UUID: Vendor specific (f29b1523-cb19-40f3-be5c-7241ecb82fd1)
UUID: Vendor specific (f29b1525-cb19-40f3-be5c-7241ecb82fd2)
Result from new bt module:
[bluetooth]# info F5:D4:41:9C:86:B0
Device F5:D4:41:9C:86:B0
Name: Nuimo
Alias: Nuimo
Appearance: 0x0180
Paired: 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)
NOTE: The Nordic board can detect all service UUIDs properly. However, it's still incompatible with the Senic Hub code.
[UPDATE 4, 21-11-17][11:38PM] [EM Board]
The EM board isn't connecting to the Nuimo at all. It isn't reading all characteristic values properly.
Following error pops up in "/var/log/messages" while debugging bluetooth errors :
-------------------------------------------------------------------------------------------------------------------------------------------------------
Nov 21 10:38:08 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/device.c:btd_device_set_temporary() temporary 0
Nov 21 10:38:08 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/device.c:device_connect_le() Connection attempt to: F5:D4:41:9C:86:B0
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/adapter.c:connected_callback() hci0 device F5:D4:41:9C:86:B0 connected eir_len 20
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/adapter.c:dev_disconnected() Device F5:D4:41:9C:86:B0 disconnected, reason 1
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/adapter.c:adapter_remove_connection()
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/plugins/policy.c:disconnect_cb() reason 1
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/adapter.c:bonding_attempt_complete() hci0 bdaddr F5:D4:41:9C:86:B0 type 2 status 0xe
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/device.c:device_bonding_failed() status 14
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/adapter.c:resume_discovery()
Nov 21 10:38:11 senic-hub daemon.debug bluetoothd[205]: ../bluez-5.44/src/device.c:att_connect_cb() connect error: Connection timed out (110)
-------------------------------------------------------------------------------------------------------------------------------------------------------
This log is less than needed to realise the actual error.
RFKILL ===
On using the command "rfkill list", this is the output obtained :
-------------------------------
skynet@skynet:~$ rfkill list
0: phy0: Wireless LAN
Soft blocked: no
Hard blocked: no
1: hci0: Bluetooth
Soft blocked: no
Hard blocked: no
2: hci1: Bluetooth
Soft blocked: yes
Hard blocked: no
-------------------------------
HCICONFIG ===
On connecting the EM board via serial to my laptop, and running bluetootctl, I cannot see the controller at all. On running hciconfig, I get:
--------------------------------------------------------------------
root@skynet:/home/skynet# hciconfig
hci1: Type: BR/EDR Bus: UART
BD Address: 0C:F3:EE:00:00:00 ACL MTU: 27:4 SCO MTU: 0:0
UP RUNNING
RX bytes:477 acl:0 sco:0 events:33 errors:0
TX bytes:184 acl:0 sco:0 commands:34 errors:0
hci0: Type: BR/EDR Bus: USB
BD Address: 7C:B0:C2:8C:5C:02 ACL MTU: 1021:5 SCO MTU: 96:6
UP RUNNING PSCAN ISCAN
RX bytes:2343 acl:0 sco:0 events:257 errors:0
TX bytes:41322 acl:0 sco:0 commands:256 errors:0
--------------------------------------------------------------------
and running hciconfig hci1 pscan shows the error : Can't set scan mode on hci1: Operation not supported (95)
[UPDATE 5, 23-11-17][11:38PM] [NRF52]
Some good news! With some fixes in the Zephyr code, the BT Module can be made to connect to more than one devices simultaneously. Following are the mods that got it working for me:
- Add in
..zephyr/samples/bluetooth/hci_uart/nrf5.conf:
CONFIG_BT=y
CONFIG_BT_HCI_RAW=y
CONFIG_BT_MAX_CONN=16
CONFIG_BT_MAX_PAIRED=16
- Note that the above specs should be exactly in the same order as above. Might not work if you shuffle them.
- To be double sure, add the above configs to
..zephyr/samples/bluetooth/hci_uart/generic.conf
Now, generate the HEX and flash the board.
Power off the NanoPi, connect the board and boot. If you see a change in the mac address of the bt board, it has been flashed with the changes.
Now using bluetoothctl CLI, connect to one Nuimo, and wait for a few seconds. Now while the Nuimo is connected, perform:
[Nuimo]# connect <another_nuimo_mac_addr> .
This should give you a positive connection message. This means that both Nuimos have been successfully paired.
Note: The DBUS communication is not always perfect when using this board, so it might connect to two Nuimos and then not connect to anymore.
Note: Reconnection of disconnected Nuimos is still not fixed. That has to be fixed from the Senic Hub application stack.
Not actual any more. Closing
DBUS BLE exception while bluetooth pairing
Exception in thread Thread-12:
Traceback (most recent call last):
File "/home/root/obd/obd_gen2_ble_py/blemodule/adapter.py", line 146, in powered
self.adapter_props.Set(constants.ADAPTER_INTERFACE, 'Powered',
File "/usr/lib/python3.8/site-packages/dbus/proxies.py", line 141, in call
return self._connection.call_blocking(self._named_service,
File "/usr/lib/python3.8/site-packages/dbus/connection.py", line 652, in call_blocking
reply_message = self.send_message_with_reply_and_block(
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.1 was not provided by any .service files