ValueError: Cannot find a device when running cpu_temperature.py example

[hubert3]

Running the cpu_temperature.py example, as soon as a client connects to the peripheral being advertised I get this exception (addresses obscured):

# python3 cpu_temperature.py
CPU temperature is 42.0C
b'h\x10'
Advertisement registered
ERROR:dbus.connection:Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/dbus/connection.py", line 230, in maybe_handle_message
    self._handler(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/bluezero-0.3.0-py3.7.egg/bluezero/adapter.py", line 267, in _properties_changed
    device_addr=macaddr)
  File "/usr/local/lib/python3.7/dist-packages/bluezero-0.3.0-py3.7.egg/bluezero/device.py", line 56, in __init__
    " using adapter: " + adapter_addr)
ValueError: Cannot find a device: xx:xx:xx:xx:xx:xx using adapter: xx:xx:xx:xx:xx:xx

Platform is a RPi4 running Raspbian GNU/Linux 10 Kernel Linux raspberrypi 4.19.97-v7l+ bluez package version 5.50-1.2~deb10u1+rpt1 Python 3.7.3

[ukBaz]

Hmmm?

I don't have a RPi 4 but I have a fairly similar setup to you:

(venv) pi@raspberrypi:~ $ python -V
Python 3.7.3
(venv) pi@raspberrypi:~ $ bluetoothctl -v
bluetoothctl: 5.50
(venv) pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.19.97-v7+ #1294 SMP Thu Jan 30 13:15:58 GMT 2020 armv7l GNU/Linux

I have just run this on my system and have not been able to reproduce your issues.

I have used the nRF Connect app on an Android phone. What are you using as a client?

If there is nothing obvious with your client (or I can't reproduce it with a similar client) then we will need to look to see if we can get more debug information from one of these: https://bluezero.readthedocs.io/en/latest/system_setup.html?highlight=debug#notes-for-getting-debug-information

[ukBaz]

There is a BLE client built into recent versions of the Chrome brower (chrome://bluetooth-internals) and this has worked from my desktop machine also:

[ukBaz]

As there is not enough information to reproduce this I am close. If there is more information then please let me know and I will reopen.

[arslan437]

Device advertise correctly but I not able to connect to it I have tested it with uart and temperature example but non of them work. bluetoothclt -v = 5.50 raspberry pi 4

setup ad_manager
setup service_manager
Advertising service  6E400001-B5A3-F393-E0A9-E50E24DCCA9E
Register Advert /ukBaz/bluezero/advertisement3038813648
Register Application  /ukBaz/bluezero/application3038813392
GetManagedObjects
GATT application registered
Advertisement registered
ERROR:dbus.connection:Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/dbus/connection.py", line 230, in maybe_h                                                                                                             andle_message
    self._handler(*args, **kwargs)
  File "/home/pi/.local/lib/python3.7/site-packages/bluezero/adapter.py", line 2                                                                                                             67, in _properties_changed
    device_addr=macaddr)
  File "/home/pi/.local/lib/python3.7/site-packages/bluezero/device.py", line 56                                                                                                             , in __init__
    " using adapter: " + adapter_addr)
ValueError: Cannot find a device: 45:10:69:42:BA:C0 using adapter: DC:A6:32:4B:9                                                                                                             F:57
^CClosing Mainloop

Dbus data

