Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Client disconnects from the server automatically after 30s #1682

Open
yihan-liu opened this issue Nov 5, 2024 · 0 comments
Open

Client disconnects from the server automatically after 30s #1682

yihan-liu opened this issue Nov 5, 2024 · 0 comments

Comments

@yihan-liu
Copy link

  • bleak version: 0.22.3
  • Python version: 3.11.3
  • Operating System: Win 11

Description

Expected behavior

Read from an custom ESP32-C3 board that sends notifications of sensor data to the client, and implement a real-time data visualization with PyQt5.

What went wrong

The bleak client will connect to the server without problem and the visualization goes fine. After an exact 30s period the client triggers a disconnect without any reason.

What I Did

Here is the client program that I use.

import sys
import asyncio
from collections import deque

from bleak import BleakScanner, BleakClient
from PyQt5 import QtWidgets, QtCore
from pyqtgraph import PlotWidget, mkPen
import pyqtgraph as pg
from qasync import QEventLoop, asyncSlot

class BTVizApp(QtWidgets.QMainWindow):
    def __init__(self):
        super().__init__()
        self.setWindowTitle('BTViz')
        self.device_name = ''
        self.client = None
        self.characteristic_uuid = None
        self.data_buffer = []
        self.plots = []
        self.curves = []
        self.timestamps = []
        self.init_ui()

    def init_ui(self):
        # Create input dialog to get BLE device name
        self.device_name, ok = QtWidgets.QInputDialog.getText(
            self, 'Device Name Input', 'Enter BLE Device Name:')
        if not ok or not self.device_name:
            QtWidgets.QMessageBox.critical(
                self, 'Error', 'No device name entered. Exiting.')
            sys.exit(1)

        # Set up central widget and layout
        self.central_widget = QtWidgets.QWidget()
        self.setCentralWidget(self.central_widget)
        self.layout = QtWidgets.QVBoxLayout(self.central_widget)

        # Status label
        self.status_label = QtWidgets.QLabel('Connecting to device...')
        self.layout.addWidget(self.status_label)

        # Start BLE connection
        asyncio.ensure_future(self.start_ble())

    @asyncSlot()
    async def start_ble(self):
        # Scan for devices
        devices = await BleakScanner.discover()
        target_device = next((d for d in devices if d.name == self.device_name), None)

        if not target_device:
            QtWidgets.QMessageBox.critical(
                self, 'Error', f'Device {self.device_name} not found.')
            sys.exit(1)

        self.status_label.setText(f'Connecting to {self.device_name}...')
        self.client = BleakClient(target_device, winrt=dict(use_cached_services=False))

        try:
            await self.client.connect()

            for service in self.client.services:
                for char in service.characteristics:
                    if 'notify' in char.properties:
                        self.characteristic_uuid = char.uuid
                        break

            if not self.characteristic_uuid:
                QtWidgets.QMessageBox.critical(
                    self, 'Error', 'No notifiable characteristic found.')
                sys.exit(1)

            self.status_label.setText('Connected. Starting notifications...')
            await self.client.start_notify(self.characteristic_uuid, self.notification_handler)
            self.status_label.setText('Connected and receiving notifications.')

        except Exception as e:
            QtWidgets.QMessageBox.critical(
                self, 'Error', f'Failed to connect: {e}')
            sys.exit(1)

    def notification_handler(self, sender, data):
        """
        Handle incoming data from the BLE device.
        """
        # Decode and parse the data
        try:
            text = data.decode('utf-8').strip()
            values = [float(v) for v in text.split(',')]
        except Exception as e:
            print(f"Failed to parse data: {e}")
            return

        if not self.plots:
            # Initialize plots based on number of channels
            num_channels = len(values)
            for i in range(num_channels):
                plot_widget = PlotWidget()
                plot_widget.enableAutoRange(axis='y')
                plot_widget.showGrid(x=True, y=True)
                plot_widget.setTitle(f"Channel {i+1}")
                pen = mkPen(color=pg.intColor(i))
                curve = plot_widget.plot(pen=pen)
                self.layout.addWidget(plot_widget)
                self.plots.append(plot_widget)
                self.curves.append(curve)

                self.data_buffer.append(deque(maxlen=100))
                self.timestamps.append(deque(maxlen=100))

        # Append data and update plots
        timestamp = QtCore.QTime.currentTime().msecsSinceStartOfDay() / 1000.0
        for i, value in enumerate(values):
            self.data_buffer[i].append(value)
            self.timestamps[i].append(timestamp)
            self.curves[i].setData(list(self.timestamps[i]), list(self.data_buffer[i]))

def main():
    app = QtWidgets.QApplication(sys.argv)
    loop = QEventLoop(app)
    asyncio.set_event_loop(loop)
    window = BTVizApp()
    window.show()
    with loop:
        loop.run_forever()

if __name__ == "__main__":
    main()

Here is the output of the program after 30s of running:

Connection error: Could not start notify on 0029: Unreachable

The bug is not independent of the peripheral because both the PCB design and firmware are highly customized. However, from the logging information I can see on my ESP32-C3 device, it says that the client initiates the disconnection:

I (52095) SDM: ESP_GATTS_DISCONNECT_EVT, reason = 19

This stands for a connection terminate by peer user.

Logs

Here is the Wireshark log around the disconnect moment, you can find that in log No.1993 the client sent this disconnect message without prior errors:

No.     Time           Source                Destination           Protocol Length Info
   1984 42.324420      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      40     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1984: 40 bytes on wire (320 bits), 40 bytes captured (320 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1985 42.325139      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1985: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1986 42.325838      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1986: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1987 42.384432      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1987: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1988 42.385055      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1988: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1989 42.385786      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1989: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1990 42.444392      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1990: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1991 42.445052      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1991: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1992 42.445776      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1992: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1993 42.465942      host                  controller            HCI_CMD  7      Sent Disconnect

Frame 1993: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: host]
    [Destination: controller]
Bluetooth HCI H4
    [Direction: Sent (0x00)]
    HCI Packet Type: HCI Command (0x01)
Bluetooth HCI Command - Disconnect
    Command Opcode: Disconnect (0x0406)
    Parameter Total Length: 3
    Connection Handle: 0x0e01
    Reason: Remote User Terminated Connection (0x13)
    [Pending in frame: 1994]
    [Command-Pending Delta: 1.761ms]
    [Response in frame: 2002]
    [Command-Response Delta: 99.83ms]

No.     Time           Source                Destination           Protocol Length Info
   1994 42.467703      controller            host                  HCI_EVT  7      Rcvd Command Status (Disconnect)

Frame 1994: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: controller]
    [Destination: host]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: HCI Event (0x04)
Bluetooth HCI Event - Command Status

No.     Time           Source                Destination           Protocol Length Info
   1995 42.504375      Espressif_f8:21:5e (SpectraDerma) localhost ()          ATT      39     Rcvd Handle Value Notification, Handle: 0x002a (Unknown: Unknown)

Frame 1995: 39 bytes on wire (312 bits), 39 bytes captured (312 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: Espressif_f8:21:5e (30:30:f9:f8:21:5e)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol
Bluetooth Attribute Protocol

No.     Time           Source                Destination           Protocol Length Info
   1996 42.518157      host                  controller            HCI_CMD  6      Sent LE Set Scan Enable

Frame 1996: 6 bytes on wire (48 bits), 6 bytes captured (48 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: host]
    [Destination: controller]
Bluetooth HCI H4
    [Direction: Sent (0x00)]
    HCI Packet Type: HCI Command (0x01)
Bluetooth HCI Command - LE Set Scan Enable
    Command Opcode: LE Set Scan Enable (0x200c)
    Parameter Total Length: 2
    Scan Enable: false (0x00)
    Filter Duplicates: false (0x00)
    [Response in frame: 1997]
    [Command-Response Delta: 4.535ms]

No.     Time           Source                Destination           Protocol Length Info
   1997 42.522692      controller            host                  HCI_EVT  7      Rcvd Command Complete (LE Set Scan Enable)

Frame 1997: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: controller]
    [Destination: host]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: HCI Event (0x04)
Bluetooth HCI Event - Command Complete

No.     Time           Source                Destination           Protocol Length Info
   1998 42.522734      host                  controller            HCI_CMD  11     Sent LE Remove Device From Filter Accept List

Frame 1998: 11 bytes on wire (88 bits), 11 bytes captured (88 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: host]
    [Destination: controller]
Bluetooth HCI H4
    [Direction: Sent (0x00)]
    HCI Packet Type: HCI Command (0x01)
Bluetooth HCI Command - LE Remove Device From Filter Accept List
    Command Opcode: LE Remove Device From Filter Accept List (0x2012)
    Parameter Total Length: 7
    Address Type: Public Device Address (0x00)
    BD_ADDR: Espressif_f8:21:5e (30:30:f9:f8:21:5e)
    [Response in frame: 1999]
    [Command-Response Delta: 1.95ms]

No.     Time           Source                Destination           Protocol Length Info
   1999 42.524684      controller            host                  HCI_EVT  7      Rcvd Command Complete (LE Remove Device From Filter Accept List)

Frame 1999: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: controller]
    [Destination: host]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: HCI Event (0x04)
Bluetooth HCI Event - Command Complete

