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.

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

"bleak.exc.BleakError: This service is already present in this BleakGATTServiceCollection!" when reconnecting a device #376

Closed
sandhu0409 opened this issue Dec 3, 2020 · 8 comments · Fixed by #621
Assignees
Labels
Backend: BlueZ Issues and PRs relating to the BlueZ backend

Comments

@sandhu0409
Copy link

  • bleak version: 0.9.1
  • Python version: 3.7
  • BlueZ version (bluetoothctl -v) in case of Linux: 5.50

Description

For very first time the central code for scanning BLE Devices worked and connected with uart device. But after connection I was not able to disconnect it.

What I Did

I had scanned BLE Devices and make connection. It worked and shown

disconnected, scanning
connected

Then I had stopped peripheral service. After service was stopped I had ran scanner class again then i was showing below error.

disconnected, scanning
Traceback (most recent call last):
  File "echoClient.py", line 31, in <module>
    ble.connect(advertisement)
  File "/usr/local/lib/python3.7/dist-packages/adafruit_ble/__init__.py", line 305, in connect
    connection = self._adapter.connect(advertisement.address, timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/_bleio/adapter_.py", line 373, in connect
    return self.await_bleak(self._connect_async(address, timeout=timeout))
  File "/usr/local/lib/python3.7/dist-packages/_bleio/adapter_.py", line 134, in await_bleak
    return future.result(timeout)
  File "/usr/lib/python3.7/concurrent/futures/_base.py", line 432, in result
    return self.__get_result()
  File "/usr/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/dist-packages/_bleio/adapter_.py", line 384, in _connect_async
    await client.connect(timeout=timeout)
  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 405, in get_services
    BleakGATTServiceBlueZDBus(service, object_path)
  File "/usr/local/lib/python3.7/dist-packages/bleak/backends/service.py", line 116, in add_service
    "This service is already present in this BleakGATTServiceCollection!"
bleak.exc.BleakError: This service is already present in this BleakGATTServiceCollection!
@hbldh
Copy link
Owner

hbldh commented Dec 3, 2020

Do you have two services with the same uuid on the peripheral? In that case this is related to #362.

@hbldh hbldh self-assigned this Dec 3, 2020
@hbldh hbldh added the Backend: BlueZ Issues and PRs relating to the BlueZ backend label Dec 3, 2020
@sandhu0409
Copy link
Author

No I have ran only one service with
UART_SERVICE_UUID = '6e400001-b5a3-f393-e0a9-e50e24dcca9e'
UART_RX_CHARACTERISTIC_UUID = '6e400002-b5a3-f393-e0a9-e50e24dcca9e'
UART_TX_CHARACTERISTIC_UUID = '6e400003-b5a3-f393-e0a9-e50e24dcca9e'
There is no other service with same UUID

@dlech
Copy link
Collaborator

dlech commented Dec 7, 2020

Can you give a full working code example to reproduce the problem?

@jeffsf
Copy link

jeffsf commented Aug 12, 2021

I'm seeing something perhaps related, when I've got a device that drops connectivity (powered off) and then try to reconnect programmatically. If you think this is a different issue, more than willing to split it off. I'm still diagnosing and trying to discover "why".

No minimal, reproducible case yet.

bluetoothctl: 5.50
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
Linux pi-walnut 5.10.52-v7+ #1440 SMP Tue Jul 27 09:54:13 BST 2021 armv7l GNU/Linux
Python 3.9.5
bleak 0.12.1

Even if I try an explicit disconnect, the problem still seems to be present.

In the disconnect callback

            if not client.willful_disconnect:
                asyncio.get_event_loop().create_task(self._reconnect())
    async def _reconnect(self):
        """
        Will try immediately, then 1, 2, 3, ..., 10, 10, ... seconds later
        """
        await self.disconnect()
        class_name = type(self).__name__
        if self._logging_reconnect:
            logger.info(
                f"Will try reconnecting to {class_name} at {self.address} "
                f"after waiting {self._reconnect_delay} seconds.")
        await asyncio.sleep(self._reconnect_delay)

        await self.connect()
        if self.is_connected:
            self._reconnect_delay = 0
            self._logging_reconnect = True
        else:
            # code to try again in a bit
Traceback (most recent call last):
  File "/home/ble-remote/devel/pyDE1/src/pyDE1/scale/scale.py", line 478, in _reconnect
    await self.connect()
  File "/home/ble-remote/devel/pyDE1/src/pyDE1/scale/scale.py", line 172, in connect
    await asyncio.gather(self._event_connectivity.publish(
  File "/home/ble-remote/devel/pyDE1/src/pyDE1/bleak_client_wrapper.py", line 88, in connect
    retval = await super(BleakClientWrapped, self).connect(**kwargs)
  File "/home/ble-remote/venv/pyDE1_3.9/lib/python3.9/site-packages/bleak/backends/bluezdbus/client.py", line 258, in connect
    self.services.add_service(BleakGATTServiceBlueZDBus(obj, path))
  File "/home/ble-remote/venv/pyDE1_3.9/lib/python3.9/site-packages/bleak/backends/service.py", line 125, in add_service
    raise BleakError(
bleak.exc.BleakError: This service is already present in this BleakGATTServiceCollection!

The wrapper tries to manage clean-up atexit, marginally successfully (mainly around if there is a running loop and things complete before Python shuts it down).

    async def connect(self, **kwargs) -> bool:
        atexit.register(self.sync_disconnect)
        retval = await super(BleakClientWrapped, self).connect(**kwargs)
        if retval:
            self._willful_disconnect = False
        return retval

    async def disconnect(self) -> bool:
        self._willful_disconnect = True
        retval = await super(BleakClientWrapped, self).disconnect()
        self._willful_disconnect = False
        if retval:
            logger.debug("Unregistering atexit disconnect "
                         f"{self.name} at {self.address}")
            atexit.unregister(self.sync_disconnect)
        return retval

On powering back on the Skale, it does show up in bluetoothctl

[CHG] Device CF:75:75:90:8C:E3 ServicesResolved: no
[CHG] Device CF:75:75:90:8C:E3 Connected: no
[DE1]# info CF:75:75:90:8C:E3 
Device CF:75:75:90:8C:E3 (random)
	Name: Skale
	Alias: Skale
	Paired: no
	Trusted: no
	Blocked: no
	Connected: no
	LegacyPairing: no
	UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
	UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
	UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
	UUID: Battery Service           (0000180f-0000-1000-8000-00805f9b34fb)
	UUID: Unknown                   (0000ff08-0000-1000-8000-00805f9b34fb)
	UUID: Vendor specific           (0f050001-3225-44b1-b97d-d3274acb29de)
	ManufacturerData Key: 0x81ef
	ManufacturerData Value:
  fe ff ff ff     

Without deep knowledge of what is supposed to be happening, it is my guess that a previous service discovery is not being cleared before adding in the re-discovered services. Breakpoint at line 325 in service.py

image

@jeffsf
Copy link

jeffsf commented Aug 12, 2021

To reproduce:

  1. Configure the BLE_ID
  2. Turn the device on and enable its advertisements
  3. Run the program
  4. Observe that the device connects
  5. Turn the device off
  6. Note the logs indicating that reconnect() was called
  7. Note the (unretrieved) error (as the task result wasn't accessed)
bleak.exc.BleakError: This characteristic is already present in this BleakGATTServiceCollection!
import asyncio
import logging

from bleak import BleakClient

format_string = "%(asctime)s %(levelname)s %(name)s: %(message)s"
logging.basicConfig(level=logging.DEBUG,
                    format=format_string,
                    )
logger = logging.getLogger('run')

def disconnect_handler(c: BleakClient):
    logger.info("Disconnect handler")
    asyncio.get_running_loop().create_task(reconnect(c))


async def reconnect(c: BleakClient):
    logger.info("Reconnect")
    await c.connect()
    if not c.is_connected:
        # lazily call recursively, as shouldn't be more than a few
        await asyncio.sleep(10)
        await reconnect(c)


async def run():

    BLE_ID = 'CF:75:75:90:8C:E3'

    client = BleakClient(BLE_ID)
    client.set_disconnected_callback(disconnect_handler)
    await client.connect()
    logger.info("Connected")
    await asyncio.sleep(90)
    logger.info("90 seconds, disconnecting")
    await client.disconnect()


if __name__ == '__main__':

    loop = asyncio.get_event_loop()
    loop.set_debug(True)
    loop.run_until_complete(run())

@jeffsf
Copy link

jeffsf commented Aug 12, 2021

Ugly fix, but this at least appears to be functional for this specific host and implementation

Use "private access" with c.services = BleakGATTServiceCollection()

async def reconnect(c: BleakClient):
    logger.info("Reconnect")
    c.services = BleakGATTServiceCollection()
    await c.connect()
    if not c.is_connected:
        # lazily call recursively, as shouldn't be more than a few
        await asyncio.sleep(10)
        await reconnect(c)

@dlech
Copy link
Collaborator

dlech commented Aug 20, 2021

For those seeing this issue when reconnecting after a disconnect, I think #621 (comment) will fix the issue (it essentially does this: #376 (comment)).

If anyone is seeing this error at a different time, it would be interesting/helpful if you could confirm the sequence of events I describe in #625 (comment).

@dlech dlech linked a pull request Aug 20, 2021 that will close this issue
@dlech dlech reopened this Aug 20, 2021
@dlech dlech changed the title This service is already present in this BleakGATTServiceCollection! bleak.exc.BleakError: "bleak.exc.BleakError: This service is already present in this BleakGATTServiceCollection!" when reconnecting a device Aug 23, 2021
jeffsf added a commit to jeffsf/pyDE1 that referenced this issue Oct 22, 2021
@dlech
Copy link
Collaborator

dlech commented Sep 3, 2022

This should be fixed by #902.

@dlech dlech closed this as completed Sep 3, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Backend: BlueZ Issues and PRs relating to the BlueZ backend
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants