hbldh / bleak

A cross platform Bluetooth Low Energy Client for Python using asyncio
MIT License
1.77k stars 294 forks source link

Intermittent "bleak.exc.BleakError: Services discovery error" when reading from Arduino #351

Closed DavesCodeMusings closed 3 years ago

DavesCodeMusings commented 3 years ago

Description

I have an Arduino Nano 33 BLE Sense reading environmental data (temperature, humidity, barometric pressure, irradiance) from its sensors and reporting via BLE. I am able to consistently read the measured characteristics using Linux's 'gatttool' and Nordic Semiconductor's nRF Connect Android app. When attempting to read with Python/Bleak, the connection throws a Service discovery error most of the time, but not always.

What I Did

I constructed a simple Python program, based on the example code in the Bleak README.rst file. On rare occasions, I am able to read characteristics with Python, but most times it will throw an error: "bleak.exc.BleakError: Services discovery error"

I have debugging output (see below) from the Arduino sketch that shows a connection being made from the Python program. The connection is closed a short time later (about 0.15 seconds.) Then, about five seconds later, Bleak throws the error. I assume the data has been read during the 0.15s connection time, because it is consistent with the length of time gatttool remains connected to carry out the same request.

My Arduino sketch is at: https://github.com/DavesCodeMusings/Nano33BLESense/blob/master/BluetoothWeather3.ino The Python code to read the temperature is at: https://github.com/DavesCodeMusings/Nano33BLESense/blob/master/read_temperature.py, but does not deviate much from the example in the README.

The fact that a connection is being made and then closed, with the error coming five seconds later makes me wonder if Bleak is timing out expecting some information my Arduino sketch is not providing. Though, if that is the case, I would expect gatttool and nRF to throw errors as well, but they do not. Reading the other characteristics (humidity, barometric pressure, and irradiance) gives the same results.

I do not have any other BLE devices to test against, and it might be tempting to say the error lies in my Arduino sketch. But, I am able to consistently read data from the same device using two other tools without error.

$ sudo ./read_temperature.py
Traceback (most recent call last):
  File "./read_temperature.py", line 21, in <module>
    loop.run_until_complete(run(address))
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "./read_temperature.py", line 15, in run
    async with BleakClient(address) as client:
  File "/usr/local/lib/python3.7/dist-packages/bleak/backends/client.py", line 60, in __aenter__
    await self.connect()
  File "/usr/local/lib/python3.7/dist-packages/bleak/backends/bluezdbus/client.py", line 157, in connect
    await self.get_services()
  File "/usr/local/lib/python3.7/dist-packages/bleak/backends/bluezdbus/client.py", line 389, in get_services
    raise BleakError("Services discovery error")
bleak.exc.BleakError: Services discovery error
$ sudo gatttool -b 71:A2:AE:D8:21:0C --char-read --uuid=0x2a6e
handle: 0x000d   value: e1 07

Debugging Output From BLE Device

Arduino serial debug output when connecting with Python: sudo ./read_temperature.py (The loop runs at 100mS intervals. Connection timeout is decremented with each iteration.)

Incoming connection from: b8:27:eb:10:b7:7f
New ambient count: 12
Pressure: 99165.9Pa
Temperature: 20.49°C
Humidity: 39.18%
Irradiance: 0.0W/sq. meter
Connect timeout: 600
Pressure: 99166.2Pa
Temperature: 20.38°C
Humidity: 39.20%
Irradiance: 0.0W/sq. meter
Connect timeout: 599
New ambient count: 12
Pressure: 99165.0Pa
Temperature: 20.40°C
Humidity: 39.26%
Irradiance: 0.0W/sq. meter
Connect timeout: 598
Pressure: 99168.8Pa
Temperature: 20.43°C
Humidity: 39.23%
Irradiance: 0.0W/sq. meter
Connect timeout: 597
New ambient count: 12
Pressure: 99166.1Pa
Temperature: 20.47°C
Humidity: 39.20%
Irradiance: 0.0W/sq. meter
Connect timeout: 596
Pressure: 99169.6Pa
Temperature: 20.42°C
Humidity: 39.10%
Irradiance: 0.0W/sq. meter
Connect timeout: 595
New ambient count: 12
Pressure: 99170.2Pa
Temperature: 20.43°C
Humidity: 39.16%
Irradiance: 0.0W/sq. meter
Connect timeout: 594
Pressure: 99163.8Pa
Temperature: 20.50°C
Humidity: 39.23%
Irradiance: 0.0W/sq. meter
Connect timeout: 593
New ambient count: 12
Pressure: 99166.1Pa
Temperature: 20.52°C
Humidity: 39.20%
Irradiance: 0.0W/sq. meter
Connect timeout: 592
Pressure: 99164.8Pa
Temperature: 20.52°C
Humidity: 39.22%
Irradiance: 0.0W/sq. meter
Connect timeout: 591
New ambient count: 12
Pressure: 99169.1Pa
Temperature: 20.52°C
Humidity: 39.29%
Irradiance: 0.0W/sq. meter
Connect timeout: 590
Pressure: 99169.2Pa
Temperature: 20.54°C
Humidity: 39.21%
Irradiance: 0.0W/sq. meter
Connect timeout: 589
New ambient count: 12
Pressure: 99167.6Pa
Temperature: 20.56°C
Humidity: 39.22%
Irradiance: 0.0W/sq. meter
Connect timeout: 588
Pressure: 99167.6Pa
Temperature: 20.49°C
Humidity: 39.16%
Irradiance: 0.0W/sq. meter
Connect timeout: 587
New ambient count: 12
Pressure: 99167.4Pa
Temperature: 20.49°C
Humidity: 39.19%
Irradiance: 0.0W/sq. meter
Connect timeout: 586
Connection terminated.

Arduino serial debug output when connecting with gatttool: sudo gatttool -b 71:A2:AE:D8:21:0C --char-read --uuid=0x2a6e (The loop runs at 100mS intervals. Connection timeout is decremented with each iteration.)

Incoming connection from: b8:27:eb:10:b7:7f
Pressure: 99158.1Pa
Temperature: 20.08°C
Humidity: 39.44%
Irradiance: 0.0W/sq. meter
Connect timeout: 600
New ambient count: 13
Pressure: 99166.5Pa
Temperature: 20.02°C
Humidity: 39.46%
Irradiance: 0.0W/sq. meter
Connect timeout: 599
Pressure: 99163.3Pa
Temperature: 20.02°C
Humidity: 39.52%
Irradiance: 0.0W/sq. meter
Connect timeout: 598
New ambient count: 13
Pressure: 99163.1Pa
Temperature: 20.02°C
Humidity: 39.51%
Irradiance: 0.0W/sq. meter
Connect timeout: 597
Pressure: 99161.2Pa
Temperature: 20.08°C
Humidity: 39.53%
Irradiance: 0.0W/sq. meter
Connect timeout: 596
New ambient count: 13
Pressure: 99164.1Pa
Temperature: 20.04°C
Humidity: 39.46%
Irradiance: 0.0W/sq. meter
Connect timeout: 595
Pressure: 99163.3Pa
Temperature: 20.08°C
Humidity: 39.56%
Irradiance: 0.0W/sq. meter
Connect timeout: 594
New ambient count: 13
Pressure: 99158.1Pa
Temperature: 20.08°C
Humidity: 39.54%
Irradiance: 0.0W/sq. meter
Connect timeout: 593
Pressure: 99162.8Pa
Temperature: 20.13°C
Humidity: 39.46%
Irradiance: 0.0W/sq. meter
Connect timeout: 592
New ambient count: 13
Pressure: 99165.2Pa
Temperature: 20.09°C
Humidity: 39.52%
Irradiance: 0.0W/sq. meter
Connect timeout: 591
Pressure: 99161.6Pa
Temperature: 20.11°C
Humidity: 39.51%
Irradiance: 0.0W/sq. meter
Connect timeout: 590
New ambient count: 13
Pressure: 99164.4Pa
Temperature: 20.09°C
Humidity: 39.48%
Irradiance: 0.0W/sq. meter
Connect timeout: 589
Pressure: 99162.2Pa
Temperature: 20.08°C
Humidity: 39.52%
Irradiance: 0.0W/sq. meter
Connect timeout: 588
New ambient count: 13
Pressure: 99157.1Pa
Temperature: 20.11°C
Humidity: 39.55%
Irradiance: 0.0W/sq. meter
Connect timeout: 587
Pressure: 99162.7Pa
Temperature: 20.06°C
Humidity: 39.44%
Irradiance: 0.0W/sq. meter
Connect timeout: 586
New ambient count: 13
Pressure: 99159.3Pa
Temperature: 20.09°C
Humidity: 39.46%
Irradiance: 0.0W/sq. meter
Connect timeout: 585
Pressure: 99166.7Pa
Temperature: 20.11°C
Humidity: 39.49%
Irradiance: 0.0W/sq. meter
Connect timeout: 584
New ambient count: 13
Pressure: 99163.9Pa
Temperature: 20.08°C
Humidity: 39.50%
Irradiance: 0.0W/sq. meter
Connect timeout: 583
Pressure: 99160.9Pa
Temperature: 20.13°C
Humidity: 39.53%
Irradiance: 0.0W/sq. meter
Connect timeout: 582
New ambient count: 13
Pressure: 99166.7Pa
Temperature: 20.11°C
Humidity: 39.48%
Irradiance: 0.0W/sq. meter
Connect timeout: 581
Pressure: 99162.5Pa
Temperature: 20.13°C
Humidity: 39.51%
Irradiance: 0.0W/sq. meter
Connect timeout: 580
New ambient count: 13
Pressure: 99159.1Pa
Temperature: 20.11°C
Humidity: 39.48%
Irradiance: 0.0W/sq. meter
Connect timeout: 579
Connection terminated.
dlech commented 3 years ago