No.     Time           Source                Destination           Protocol Length Info
   2000 42.524697      host                  controller            HCI_CMD  6      Sent LE Set Scan Enable

Frame 2000: 6 bytes on wire (48 bits), 6 bytes captured (48 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: host]
    [Destination: controller]
Bluetooth HCI H4
    [Direction: Sent (0x00)]
    HCI Packet Type: HCI Command (0x01)
Bluetooth HCI Command - LE Set Scan Enable
    Command Opcode: LE Set Scan Enable (0x200c)
    Parameter Total Length: 2
    Scan Enable: true (0x01)
    Filter Duplicates: false (0x00)
    [Response in frame: 2001]
    [Command-Response Delta: 1.994ms]

No.     Time           Source                Destination           Protocol Length Info
   2001 42.526691      controller            host                  HCI_EVT  7      Rcvd Command Complete (LE Set Scan Enable)

Frame 2001: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: controller]
    [Destination: host]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: HCI Event (0x04)
Bluetooth HCI Event - Command Complete

No.     Time           Source                Destination           Protocol Length Info
   2002 42.565772      controller            host                  HCI_EVT  7      Rcvd Disconnect Complete

Frame 2002: 7 bytes on wire (56 bits), 7 bytes captured (56 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: controller]
    [Destination: host]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: HCI Event (0x04)
Bluetooth HCI Event - Disconnect Complete

No.     Time           Source                Destination           Protocol Length Info
   2003 60.841683      remote ()             localhost ()          L2CAP    9      Rcvd Connection oriented channel

Frame 2003: 9 bytes on wire (72 bits), 9 bytes captured (72 bits) on interface [email protected]:24352, id 0
Bluetooth
    [Source: 00:00:00_00:00:00 (00:00:00:00:00:00)]
    [Destination: 00:00:00_00:00:00 (00:00:00:00:00:00)]
Bluetooth HCI H4
    [Direction: Rcvd (0x01)]
    HCI Packet Type: ACL Data (0x02)
Bluetooth HCI ACL Packet
Bluetooth L2CAP Protocol

I also have the log near the disconnection moment with my BLEAK_LOGGING set to 1, you can see that the connection is maintained untill 21:48:54:

2024-11-04 21:48:21,423 bleak.backends.winrt.client MainThread DEBUG: Connecting to BLE device @ 30:30:F9:F8:21:5E
2024-11-04 21:48:21,479 bleak.backends.winrt.client MainThread DEBUG: getting services (service_cache_mode=<BluetoothCacheMode.UNCACHED: 1>, cache_mode=<BluetoothCacheMode.UNCACHED: 1>)...
2024-11-04 21:48:21,821 bleak.backends.winrt.client Dummy-1 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE8c:55:4a:a1:c4:0c-30:30:f9:f8:21:5e, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.ACTIVE: 1>
2024-11-04 21:48:21,883 bleak.backends.winrt.client Dummy-2 DEBUG: max_pdu_size_changed_handler: 516
2024-11-04 21:48:22,104 bleak.backends.winrt.client Dummy-1 DEBUG: 30:30:F9:F8:21:5E: services changed
2024-11-04 21:48:23,489 bleak.backends.winrt.client Dummy-2 DEBUG: 30:30:F9:F8:21:5E: services changed
2024-11-04 21:48:54,086 bleak.backends.winrt.client Dummy-1 DEBUG: max_pdu_size_changed_handler: 23
2024-11-04 21:48:54,087 bleak.backends.winrt.client Dummy-3 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE8c:55:4a:a1:c4:0c-30:30:f9:f8:21:5e, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.CLOSED: 0>
2024-11-04 21:48:54,097 bleak.backends.winrt.client Dummy-3 DEBUG: 30:30:F9:F8:21:5E: services changed
2024-11-04 21:48:54,105 bleak.backends.winrt.client Dummy-1 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE8c:55:4a:a1:c4:0c-30:30:f9:f8:21:5e, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.ACTIVE: 1>
2024-11-04 21:48:54,108 bleak.backends.winrt.client Dummy-4 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE8c:55:4a:a1:c4:0c-30:30:f9:f8:21:5e, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.CLOSED: 0>
2024-11-04 21:48:54,171 bleak.backends.winrt.client MainThread DEBUG: closing requester
2024-11-04 21:48:54,182 bleak.backends.winrt.client MainThread DEBUG: closing session        
2024-11-04 21:48:54,185 bleak.backends.winrt.client MainThread WARNING: 30:30:F9:F8:21:5E: unhandled services changed event
Connection error: Could not start notify on 0029: Unreachable

The final line is the same as without BLEAK_LOGGING.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@yihan-liu