fails to connect to TC66C via bluetooth

[blshkv]

rd-usb-1.22.1

Please let me know how can I debug it further.

Here is the log file:

2024-06-07 12:07:48 - Connected
2024-06-07 12:07:48 - operation failed, retrying 1 of 10 or until 2024-06-07 12:08:48
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 93, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 110, in _read_run
    await self.client.start_notify(SERVER_TX_DATA[self.addresses_index], self.response.callback)
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 822, in start_notify
    raise BleakError(f"Characteristic {char_specifier} not found!")
bleak.exc.BleakError: Characteristic 0000ffe4-0000-1000-8000-00805f9b34fb not found!

2024-06-07 12:07:54 - operation failed, retrying 2 of 10 or until 2024-06-07 12:08:48
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 93, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 110, in _read_run
    await self.client.start_notify(SERVER_TX_DATA[self.addresses_index], self.response.callback)
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 822, in start_notify
    raise BleakError(f"Characteristic {char_specifier} not found!")
bleak.exc.BleakError: Characteristic 0000ffe4-0000-1000-8000-00805f9b34fb not found!

[kolinger]

It's not easy to debug Bluetooth issues since these messages are very generic and they could mean anything at all. It could mean basic things as bad signal or complicated things like the TC66C has new revision of hardware with different Bluetooth characteristics... RD-USB doesn't see what it excepts but there is no way to know why.

I don't know what did you try. Did you try to use official Android app to verify if Bluetooth connection works? Since this could mean literally anything then please try basic stuff to verify as much as possible to reduce the possibilities.

Another basic check is to probe the TC66C with hcitool & bluetoothctl:

First you need to know Bluetooth address, if you don't do LE scan:

# hcitool lescan

Then try to connect and see what TC66C says about itself:

# bluetoothctl
-> connect <bdaddr>

This should say Connection successful and spit out whole lot of [NEW] ..., please post those [NEW] ... elements to see what characteristics your TC66C advertises. If this works as expected and you don't see characteristic with UUID 0000ffe4-0000-1000-8000-00805f9b34fb then your TC66C is different than others. If this fails then the issue isn't RD-USB but the Bluetooth stack or the TC66C itself.

[blshkv]

It could be a new communication way indeed, as I purchased it recently firmware 1.18

just a quick reply, bluetoothctl connect returned the following:

connect 48:87:2d:72:13:9b7:2d:72:13:9b
Attempting to connect to 48:87:2d:72:13:9b
[bluetooth]# hci0 type 7 discovering off
[bluetooth]# hci0 48:87:2D:72:13:9B type LE Public connected eir_len 30
[CHG] Device 48:87:2D:72:13:9B Connected: yes
[BT24-M]# Connection successful
[BT24-M]# [NEW] Primary Service (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0006
        00001801-0000-1000-8000-00805f9b34fb
        Generic Attribute Profile
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0006/char0007
        00002a05-0000-1000-8000-00805f9b34fb
        Service Changed
[BT24-M]# [NEW] Descriptor (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0006/char0007/desc0009
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[BT24-M]# [NEW] Primary Service (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a
        0000180a-0000-1000-8000-00805f9b34fb
        Device Information
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char000b
        00002a29-0000-1000-8000-00805f9b34fb
        Manufacturer Name String
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char000d
        00002a24-0000-1000-8000-00805f9b34fb
        Model Number String
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char000f
        00002a26-0000-1000-8000-00805f9b34fb
        Firmware Revision String
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char0011
        00002a28-0000-1000-8000-00805f9b34fb
        Software Revision String
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char0013
        00002a23-0000-1000-8000-00805f9b34fb
        System ID
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service000a/char0015
        00002a50-0000-1000-8000-00805f9b34fb
        PnP ID
[BT24-M]# [NEW] Primary Service (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017
        0000ffe0-0000-1000-8000-00805f9b34fb
        Unknown
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017/char0018
        0000ffe1-0000-1000-8000-00805f9b34fb
        Unknown
[BT24-M]# [NEW] Descriptor (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017/char0018/desc001a
        00002902-0000-1000-8000-00805f9b34fb
        Client Characteristic Configuration
[BT24-M]# [NEW] Descriptor (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017/char0018/desc001b
        00002901-0000-1000-8000-00805f9b34fb
        Characteristic User Description
[BT24-M]# [NEW] Characteristic (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017/char001c
        0000ffe2-0000-1000-8000-00805f9b34fb
        Unknown