You could try logging the Bluetooth traffic to see what the difference is between Bleak and the other tools you are using: https://bleak.readthedocs.io/en/latest/troubleshooting.html#linux

DavesCodeMusings commented 3 years ago

I ran a tcpdump capture on the Raspberry Pi for both gatttool traffic and python/bleak traffic. (See below.)

With gatttool, it requests Temperature and that's it (line 15 of gatttool.pcap).

Python/Bleak on the other hand, requests a service list first (line 28 of bleak.pcap). The Arduino is reporting three services: Generic Access Profile, Generic Attribute Profile, and Environmental Sensing (line 30).

It looks as if the request is made again (line 31) but with a different range of handles. This is when the Arduino begins reporting Attribute Not Found.

With the nRF Connect Android app, the three services Generic Access (0x1800) Generic Attribute (0x1801) and Environmental Sensing (0x181A) all appear in the output.

I'm not sure why Bleak is asking twice, but this seems to be the source of the error.

tcpdump gatttool:

    1   0.000000         host → controller   HCI_CMD 11 Sent LE Set Scan Parameters
    2   0.000346   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Parameters)
    3   0.000387         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
    4   0.000754   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
    5   0.400172   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Advertising Report)
    6   0.400264         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
    7   0.402631   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
    8   0.402704         host → controller   HCI_CMD 29 Sent LE Create Connection
    9   0.403245   controller → host         HCI_EVT 7 Rcvd Command Status (LE Create Connection)
   10   0.507728   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Connection Complete)
   11   0.508004         host → controller   HCI_CMD 6 Sent LE Read Remote Used Features
   12   0.508459   controller → host         HCI_EVT 7 Rcvd Command Status (LE Read Remote Used Features)
   13   0.508561   controller → host         HCI_EVT 17 Rcvd Command Complete (LE Read Remote Used Features)
   14   0.588547   controller → host         HCI_EVT 15 Rcvd LE Meta (LE Read Remote Used Features Complete)
   15   0.589062 localhost () → 71:a2:ae:d8:21:0c () ATT 16 Sent Read By Type Request, Temperature, Handles: 0x0001..0xffff
   16   0.783371 71:a2:ae:d8:21:0c () → localhost () ATT 15 Rcvd Read By Type Response, Attribute List Length: 1
   17   0.811967   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   18   2.821839         host → controller   HCI_CMD 7 Sent Disconnect
   19   2.822200   controller → host         HCI_EVT 7 Rcvd Command Status (Disconnect)
   20   2.831460   controller → host         HCI_EVT 7 Rcvd Disconnect Complete

tcpdump python/bleak:

    1   0.000000         host → controller   HCI_CMD 10 Sent LE Set Random Address
    2   0.000351   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Random Address)
    3   0.000385         host → controller   HCI_CMD 11 Sent LE Set Scan Parameters
    4   0.000667   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Parameters)
    5   0.000697         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
    6   0.001053   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
    7   0.018840   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Advertising Report)
    8   0.019685   controller → host         HCI_EVT 26 Rcvd LE Meta (LE Advertising Report)
    9   0.023736   controller → host         HCI_EVT 46 Rcvd LE Meta (LE Advertising Report)
   10   0.052785         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   11   0.054662   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   12   0.082167         host → controller   HCI_CMD 11 Sent LE Set Scan Parameters
   13   0.082482   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Parameters)
   14   0.082521         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   15   0.082874   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   16   0.123729   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Advertising Report)
   17   0.123772         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   18   0.125894   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   19   0.125925         host → controller   HCI_CMD 29 Sent LE Create Connection
   20   0.126443   controller → host         HCI_EVT 7 Rcvd Command Status (LE Create Connection)
   21   0.337243   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Connection Complete)
   22   0.337418         host → controller   HCI_CMD 6 Sent LE Read Remote Used Features
   23   0.338068   controller → host         HCI_EVT 7 Rcvd Command Status (LE Read Remote Used Features)
   24   0.338083   controller → host         HCI_EVT 17 Rcvd Command Complete (LE Read Remote Used Features)
   25   0.405581   controller → host         HCI_EVT 15 Rcvd LE Meta (LE Read Remote Used Features Complete)
   26   0.406752 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 12 Sent Exchange MTU Request, Client Rx MTU: 517
   27   0.600385 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 12 Rcvd Exchange MTU Response, Server Rx MTU: 247
   28   0.600752 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Group Type Request, GATT Primary Service Declaration, Handles: 0x0001..0xffff
   29   0.649365   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   30   0.698511 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 29 Rcvd Read By Group Type Response, Attribute List Length: 3, Generic Access Profile, Generic Attribute Profile, Environmental Sensing
   31   0.698773 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Group Type Request, GATT Primary Service Declaration, Handles: 0x0013..0xffff
   32   0.795416 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 14 Rcvd Error Response - Attribute Not Found, Handle: 0x0013 (Environmental Sensing: Unknown)
   33   0.795814 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Group Type Request, GATT Secondary Service Declaration, Handles: 0x0001..0xffff
   34   0.893105   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   35   1.039232 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 14 Rcvd Error Response - Attribute Not Found, Handle: 0x0001 (Generic Access Profile)
   36   1.039565 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Type Request, GATT Include Declaration, Handles: 0x0001..0x0012
   37   1.136664 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 14 Rcvd Error Response - Attribute Not Found, Handle: 0x0001 (Generic Access Profile)
   38   1.136961 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Type Request, GATT Characteristic Declaration, Handles: 0x0001..0x0012
   39   1.185606   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   40   1.625362   controller → host         HCI_EVT 7 Rcvd Disconnect Complete
hbldh commented 3 years ago

Yes, when starting a BleakClient, it needs to fetch all services, characteristics and descriptors to be able to do any work. You should try to not close the connection between readings, because that is the most expensive - and error prone - operation in Bleak.

The BlueZ DBus API might call additional times to your peripheral in the background, separate from Bleak. It handles some services separately and encapsulates these in DBus properties, so that might be it. I have not experienced Bleak doing anything wrong when fetching services and characteristics...

gatttool is not comparable to Bleak in this sense. Bleak will never perform similar to gatttool and you should try to work differently than you would with it. Bleak is higher level and is primarily geared towards a cross-platform solution instead of a optimal handling of number of BLE calls.

DavesCodeMusings commented 3 years ago

I assume by "not close the connection between readings" you mean my use of the connection time out in the Arduino sketch. If so, that is only there because the Arduino is not multi-threaded and can only service one client at a time. Without the timeout, if there are any clients that do not disconnect properly, the Arduino will need to be reset to release the old connection.

After looking at the difference in the traffic captures between gatttool and Bleak, I can see how Bleak is more robust with the request of more then just a single characteristic. Would it be useful for Bleak to have a function to do something similar to gatttool and request a single characteristic value and nothing more?

At this point, it looks to me like Bleak is expecting something that my Arduino sketch or the Arduino BLE library is not sending. I'll keep looking into it and see if I can determine what that is.

The one thing that still nags at me is that I'm consistently able to get the services list and the characteristics using the nRF Connect debugger app. If there is any error in the information exchange, it's not fatal as far as nRF Connect is concerned. Is there any way to do something similar with Bleak? Maybe a warning rather than a fatal exception?

DavesCodeMusings commented 3 years ago

Interesting turn of events. It is working now. I have changed nothing. I managed to capture the exchange with tshark (I mistakenly typed tcpdump before. All captures are actually with tshark the command-line wireshark.)

The exchange is a little longer (48 vs. 40 lines) and the value of the requested temperature characteristic is returned as expected.

Again, I have changed nothing in the Arduino sketch or the Python code. It's just working now. Very odd.

    1   0.000000         host → controller   HCI_CMD 10 Sent LE Set Random Address
    2   0.000373   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Random Address)
    3   0.000408         host → controller   HCI_CMD 11 Sent LE Set Scan Parameters
    4   0.000700   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Parameters)
    5   0.000726         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
    6   0.001086   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
    7   0.005009   controller → host         HCI_EVT 31 Rcvd LE Meta (LE Advertising Report)
    8   0.039589   controller → host         HCI_EVT 46 Rcvd LE Meta (LE Advertising Report)
    9   0.094558   controller → host         HCI_EVT 46 Rcvd LE Meta (LE Advertising Report)
   10   0.099403   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Advertising Report)
   11   0.100066   controller → host         HCI_EVT 26 Rcvd LE Meta (LE Advertising Report)
   12   0.148602         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   13   0.150368   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   14   0.176280         host → controller   HCI_CMD 11 Sent LE Set Scan Parameters
   15   0.176636   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Parameters)
   16   0.176668         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   17   0.177002   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   18   0.209706   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Advertising Report)
   19   0.209738         host → controller   HCI_CMD 6 Sent LE Set Scan Enable
   20   0.211604   controller → host         HCI_EVT 7 Rcvd Command Complete (LE Set Scan Enable)
   21   0.211629         host → controller   HCI_CMD 29 Sent LE Create Connection
   22   0.212152   controller → host         HCI_EVT 7 Rcvd Command Status (LE Create Connection)
   23   0.316054   controller → host         HCI_EVT 22 Rcvd LE Meta (LE Connection Complete)
   24   0.316211         host → controller   HCI_CMD 6 Sent LE Read Remote Used Features
   25   0.316727   controller → host         HCI_EVT 7 Rcvd Command Status (LE Read Remote Used Features)
   26   0.316830   controller → host         HCI_EVT 17 Rcvd Command Complete (LE Read Remote Used Features)
   27   0.403780   controller → host         HCI_EVT 15 Rcvd LE Meta (LE Read Remote Used Features Complete)
   28   0.404380 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 12 Sent Exchange MTU Request, Client Rx MTU: 517
   29   0.549872 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 12 Rcvd Exchange MTU Response, Server Rx MTU: 247
   30   0.550100 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 12 Sent Read Request, Handle: 0x0003 (Unknown)
   31   0.598830   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   32   0.696140 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 17 Rcvd Read Response, Handle: 0x0003 (Unknown)
   33   0.696466 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 12 Sent Read Request, Handle: 0x0005 (Unknown)
   34   0.793585 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 12 Rcvd Read Response, Handle: 0x0005 (Unknown)
   35   0.793899 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Group Type Request, GATT Primary Service Declaration, Handles: 0x0001..0xffff
   36   0.842562   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   37   0.891718 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 29 Rcvd Read By Group Type Response, Attribute List Length: 3, Generic Access Profile, Generic Attribute Profile, Environmental Sensing
   38   0.892031 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 16 Sent Read By Group Type Request, GATT Primary Service Declaration, Handles: 0x0013..0xffff
   39   0.988617 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 14 Rcvd Error Response - Attribute Not Found, Handle: 0x0013 (Environmental Sensing: Unknown)
   40   1.038566 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 14 Sent Write Request, Handle: 0x0009 (Generic Attribute Profile: Unknown)
   41   1.086292   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   42   1.232388 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 10 Rcvd Write Response, Handle: 0x0009 (Generic Attribute Profile: Unknown)
   43   1.232639 localhost () → 71:a2:ae:d8:21:0c (Nano33BLE) ATT 12 Sent Read Request, Handle: 0x000e (Environmental Sensing: Unknown)
   44   1.329840 71:a2:ae:d8:21:0c (Nano33BLE) → localhost () ATT 12 Rcvd Read Response, Handle: 0x000e (Environmental Sensing: Unknown)
   45   1.412848   controller → host         HCI_EVT 8 Rcvd Number of Completed Packets
   46   3.788931         host → controller   HCI_CMD 7 Sent Disconnect
   47   3.789285   controller → host         HCI_EVT 7 Rcvd Command Status (Disconnect)
   48   3.816706   controller → host         HCI_EVT 7 Rcvd Disconnect Complete
