Is there a way to reduce the latency in start_notify()?

[datoslabs]

• bleak version: 0.14.2
• Python version: 3.7.11
• Operating System: Windows 10
• BlueZ version (bluetoothctl -v) in case of Linux: N/A

Description

Hi,

I am running Bleak on Windows 10 (central) reading 9DOF IMU data (packed into 1 GATT characteristic) from Arduino Nano 33 BLE. I have noticed that there is an average of 180ms -200ms latency between when the IMU characteristic is updated and when the python program is notified in the start_notify() callback. I measured this latency by comparing the Arduino Serial Monitor time stamp (connected to the same Windows 10 machine) and the time stamp in the start_notify() callback for the corresponding record. When I switched to polling the characteristic in a while loop with asyncio.sleep(0), the latency drops to an average of 20-25ms. Is polling the best practice in minimizing the latency of reading characteristic value updates?

[dlech]

Can you share the full programs? Both the notify version and the polled version?

[datoslabs]

Absolutely, here is an excerpt of the code... BTW, I know a small part of the latency is due to data parsing but since I kept the parsing steps the same in both, it would be irrelevant in the comparative results.

Using BLE Notify: The connect() method scans for the BLE device and calls start_notify on the characteristic.

async def connect(debug=False):
    global arduino, devices, queue

    # Call back for the BLE start_notify()
    async def parseData(sender, data):
        #print('{}, inside parseData(), id(queue):{}'.format(time.time(), id(queue)))
        sensorData=[]
        # 9 DOF IMU + 4 Load Cell readings
        for i in range(0,52,4):
            sensorData.append(struct.unpack('<f', data[i:i+4])[0])
        sensorData.append(int.from_bytes(data[52:54], byteorder='little'))
        sensorData.append(struct.unpack('<l', data[54:58])[0])
        queue.put_nowait((time.time(), sensorData))

    if (debug):
        print("Scanning for BLE devices...")
    devices = await BleakScanner.discover()
    arduinoFound=False
    for d in devices:
        if (debug):
            print(d)
        if (d.address == ARDUINO_ADDRESS):
            arduinoFound = True
    if arduinoFound:
        if (debug):
            print("Establishing connection to arduino at {0}...".format(ARDUINO_ADDRESS))
        try:
            arduino = BleakClient(ARDUINO_ADDRESS)
            await arduino.connect()
            if arduino.is_connected:
                print("Connected!, MTU size:{}".format(arduino.mtu_size))
                await arduino.start_notify(DATA_CHAR_UUID, parseData)
                print("Subscribed to BLE notifications.")
            else:
                print("Having trouble connecting to arduino at {0}".format(ARDUINO_ADDRESS))
        except BaseException as err:
            print("Error: {0}.".format(err, type(err)))
            raise err
    else:
        print("Error: Arduino BLE not found!")
        raise Exception("Arduino BLE not found!")

Polling:

#After connection to BLE is successfully established...
try:
    while True: 
        sensorData=[]
        data = bytes(await arduino.read_gatt_char(DATA_CHAR_UUID))

        for i in range(0,52,4):
            sensorData.append(struct.unpack('<f', data[i:i+4])[0])
        sensorData.append(int.from_bytes(data[52:54], byteorder='little'))
        sensorData.append(struct.unpack('<l', data[54:58])[0])
        queue.put_nowait((time.time(), sensorData))
        await asyncio.sleep(0)
except Exception as e:
    print(e)

[dlech]

This isn't quite enough code to see if you are doing something like disconnecting and reconnecting constantly in the notify version.

[datoslabs]

Both versions, as far as I can detect, are not constantly disconnecting and reconnecting during the test (at least not in the code I wrote nor detectable on the Arduino side). The notify version essentially gets executed by calling await connect() and I left it running for a min or so before disconnecting via await arduino.disconnect(). I'd also output to the Serial Monitor on the Arduino side when it's not connected to central and stop updating the characteristics. The last 4 bytes sent by the BLE characteristic acts as a "pseudo" ID assigned by Arduino. At the end of the test runs, I compare the records' receipt time stamp in the asyncio.queue against the corresponding Arduino's Serial Monitor time stamp using the "pseudo" ID.

[datoslabs]

Update

I just noticed that while the poll version has lower latency, it's only able to read every ~110ms; the Arduino is updating the characteristics every ~15ms. My CPU load is only ~10% during the test with plenty of free memory so I know it's not throttling due to resource constraints; is there a system log I can check for more details on what's happening at the pocket levels?

[dlech]

is there a system log I can check for more details on what's happening at the pocket levels?

Yes, see https://bleak.readthedocs.io/en/latest/troubleshooting.html#capture-bluetooth-traffic

[datoslabs]

Thank you very much @dlech!

Based on the Bluetooth traffic captured in Wireshark, the polling version, as expected, can only poll every ~110ms due to the extra "handshakes" around read requests whereas notify version continuously receives data packets from the peripheral. After I performed optional driver updates on my Windows 10, the latency for the notify version is at a more acceptable 25-30ms level. One thing to note is that my Bluetooth driver appeared to be the same version after the updates so I am not sure if the latency was fixed due to the restart or updated shared DLLs.