[BT24-M]# [NEW] Descriptor (Handle 0x0000)
        /org/bluez/hci0/dev_48_87_2D_72_13_9B/service0017/char001c/desc001e
        00002901-0000-1000-8000-00805f9b34fb
        Characteristic User Description
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B UUIDs: 00001800-0000-1000-8000-00805f9b34fb
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B UUIDs: 00001801-0000-1000-8000-00805f9b34fb
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B UUIDs: 0000180a-0000-1000-8000-00805f9b34fb
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B UUIDs: 00004d53-0000-1000-8000-00805f9b34fb
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B UUIDs: 0000ffe0-0000-1000-8000-00805f9b34fb
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B ServicesResolved: yes
[BT24-M]# [CHG] Device 48:87:2D:72:13:9B Modalias is nil

[kolinger]

Indeed it looks like TC66C has yet another revision.

We already have 2 sets:

SERVER_RX_DATA = ["0000ffe9-0000-1000-8000-00805f9b34fb", "0000ffe2-0000-1000-8000-00805f9b34fb"]
SERVER_TX_DATA = ["0000ffe4-0000-1000-8000-00805f9b34fb", "0000ffe1-0000-1000-8000-00805f9b34fb"]

Can you could identify what is RX and what is TX characteristic? That what would be helpful.

00001801-0000-1000-8000-00805f9b34fb is service isn't? We need RX and TX characteristic. RX if for receiving data, TX is for sending data from our point of view.

[kolinger]

Actually I see your TC66C has 0000ffe2-0000-1000-8000-00805f9b34fb and 0000ffe1-0000-1000-8000-00805f9b34fb and that should be already supported...

There is the trap! Bleak changed the message from Characteristic X was not found to Characteristic X not found and this did break the code that tries to identify what TC66C it is. Easy fix.

[kolinger]

Could you please try 1.22.2 to verify this fixes the issue?

[blshkv]

nop, it did not fix it:

2024-06-08 05:30:46 - Connecting
2024-06-08 05:30:49 - Connected
2024-06-08 05:30:49 - operation failed, retrying 1 of 10 or until 2024-06-08 05:31:49
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 93, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 111, in _read_run
    await self.client.start_notify(SERVER_TX_DATA[self.addresses_index], self.response.callback)
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 822, in start_notify
    raise BleakError(f"Characteristic {char_specifier} not found!")
bleak.exc.BleakError: Characteristic 0000ffe4-0000-1000-8000-00805f9b34fb not found!

2024-06-08 05:30:54 - operation failed, retrying 2 of 10 or until 2024-06-08 05:31:49
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 93, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 111, in _read_run
    await self.client.start_notify(SERVER_TX_DATA[self.addresses_index], self.response.callback)
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 822, in start_notify
    raise BleakError(f"Characteristic {char_specifier} not found!")
bleak.exc.BleakError: Characteristic 0000ffe4-0000-1000-8000-00805f9b34fb not found!

[kolinger]

I see, there are multiple issues. First call with wrong UUID doesn't throw error and that's where the error handling is. Second call throws error but the error handling for different UUID is only for the first call. Will fix tomorrow.

[kolinger]

Could you please try 1.22.3 to verify this fixes the issue?

[blshkv]

still something is wrong, see the error below. btw, you don't need to release it every time, I can test the latest from git. Just let me know when you want me to test it.

2024-06-08 15:21:05 - Connecting
2024-06-08 15:21:07 - Connected
2024-06-08 15:21:22 - operation failed, retrying 1 of 10 or until 2024-06-08 15:22:07
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 90, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 125, in _read_run
    raise NoResponseException
interfaces.tc.NoResponseException

2024-06-08 15:21:27 - Disconnecting

[kolinger]

still something is wrong, see the error below.

Indeed, the bleak is playing with me good. First the message changed to different wording, then first call doesn't fail and now the message doesn't include the UUID. If only there was dedicated exception or some code that would tell me what error it is instead of relaying on the message :).

btw, you don't need to release it every time, I can test the latest from git. Just let me know when you want me to test it.

Yeah, that would be much easier but you know - I'm so sure that this fix will make it work so I may as well release it....

I will wait this time - please try the current git version.

[blshkv]

Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