signal time=1604738844.264717 sender=:1.2 -> destination=(null destination) serial=813 pat                                                                                                   h=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dsoc_2dfe201000_2eserial_2dtty_                                                                                                   2dttyAMA0_2dhci0_2dhci0_3a64_2edevice; interface=org.freedesktop.DBus.Properties; member=P                                                                                                   ropertiesChanged
   string "org.freedesktop.systemd1.Unit"
   array [
      dict entry(
         string "ActiveState"
         variant             string "inactive"
      )
      dict entry(
         string "SubState"
         variant             string "dead"
      )
      dict entry(
         string "StateChangeTimestamp"
         variant             uint64 1604738844262414
      )
      dict entry(
         string "StateChangeTimestampMonotonic"
         variant             uint64 2436603947
      )
      dict entry(
         string "InactiveExitTimestamp"
         variant             uint64 1604738838553032
      )
      dict entry(
         string "InactiveExitTimestampMonotonic"
         variant             uint64 2430894564
      )
      dict entry(
         string "ActiveEnterTimestamp"
         variant             uint64 1604738838553032
      )
      dict entry(
         string "ActiveEnterTimestampMonotonic"
         variant             uint64 2430894564
      )
      dict entry(
         string "ActiveExitTimestamp"
         variant             uint64 1604738844262414
      )
      dict entry(
         string "ActiveExitTimestampMonotonic"
         variant             uint64 2436603947
      )
      dict entry(
         string "InactiveEnterTimestamp"
         variant             uint64 1604738844262414
      )
      dict entry(
         string "InactiveEnterTimestampMonotonic"
         variant             uint64 2436603947
      )
      dict entry(
         string "Job"
         variant             struct {
               uint32 0
               object path "/"
            }
      )
      dict entry(
         string "ConditionResult"
         variant             boolean false
      )
      dict entry(
         string "AssertResult"
         variant             boolean false
      )
      dict entry(
         string "ConditionTimestamp"
         variant             uint64 0
      )
      dict entry(
         string "ConditionTimestampMonotonic"
         variant             uint64 0
      )
      dict entry(
         string "AssertTimestamp"
         variant             uint64 0
      )
      dict entry(
         string "AssertTimestampMonotonic"
         variant             uint64 0
      )
      dict entry(
         string "InvocationID"
         variant             array of bytes [
               4b 09 5d 11 15 b7 49 7d 8a 8c 53 35 d7 1c dc 4e
            ]
      )
   ]
   array [
      string "Conditions"
      string "Asserts"
   ]
signal time=1604738844.265571 sender=:1.2 -> destination=(null destination) serial=814 pat                                                                                                   h=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=UnitRemove                                                                                                   d
   string "sys-devices-platform-soc-fe201000.serial-tty-ttyAMA0-hci0-hci0:64.device"
   object path "/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dsoc_2dfe201000_2                                                                                                   eserial_2dtty_2dttyAMA0_2dhci0_2dhci0_3a64_2edevice"

Bluetooth -nEd results

bluetoothd[1455]: Bluetooth daemon 5.50
bluetoothd[1455]: src/main.c:parse_config() parsing /etc/bluetooth/main.conf
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “DiscoverableTimeou                                                                                                   t” in group “General”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “PairableTimeout” i                                                                                                   n group “General”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “Privacy” in group                                                                                                    “General”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “Name” in group “Ge                                                                                                   neral”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “Class” in group “G                                                                                                   eneral”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “DeviceID” in group                                                                                                    “General”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “ReverseServiceDisc                                                                                                   overy” in group “General”
bluetoothd[1455]: src/main.c:parse_config() Key file does not have key “MinEncKeySize” in                                                                                                    group “GATT”
D-Bus setup failed: Name already in use
bluetoothd[1455]: Unable to get on D-Bus

[ukBaz]

Thank you for posting more debug information. The only piece of information that looks interesting is:

D-Bus setup failed: Name already in use bluetoothd[1455]: Unable to get on D-Bus

Did you do sudo service bluetooth stop before you did bluetoothd -nEd?

I have just re-ran the CPU example and have been able to connect and read data.

There have been some issues with versions of the bluez-firmware on Raspberry Pi recently. Can you check you are up-to-date with the various packages. This is what I currently have on my system:

pi@raspberrypi:~ $ dpkg -l | grep bluez
ii  bluez                                5.50-1.2~deb10u1+rpt2               armhf        Bluetooth tools and daemons
ii  bluez-firmware                       1.2-4+rpt6                          all          Firmware for Bluetooth devices

[arslan437]

Yes I did stop the bluetooth basically I followed this link https://bluezero.readthedocs.io/en/stable/system_setup.html#notes-for-getting-debug-information

