Bluetooth related errors when testing with nrf52 dev board

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 on and then scan off
pair D6:E2:3F:1E:98:2D
connect 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 the nuimo_app isn'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, the bluetoothctl CLI shows abnormal behaviour, and fails to pair with 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 bluetoothctlCLI 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 --discover

gattctl --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

getsenic / gatt-python

Bluetooth related errors when testing with nrf52 dev board #17