2024-06-08 15:46:40,676 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 140, in connect
    raise BleakDeviceNotFoundError(
bleak.exc.BleakDeviceNotFoundError: Device with address 48:87:2D:72:13:9B was not found.

2024-06-08 15:46:52,353 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

2024-06-08 15:47:03,939 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

2024-06-08 15:47:15,142 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 140, in connect
    raise BleakDeviceNotFoundError(
bleak.exc.BleakDeviceNotFoundError: Device with address 48:87:2D:72:13:9B was not found.

2024-06-08 15:47:36,079 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

2024-06-08 15:47:36,080 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/data/src/rd-usb/webapp/backend.py", line 252, in run
    self.retry(self.interface.connect)
  File "/data/src/rd-usb/webapp/backend.py", line 359, in retry
    self.interface.connect()
  File "/data/src/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/data/src/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/data/src/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/data/src/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

[kolinger]

The Device with address 48:87:2D:72:13:9B was not found. is not related to RD-USB. This is just Bluetooth stack being funny telling you the TC66C doesn't exist. Unplug TC66C, restart RD-USB, ... Bluetooth is flaky like this but I what I can do if it's telling me that device doesn't exist even if it does...

[blshkv]

ok, replugged. That's the initial error:

2024-06-08 15:51:27,410 - ERROR - <class 'interfaces.wrapper.ErrorException'>
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 34, in connect
    self.get_result(60)
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 209, in connect
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 384, in call
    await future
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 54, in connect
    self.get_loop().run_until_complete(self._connect_run(self.address))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 61, in _connect_run
    await self.client.connect()
  File "/usr/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 146, in connect
    async with async_timeout(timeout):
  File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

[kolinger]

Looks like Bluetooth doesn't work at all now. It fails before it even gets where you ended last time. Since it fails on timeout when trying to connect() - not anything we can do about that. You can try the probe with bluetoothctl to verify this. Try to somehow reset the Bluetooth stack on your machine or reboot the machine. If you mess with Bluetooth a lot it sometimes bricks like this.

[blshkv]

ok, rebooted, the bluetooth is back. Here is the new error:

2024-06-08 16:11:21 - Connected
2024-06-08 16:11:36 - operation failed, retrying 1 of 10 or until 2024-06-08 16:12:21
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 90, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 125, in _read_run
    raise NoResponseException
interfaces.tc.NoResponseException

[blshkv]

it's getting close:

2024-06-08 16:15:38 - Connecting
2024-06-08 16:15:38 - Connected
2024-06-08 16:15:38 - {"timestamp": 1717834538.90098, "voltage": 0.0, "current": 0.0, "power": 0.0, "resistance": 9999.9, "accumulated_current": 109.0, "accumulated_power": 519.0, "accumulated_time": null, "temperature": 26.0, "data_plus": 2.09, "data_minus": 2.68, "mode_id": null, "mode_name": null}
2024-06-08 16:15:39 - {"timestamp": 1717834539.8646936, "voltage": 0.0, "current": 0.0, "power": 0.0, "resistance": 9999.9, "accumulated_current": 109.0, "accumulated_power": 519.0, "accumulated_time": null, "temperature": 26.0, "data_plus": 2.13, "data_minus": 2.73, "mode_id": null, "mode_name": null}
2024-06-08 16:15:40 - Disconnecting
2024-06-08 16:15:40 - {"timestamp": 1717834540.8754232, "voltage": 0.0, "current": 0.0, "power": 0.0, "resistance": 9999.9, "accumulated_current": 109.0, "accumulated_power": 519.0, "accumulated_time": null, "temperature": 26.0, "data_plus": 2.13, "data_minus": 2.73, "mode_id": null, "mode_name": null}
2024-06-08 16:15:41 - Disconnected
2024-06-08 16:17:02 - Connecting
2024-06-08 16:17:04 - Connected
2024-06-08 16:17:19 - operation failed, retrying 1 of 10 or until 2024-06-08 16:18:04
Traceback (most recent call last):
  File "/usr/share/rd-usb/webapp/backend.py", line 363, in retry
    return callback()
           ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 49, in read
    return self.get_result(60)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 67, in get_result
    raise ErrorException(result)
interfaces.wrapper.ErrorException: Traceback (most recent call last):
  File "/usr/share/rd-usb/interfaces/wrapper.py", line 112, in call
    result = callback()
             ^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 90, in read
    return self.get_loop().run_until_complete(self._read_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/share/rd-usb/interfaces/tc.py", line 125, in _read_run
    raise NoResponseException
interfaces.tc.NoResponseException

[kolinger]

What happened there - it connected and disconnected by itself and then connected and failed?

[blshkv]

Yes! It's started to work! I have changed a few things, but I think the main one was: "CONFIG_BT_RFCOMM_TTY" in the kernel, which was disabled

[kolinger]

👍 Finally!

I don't have experience with custom kernel config so I don't know - but why would the option disabled by default if it's required for RFCOMM... Strange...

[blshkv]

We compile everything from source including kernel at Gentoo, that's why ;-) And I like to keep it clean with only modules which are relevant to my hardware. btw, I got a hint from a Ubutnu user, he had to install "kernel-extra-modules".

Please release this version, 1.22.3 is still broken.

Thanks for all your help!

[kolinger]

There is 1.22.4 already - that one includes the third fix.

I'm Debian user and there RFCOMM works without extra stuff, the sweet generic binaries. I know the Gentoo people like to compile everything - so much so they invented way to compile the compiler - the stage 1! 😄

[blshkv]

nah, that's GCC thingy. I think the story is that they had to compile a first version using a proprietary compiler, but switched to their own compiler later to avoid licence issues.

Have a great weekend, and thanks again!