pi@raspberrypi:~ $ sudo service bluetooth start
pi@raspberrypi:~ $ bluetoothd -nEd
bluetoothd[2181]: Bluetooth daemon 5.50
bluetoothd[2181]: src/main.c:parse_config() parsing /etc/bluetooth/main.conf
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “DiscoverableTimeout” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “PairableTimeout” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “Privacy” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “Name” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “Class” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “DeviceID” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “ReverseServiceDiscovery” in group “General”
bluetoothd[2181]: src/main.c:parse_config() Key file does not have key “MinEncKeySize” in group “GATT”
D-Bus setup failed: Connection ":1.174" is not allowed to own the service "org.bluez" due to security policies in the configuration file
bluetoothd[2181]: Unable to get on D-Bus

Packages that I have on my pi

pi@raspberrypi:~ $ dpkg -l | grep bluez
ii  bluez                                 5.50-1.2~deb10u1+rpt2                  armhf        Bluetooth tools and daemons
ii  bluez-firmware                        1.2-4+rpt6                             all          Firmware for Bluetooth devices

[arslan437]

here is the some of the data from the bluetoothclt with uart example running

[CHG] Controller DC:A6:32:4B:9F:57 SupportedInstances: 0x03
[CHG] Controller DC:A6:32:4B:9F:57 ActiveInstances: 0x02
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000ffff-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 SupportedInstances: 0x04
[CHG] Controller DC:A6:32:4B:9F:57 ActiveInstances: 0x01
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000ffff-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000ffff-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000ffff-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 SupportedInstances: 0x03
[CHG] Controller DC:A6:32:4B:9F:57 ActiveInstances: 0x02
[NEW] Device 48:93:56:CE:08:F2 48-93-56-CE-08-F2
[CHG] Device 48:93:56:CE:08:F2 Connected: no
[DEL] Device 48:93:56:CE:08:F2 48-93-56-CE-08-F2

[ukBaz]

The transcript above shows you using start not stop. There cannot be two bluetoothd daemons running so that is why it gives the error with that command which is probably unrelated to your connection issue.

Your packages look up to date (or at least the same as what I have). We need to find out what is different between our two environments.

I am confused by your bluetoothctl transcript. Where are those UUID's coming from? For example: 0000ffff-0000-1000-8000-00805f9b34fb. Maybe we need to step back a bit. My assumption was that you were trying to create a BLE peripheral on the RPi and connect to it from another device. e.g. your phone. Is that correct?

I have just ran both the ble_uart.py and cpu_temperature.py example successfull. Are you running these examples unmodified?

Have you changed the D-Bus permissions?

We need is to identify what is different on your system than mine so that I can reproduce the error or correct your system. Can you do a bluetoothctl show and share.

Also, try having sudo btmon running in a different terminal to see if anything useful is reported in there when the failure happens.

[arslan437]

0000ffff-0000-1000-8000-00805f9b34fb ignore this I added this uuid to adervertisement using bluetoothclt.

yes, I am running these examples unmodified.

yes, I have copied the file to system.d as documentation (I have waste couple of hour on that already).

Now I got the uart example working perfectly but here what I did so it started working bluetoothctl -> menu advertise -> service 6E400001-B5A3-F393-E0A9-E50E24DCCA9E 0x45 0x45

pi@raspberrypi:~/tcodes $ bluetoothctl
Agent registered
[bluetooth]# menu advertise
Menu advertise:
Available commands:
-------------------
uuids [uuid1 uuid2 ...]                           Set/Get advertise uuids
service [uuid] [data=xx xx ...]                   Set/Get advertise service data
manufacturer [id] [data=xx xx ...]                Set/Get advertise manufacturer data
data [type] [data=xx xx ...]                      Set/Get advertise data
discoverable [on/off]                             Set/Get advertise discoverable
discoverable-timeout [seconds]                    Set/Get advertise discoverable timeout
tx-power [on/off]                                 Show/Enable/Disable TX power to be advertised
name [on/off/name]                                Configure local name to be advertised
appearance [on/off/value]                         Configure custom appearance to be advertised
duration [seconds]                                Set/Get advertise duration
timeout [seconds]                                 Set/Get advertise timeout
clear [uuids/service/manufacturer/config-name...] Clear advertise config
back                                              Return to main menu
version                                           Display version
quit                                              Quit program
exit                                              Quit program
help                                              Display help about this program
export                                            Print evironment variables
[bluetooth]# service 6E400001-B5A3-F393-E0A9-E50E24DCCA9E 0x45 0x45
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 UUIDs: 0000112d-0000-1000-8000-00805f9b34fb
[CHG] Controller DC:A6:32:4B:9F:57 SupportedInstances: 0x04
[CHG] Controller DC:A6:32:4B:9F:57 ActiveInstances: 0x01
[NEW] Device 6C:AF:4B:99:95:EB 6C-AF-4B-99-95-EB
[NEW] Primary Service
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0001
        00001801-0000-1000-8000-00805f9b34fb
        Generic Attribute Profile
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0001/char0002
        00002a05-0000-1000-8000-00805f9b34fb
        Service Changed
