hbldh / bleak

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

BleakScanner and BleakClient cause delay in existing connections in Linux #1290

Closed stuartlynne closed 1 year ago

stuartlynne commented 1 year ago

Description

In a program using BleakClient to create connections to multiple BLE devices, an existing relationship that is receiving data on a notify characteristic sees a short (about 4-5 seconds) pause when either BleakScanner or BleakClient is used.

It does not appear that any data is lost, it is just delayed in arrival.

This does not happen on Windows.

What I Did

See scantest.py, I'll add that as a separate comment.

Logs

BleakClient affecting received data. The data_conv function prints the device name, elapsed time from the last call and the calls per second from the start of the connection. In this example, there was a 4.8-second delay (3.8 seconds extra) when the new connection was being made.

Client.data_conv[Polar H10 9F65612A   1.0  1.1/S ]   14:46:32  data: 10 3e d8 03
Client.data_conv[Polar H10 9F65612A   1.0  1.1/S ]   14:46:33  data: 10 3e f6 03
Client.data_conv[Polar H10 9F65612A   0.9  1.1/S ]   14:46:34  data: 10 3e dc 03
Client.data_conv[Polar H10 9F65612A   1.0  1.1/S ]   14:46:35  data: 10 3e fc 03
main: HRM-Dual:929843
Client.__init__[HRM-Dual:929843]
Client.start[HRM-Dual:929843]
Client.task[HRM-Dual:929843] connect
Client.data_conv[Polar H10 9F65612A   1.1  1.1/S ]   14:46:36  data: 10 3e 03 04
Client.data_conv[Polar H10 9F65612A   4.8  0.9/S ]   14:46:41  data: 10 3e f5 03
Client.data_conv[Polar H10 9F65612A   0.0  0.9/S ]   14:46:41  data: 10 3e 01 04

BleakScanner affecting received data. In this example, there are two clients connected. Both see the elapsed time at 5, so additional 4 seconds of delay.

Client.data_conv[HRM-Dual:929843      0.5  2.2/S ]   14:46:52  data: 10 3c ee 03
Client.data_conv[Polar H10 9F65612A   1.0  1.0/S ]   14:46:53  data: 10 3d f2 03
Client.data_conv[HRM-Dual:929843      0.8  2.1/S ]   14:46:53  data: 10 3d d5 03
Scanner.task[1]: starting BleakScanner ----------------------------
Client.data_conv[HRM-Dual:929843      1.0  1.9/S ]   14:46:54  data: 00 3d
Client.data_conv[Polar H10 9F65612A   1.1  1.0/S ]   14:46:54  data: 10 3d f0 03
Client.data_conv[HRM-Dual:929843      5.0  1.1/S ]   14:46:59  data: 10 3d ef 03
Client.data_conv[HRM-Dual:929843      0.0  1.2/S ]   14:46:59  data: 10 3d e8 03
Client.data_conv[HRM-Dual:929843      0.0  1.3/S ]   14:46:59  data: 10 3d f3 03
Client.data_conv[HRM-Dual:929843      0.0  1.4/S ]   14:46:59  data: 00 3d
Client.data_conv[HRM-Dual:929843      0.0  1.5/S ]   14:46:59  data: 10 3c f8 03
Client.data_conv[HRM-Dual:929843      0.0  1.6/S ]   14:46:59  data: 10 3d de 03
Client.data_conv[Polar H10 9F65612A   5.0  0.9/S ]   14:46:59  data: 10 3d ee 03
Client.data_conv[Polar H10 9F65612A   0.0  0.9/S ]   14:46:59  data: 10 3d d4 03
Client.data_conv[Polar H10 9F65612A   0.0  1.0/S ]   14:46:59  data: 10 3d ef 03
Client.data_conv[Polar H10 9F65612A   0.0  1.0/S ]   14:46:59  data: 10 3d e7 03
Client.data_conv[Polar H10 9F65612A   0.0  1.0/S ]   14:46:59  data: 10 3d f3 03
Client.data_conv[HRM-Dual:929843      0.2  1.6/S ]   14:46:59  data: 10 3d e7 03
Scanner.task[1]: started ----------------------------
Client.data_conv[Polar H10 9F65612A   0.9  1.0/S ]   14:47:00  data: 10 3d f7 03
stuartlynne commented 1 year ago

scantest.py

import sys
import signal
import asyncio
import subprocess

from time import time
import datetime
import multiprocessing
import platform
import re

import bleak
from bleak import BleakScanner
from bleak.uuids import uuid16_dict
from bleak import BleakClient
from bleak.backends.scanner import AdvertisementData 
from bleak.backends.device import BLEDevice

def BLE_UUID(name):
    uuids = [ k for k, v in uuid16_dict.items() if v == name ] 
    uuid = f"0000{uuids[0]:x}-0000-1000-8000-00805f9b34fb"
    return uuid

HEART_RATE_SERVICE = BLE_UUID('Heart Rate')
HEART_RATE_MEASUREMENT_UUID = BLE_UUID('Heart Rate Measurement')

Supported_Services = [ HEART_RATE_SERVICE, ]

def bytes2str(bytes):
    return ' '.join(str('%02x'%b) for b in bytes)