hbldh commented 3 years ago

No, I mean you Python code. Instead of running sudo ./read_temperature.py multiple times, change your Python program to keep the connection alive and read multiple times with the created session:

#!/usr/bin/env python3
#
# read_irradiance.py - connect to Blutooth Low Energy device and read the GATT
# Environmental Sensing characteristic for temperature.
# 
import asyncio
from bleak import BleakClient

address = input("Device Address (e.g. 12:34:56:78:9A:BC): ")
TEMPERATURE_UUID = "00002a6e-0000-1000-8000-00805f9b34fb"
async def run(address):
    async with BleakClient(address) as client:
        while True:
            temperature = await client.read_gatt_char(TEMPERATURE_UUID)
            print("Temperature: {0} Celsius".format(int.from_bytes(temperature, byteorder='little', signed=True) / 100))
            await asyncio.sleep(0.1)  # Sleep 100 ms and then read again.

loop = asyncio.get_event_loop()

This way you do not have to ask for services etc. every time you want to read from your device. It is much more efficient and a better way to use Bleak.

Would it be useful for Bleak to have a function to do something similar to gatttool and request a single characteristic value and nothing more?

No. There is a tool for that already: gatttool. If you want that functionality, use that instead is my recommendation. It is more suited for such usecases.

The one thing that still nags at me is that I'm consistently able to get the services list and the characteristics using the nRF Connect debugger app. If there is any error in the information exchange, it's not fatal as far as nRF Connect is concerned. Is there any way to do something similar with Bleak? Maybe a warning rather than a fatal exception?

No. If Bleak cannot get services it cannot do what it is supposed to do. It needs to raise an exception then. But you as a user can catch the exception and retry the connection. There are no guarantees that connections will succeed, there are a lot of things that can go wrong, in Bleak, BlueZ, DBus, Linux, your peripheral,... You should prepare your code for that possibility.

nRF Connect is a debugging tool, and thus it does not require the services to perform its main function. It is sufficient that it warns about it. For Bleak it is the other way around. I don't know. But it is not especially useful to compare Bleak with other BLE tools if they do not use the same underlying APIs, i.e. the BlueZ DBus API.

DavesCodeMusings commented 3 years ago

Thanks for the clarification. And thank you for all the time you spent on this issue. I still do not know why it is working now when it almost consistently failed before. I'll keep experimenting. I can see Bleak being very useful in my home automation projects and I appreciate your contributions to free software with this library.

DavesCodeMusings commented 3 years ago

I have found the culprit! I must apologize, as it was not Bleak as I initially suspected. I'm leaving this explanation of what happened in case any other Arduino users are hit by the same problem.

Uploading an Arduino sketch can result in a new BLE address for the device. That was the source of the problem.

I was assuming a BLE address was like an Ethernet MAC address in that it was burned in at the factory and read-only. Not so! Not only does the Arduino Nano's BLE address change when you update the firmware, but it can also change when a new sketch is uploaded.

I had made the mistake of hard-coding the BLE address in my Python test scripts. They would then work until I made a change to the sketch and uploaded it.

The nRF Connect Android app was looking up the device by name and resolving to the proper BLE address each time, which is why it never failed as my Python scripts did.

Many thanks to the Bleak devs for answering my questions prior to this discovery.