[NEW] Primary Service
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028
        0000fe35-0000-1000-8000-00805f9b34fb
        HUAWEI Technologies Co., Ltd
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char0029
        00002a00-0000-1000-8000-00805f9b34fb
        Device Name
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char002b
        00002a01-0000-1000-8000-00805f9b34fb
        Appearance
[NEW] Descriptor
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char002b/desc002d
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char002e
        00002a02-0000-1000-8000-00805f9b34fb
        Peripheral Privacy Flag
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char0030
        00002a03-0000-1000-8000-00805f9b34fb
        Reconnection Address
[NEW] Descriptor
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0028/char0030/desc0032
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[NEW] Primary Service
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0033
        0000046a-0000-1000-8000-00805f9b34fb
        Unknown
[NEW] Characteristic
        /org/bluez/hci0/dev_6C_AF_4B_99_95_EB/service0033/char0034
        0000046c-0000-1000-8000-00805f9b34fb
        Unknown
[CHG] Device 6C:AF:4B:99:95:EB UUIDs: 0000046a-0000-1000-8000-00805f9b34fb
[CHG] Device 6C:AF:4B:99:95:EB UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[CHG] Device 6C:AF:4B:99:95:EB UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[CHG] Device 6C:AF:4B:99:95:EB UUIDs: 0000fe35-0000-1000-8000-00805f9b34fb
[CHG] Device 6C:AF:4B:99:95:EB ServicesResolved: yes
[CHG] Device 6C:AF:4B:99:95:EB Name: HUAWEI Mate 10 lite
[CHG] Device 6C:AF:4B:99:95:EB Alias: HUAWEI Mate 10 lite

After that in a separate terminal, I run the uart example and it worked perfectly.

I hope will be able to figure out whats wrong now

when everything is working bluetoothctl show results