class Scanner:

    def __init__(self):
        print('Scanner.__init__', file=sys.stderr)   
        self.event = asyncio.Event()  
        self.queue = asyncio.Queue()  

    # start
    # Create the asyncio task, passing the supported services list and asyncio queue to the task.
    def start(self, ): 
        print('Scanner.start', file=sys.stderr)
        self.scanner_task = asyncio.create_task(self.task(queue=self.queue, ))

    # _task
    # The scanner task. Creates a BleaScanner and in the callback looks for devices that
    # have match in the supported services. Device information for found devices is placed
    # in the queue.
    async def task(self, queue=None ):

        print('Scanner.task', file=sys.stderr)
        scan_time = 40
        async def callback(device, adv):
            for s in Supported_Services:
                if s.lower() in adv.service_uuids:
                    #print('Scanner.callback: %s' % (device.name), file=sys.stderr)
                    await queue.put(device)
                    return

        count = 0
        while not self.event.is_set():
            print('Scanner.task[%d]: starting BleakScanner ----------------------------' % (count), file=sys.stderr)
            async with BleakScanner(detection_callback=callback, scanning_mode="active") as scanner:
                print('Scanner.task[%d]: started ----------------------------' % (count), file=sys.stderr)
                await asyncio.sleep(scan_time)
                count += 1

    def stop(self,):
        print('Scanner.stop', file=sys.stderr)
        self.event.set()
    def empty(self,):
        return self.queue.empty()
    async def get(self,):
        return await self.queue.get()
class Client:

    def __init__(self, device):
        print('Client.__init__[%s]' % (device.name), file=sys.stderr)
        self.event = asyncio.Event()
        self.device = device
        self.first_time = self.last_time = None
        self.count = 0

    def start(self, ):
        print('Client.start[%s]' % (self.device.name), file=sys.stderr)
        self.scanner_task = asyncio.create_task(self.task())

    def stop(self,):
        print('Client.stop[%s]' % (self.device.name), file=sys.stderr)
        self.event.set()

    def client_disconnect(self, client):
        print('Client.client_disconnect[%s]' % (self.device.name), file=sys.stderr)
        self.event.set()

    def data_conv(self, sender, data):
        now = time()
        if self.last_time is None:
            self.last_time = self.first_time = now

        elapsed = now - self.last_time
        total_time = now - self.first_time
        self.last_time = now

        timestamp = datetime.datetime.fromtimestamp(now).strftime(f"%H:%M:%S")
        self.count += 1

        print("Client.data_conv[%-20s %3.1f %4.1f/S ]   %s  data: %s " % (
            self.device.name, elapsed, self.count / total_time if total_time != 0 else 0, timestamp, bytes2str(data)), file=sys.stderr)
    async def task(self, ):
        try:
            print('Client.task[%s] connect' % (self.device.name), file=sys.stderr)
            async with BleakClient(self.device, timeout=15.0, disconnected_callback=self.client_disconnect) as client:
                print('Client.task[%s] connected' % (self.device.name), file=sys.stderr)
                await client.start_notify(HEART_RATE_MEASUREMENT_UUID, self.data_conv)
                print('Client.task[%s] start_notify called' % (self.device.name), file=sys.stderr)
                while not self.event.is_set():
                    await asyncio.sleep(2)
                await client.stop_notify(HEART_RATE_MEASUREMENT_UUID, )
        except Exception as e:
            print('Client.task[%s] Exception e: %s' % (self.device.name, e), file=sys.stderr)
            print(traceback.format_exc(), file=sys.stderr)

async def main():

    clients = {}

    print('Python version: %s' % (sys.version), file=sys.stderr)
    if platform.system() == 'Linux':
        print('Bleak version: %s' % (bleak.__version__), file=sys.stderr)
        p = subprocess.run(["bluetoothctl", "--version"], capture_output=True, text=True)
        print('BlueZ version: %s' % (p.stdout), file=sys.stderr)

    def sigint_handler():
        print('sigint_handler: ', file=sys.stderr)
        scanner.stop()
        exitevent.set()
        for name, client in clients.items():
            client.stop()

    print('main: setup signal handler', file=sys.stderr)
    signal.signal(signal.SIGINT, lambda signal, frame: sigint_handler())

    print('main: start scanner', file=sys.stderr)
    exitevent = asyncio.Event()
    scanner = Scanner()
    scanner.start()

    while not exitevent.is_set():

        if scanner.empty():
            await asyncio.sleep(2)
            continue

        device = await scanner.get()
        if device.name not in clients:
            print('main: %s' % (device.name), file=sys.stderr)
            client = Client(device)
            client.start()
            clients[device.name] = client
            await asyncio.sleep(20)

asyncio.run(main())
dlech commented 1 year ago

Are you using the exact same Bluetooth adapter/radio on both Windows and Linux?

stuartlynne commented 1 year ago

TPLink USB Dongle in both.

Swapped, and now Linux is behaving. Swapped back and still behaved.

So presumably an underlying issue with BlueZ and linux drivers.

dlech commented 1 year ago

Does that mean we should close the issue?

stuartlynne commented 1 year ago

Yes, I think so. If there is an issue it would be with BlueZ.

Thanks!

On Fri, Apr 28, 2023 at 5:04 PM David Lechner @.***> wrote:

Does that mean we should close the issue?

— Reply to this email directly, view it on GitHub https://github.com/hbldh/bleak/issues/1290#issuecomment-1528262183, or unsubscribe https://github.com/notifications/unsubscribe-auth/AACIUWIFLUF6TDN2ZWLSHG3XDRLIPANCNFSM6AAAAAAXOOJMJI . You are receiving this because you authored the thread.Message ID: @.***>

-- __O____ -\<,____ ____()/()___


@.***>__604-518-1749(m)604-461-7532(h)