[6C-AF-4B-99-95-EB]# show
Controller DC:A6:32:4B:9F:57 (public)
        Name: raspberrypi
        Alias: RPi_UART
        Class: 0x00400000
        Powered: yes
        Discoverable: no
        Pairable: no
        UUID: Nordic UART Service       (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
        UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control        (0000110e-0000-1000-8000-00805f9b34fb)
        UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
        UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
        UUID: SIM Access                (0000112d-0000-1000-8000-00805f9b34fb)
        Modalias: usb:v1D6Bp0246d0532
        Discovering: no
[6C-AF-4B-99-95-EB]#

when I exit out of Bluetoothctl, stop the uart example than run the uart example again

pi@raspberrypi:~/tcodes $ bluetoothctl show
Controller DC:A6:32:4B:9F:57 (public)
        Name: raspberrypi
        Alias: RPi_UART
        Class: 0x00400000
        Powered: yes
        Discoverable: no
        Pairable: no
        UUID: Nordic UART Service       (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
        UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control        (0000110e-0000-1000-8000-00805f9b34fb)
        UUID: PnP Information           (00001200-0000-1000-8000-00805f9b34fb)
        UUID: A/V Remote Control Target (0000110c-0000-1000-8000-00805f9b34fb)
        UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
        UUID: SIM Access                (0000112d-0000-1000-8000-00805f9b34fb)
        Modalias: usb:v1D6Bp0246d0532
        Discovering: no

journalctl

pi@raspberrypi:~/tcodes $ journalctl -u bluetooth -f
-- Logs begin at Fri 2020-11-06 22:06:38 HST. --
Nov 07 01:56:30 raspberrypi bluetoothd[1362]: No cache for 79:19:0E:24:37:CC
Nov 07 02:40:00 raspberrypi bluetoothd[1362]: No cache for 48:93:56:CE:08:F2
Nov 07 02:45:06 raspberrypi bluetoothd[1362]: No cache for 48:93:56:CE:08:F2
Nov 07 02:58:52 raspberrypi bluetoothd[1362]: No cache for 6D:A0:58:73:38:47
Nov 07 03:22:45 raspberrypi bluetoothd[1362]: No cache for 54:B4:DD:67:2F:18
Nov 07 03:26:22 raspberrypi bluetoothd[1362]: No cache for 54:B4:DD:67:2F:18
Nov 07 03:31:42 raspberrypi bluetoothd[1362]: No cache for 61:25:43:76:AA:5E
Nov 07 03:37:17 raspberrypi bluetoothd[1362]: No cache for 61:25:43:76:AA:5E
Nov 07 03:47:41 raspberrypi bluetoothd[1362]: No cache for 71:79:65:B2:A4:5F
Nov 07 03:49:44 raspberrypi bluetoothd[1362]: No cache for 71:79:65:B2:A4:5F
Nov 07 03:57:28 raspberrypi bluetoothd[1362]: No cache for 71:79:65:B2:A4:5F
Nov 07 03:57:46 raspberrypi bluetoothd[1362]: No cache for 71:79:65:B2:A4:5F
Nov 07 04:03:35 raspberrypi bluetoothd[1362]: No cache for 6C:AF:4B:99:95:EB

sudo btmon results

pi@raspberrypi:~/tcodes $ sudo btmon
Bluetooth monitor ver 5.50
= Note: Linux version 5.4.72-v7l+ (armv7l)                                          0.730426
= Note: Bluetooth subsystem version 2.22                                            0.730436
= New Index: DC:A6:32:4B:9F:57 (Primary,UART,hci0)                           [hci0] 0.730442
= Open Index: DC:A6:32:4B:9F:57                                              [hci0] 0.730448
= Index Info: DC:A6:32:4B:9F:57 (Cypress Semiconductor Corporation)          [hci0] 0.730453
@ MGMT Open: bluetoothd (privileged) version 1.14                          {0x0001} 0.730458
@ MGMT Open: btmon (privileged) version 1.14                               {0x0002} 0.730984
@ MGMT Command: Add UUID (0x0010) plen 17                           {0x0001} [hci0] 7.604993
        UUID: 6e400001-b5a3-f393-e0a9-e50e24dcca9e
        Service class: 0x00
< HCI Command: Write Extended Inquiry Response (0x03|0x0052) plen 241     #1 [hci0] 7.605031
        FEC: Not required (0x00)
        Name (complete): RPi_UART
        TX power: 0 dBm
        Device ID: USB Implementer's Forum assigned (0x0002)
          Vendor: Linux Foundation (0x1d6b)
          Product: 0x0246
          Version: 5.3.2 (0x0532)
        16-bit Service UUIDs (complete): 3 entries
          A/V Remote Control (0x110e)
          A/V Remote Control Target (0x110c)
          SIM Access (0x112d)
        128-bit Service UUIDs (complete): 1 entry
          Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
> HCI Event: Command Complete (0x0e) plen 4                               #2 [hci0] 7.606184
      Write Extended Inquiry Response (0x03|0x0052) ncmd 1
        Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 6                      {0x0001} [hci0] 7.606221
      Add UUID (0x0010) plen 3
        Status: Success (0x00)
        Class: 0x400000
          Major class: Miscellaneous
          Minor class: 0x00
          Telephony (Cordless telephony, Modem, Headset)
@ MGMT Command: Add Advertising (0x003e) plen 29                    {0x0001} [hci0] 7.606555
        Instance: 1
        Flags: 0x00000001
          Switch into Connectable mode
        Duration: 0
        Timeout: 0
        Advertising data length: 18
        128-bit Service UUIDs (complete): 1 entry
          Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
        Scan response length: 0
@ MGMT Event: Advertising Added (0x0023) plen 1                     {0x0002} [hci0] 7.606569
        Instance: 1
< HCI Command: LE Set Advertising Parameters (0x08|0x0006) plen 15        #3 [hci0] 7.606601
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                               #4 [hci0] 7.606896
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1               #5 [hci0] 7.606927
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                               #6 [hci0] 7.607311
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4                      {0x0001} [hci0] 7.607339
      Add Advertising (0x003e) plen 1
        Status: Success (0x00)
        Instance: 1
> HCI Event: LE Meta Event (0x3e) plen 19                                #7 [hci0] 30.679511
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 64
        Role: Slave (0x01)
        Peer address type: Random (0x01)
        Peer address: 4E:E4:C0:F5:D2:DB (Resolvable)
        Connection interval: 50.00 msec (0x0028)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
        Master clock accuracy: 0x01
@ MGMT Event: Device Connected (0x000b) plen 13                    {0x0002} [hci0] 30.679547
        LE Address: 4E:E4:C0:F5:D2:DB (Resolvable)
        Flags: 0x00000000
        Data length: 0
@ MGMT Event: Device Connected (0x000b) plen 13                    {0x0001} [hci0] 30.679547
        LE Address: 4E:E4:C0:F5:D2:DB (Resolvable)
        Flags: 0x00000000
        Data length: 0
> HCI Event: Vendor (0xff) plen 5                                        #8 [hci0] 30.679560
        55 00 00 40 00                                   U..@.
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2         #9 [hci0] 30.679679
        Handle: 64
> HCI Event: Command Status (0x0f) plen 4                               #10 [hci0] 30.680455
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 14                            #11 [hci0] 30.680460
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
        00 00 00 00 00 00 00 00 00 00                    ..........
> HCI Event: LE Meta Event (0x3e) plen 12                               #12 [hci0] 30.804296
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 64
        Features: 0x19 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Slave-initiated Features Exchange
          LE Ping
= bluetoothd: No cache for 4E:E4:C0:F5:D2:DB                                       30.804688
< ACL Data TX: Handle 64 flags 0x00 dlen 7                              #13 [hci0] 30.804796
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> ACL Data RX: Handle 64 flags 0x02 dlen 7                              #14 [hci0] 30.953980
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 517
< ACL Data TX: Handle 64 flags 0x00 dlen 11                             #15 [hci0] 30.954175
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 11                             #16 [hci0] 30.954449
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
< ACL Data TX: Handle 64 flags 0x00 dlen 18                             #17 [hci0] 30.954610
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0005
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x0006-0x0009
        UUID: Generic Attribute Profile (0x1801)
> HCI Event: Number of Completed Packets (0x13) plen 5                  #18 [hci0] 31.094140
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: Number of Completed Packets (0x13) plen 5                  #19 [hci0] 31.344179
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: LE Meta Event (0x3e) plen 10                               #20 [hci0] 31.356854
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 64
        Connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
< HCI Command: LE Set Advertising Parameters (0x08|0x0006) plen 15      #21 [hci0] 32.528520
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                             #22 [hci0] 32.528877
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1             #23 [hci0] 32.528910
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                             #24 [hci0] 32.529300
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5                  #25 [hci0] 36.359869
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: Disconnect Complete (0x05) plen 4                          #26 [hci0] 36.359962
        Status: Success (0x00)
        Handle: 64
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8                  {0x0002} [hci0] 36.359978
        LE Address: 4E:E4:C0:F5:D2:DB (Resolvable)
        Reason: Connection timeout (0x01)
@ MGMT Event: Device Disconnected (0x000c) plen 8                  {0x0001} [hci0] 36.359978
        LE Address: 4E:E4:C0:F5:D2:DB (Resolvable)
        Reason: Connection timeout (0x01)

[ukBaz]

What you have done with bluetoothctl is the same as what is done with the Bluezero code is doing.

I am still unable to reproduce the fault here. A thought is that you have the system in some unexpected state. If you have had failures earlier in the adding the advertisements, I sometimes find it necessary to restart the Bluetooth service sudo service bluetooth restart to get it back into a known condition.

Your MIDI question is a separate issue so I've started a new ticket for that.

[arslan437]

I did restart the service and rebooted the pi multiple time but the situation is still the same.

so I did upgraded the bluez to 5.54 but no luck. here are the steps

wget http://www.kernel.org/pub/linux/bluetooth/bluez-5.54.tar.xz
sudo tar xf bluez-5.54.tar.xz
cd bluez-5.54
./configure --prefix=/usr \
            --mandir=/usr/share/man \
            --sysconfdir=/etc \
            --localstatedir=/var \
            --enable-experimental \
            --enable-maintainer-mode\
            --enable-midi
make -j 4 && sudo make install
sudo sed -i '/^ExecStart.*bluetoothd\s*$/ s/$/ --experimental/' /lib/systemd/system/bluetooth.service
sudo systemctl daemon-reload
sudo service bluetooth restart

sudo cp /usr/lib/bluetooth/bluetoothd /usr/lib/bluetooth/bluetoothd-550.orig
sudo ln -sf /usr/libexec/bluetooth/bluetoothd /usr/lib/bluetooth/bluetoothd
sudo systemctl daemon-reload

[arslan437]

here is the error from the nrf connect app. By the way which app are you using for testing?

[ukBaz]

I have been using a combination of chrome://bluetooth-internals/#device, nRF Connect app, and nRF UART 2.0 app and it has generally been without issue.

Then finally today I had one connection that gave me the error:

(venv) pi@raspberrypi:~/development/python-bluezero $ python examples/ble_uart.py 

setup ad_manager
setup service_manager
Advertising service  6E400001-B5A3-F393-E0A9-E50E24DCCA9E
Register Advert /ukBaz/bluezero/advertisement1970724976
Register Application  /ukBaz/bluezero/application1974338128
GetManagedObjects
GATT application registered
Advertisement registered
ERROR:dbus.connection:Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/dbus/connection.py", line 230, in maybe_handle_message
    self._handler(*args, **kwargs)
  File "/home/pi/development/python-bluezero/bluezero/adapter.py", line 267, in _properties_changed
    device_addr=macaddr)
  File "/home/pi/development/python-bluezero/bluezero/device.py", line 56, in __init__
    " using adapter: " + adapter_addr)
ValueError: Cannot find a device: 75:8F:AE:E6:48:4E using adapter: 00:02:5B:03:44:07
my test data
^C^CClosing Mainloop
(venv) pi@raspberrypi:~/development/python-bluezero $ python examples/ble_uart.py 

setup ad_manager
setup service_manager
Advertising service  6E400001-B5A3-F393-E0A9-E50E24DCCA9E
Register Advert /ukBaz/bluezero/advertisement1971355824
Register Application  /ukBaz/bluezero/application1979622352
GetManagedObjects
GATT application registered
Advertisement registered
my test data

However, when I ran it again it worked without error. In the session that got the ERROR, it still allowed me to send my test data.

I need to test this a little more to find out why it only is an issue intermittently. I need to do some logging of what the contents are that cause the good and bad triggering of the _properties_changed call back in the adapter: https://github.com/ukBaz/python-bluezero/blob/master/bluezero/adapter.py#L258

[arslan437]

Its totally the opposite case, just worked few time I don't how. But will be waiting for your response.

[ukBaz]

Can you take a look at the ble_peripheral branch I have just created. https://github.com/ukBaz/python-bluezero/tree/ble_peripheral

I've done a new commitwhich I hope solves this problem. It seems the issue was when there was a properties changed event that was for a disconnect. The adapter was still trying to create a new device. I haven't been able to create a failure with this new commit. Would be good if someone else could try it also.

[arslan437]

I have tested it and it worked perfectly. It solved the issue.

[ukBaz]

Thanks for testing. I'll do some more testing using the adapter code when it is used as a central device to check it hasn't broken that and then I'll merge.

[ukBaz]

This fix has been merged so I'm going to close this issue