ESPhome Bluetooth BLE proxy stops working

OiD-W · December 2, 2023, 12:38pm

Hello wonderful people!

I’m running the latest HA (2023.11.6) and ESPHome (2023.11.6) versions with the newest BLE Proxy repo (github://esphome/firmware/bluetooth-proxy/wt32-eth01.yaml).

My issue is that it does not work longer than a day or two.

When it works it’s flawless.
I’ve tried on 2 different ESP32 boards and a 3rd one with ethernet and all have the same issue.
The device is never offline and I can see the logs. Sometimes it gets suck at “Pausing scan to make connection…” and others at “Starting scan…” while other times the logs look as normal sending, connecting and receiving but the actual BLE devices do nothing and HA shows no updates either.

Any ideas?

Thanks!

Mikrofarad · December 23, 2023, 8:48am

That’s a common problem. I have two BT proxies running on different ESP32 hardware and I created an automation to get it running more than only for hours.
My automation activates “Safe Mode Boot” of the proxy under certain cirumstances. But in rare cases the proxy hangs completly (it’s no more visible on my WLAN) and a power reset is necessary

brooksben11 · December 23, 2023, 2:35pm

That’s definitely not normal behavior. I have 6 all acting as BT Proxies in addition to whatever original purpose they had (some of which are reasonably demanding too) and have never had an issue with any of them like that.

OiD-W · December 24, 2023, 6:14pm

To be honest, I’m not even sure what safe boot even does as it has already stopped responding. Power cycling sometimes solves the issue but many times it does not for me.

OiD-W · December 24, 2023, 6:15pm

Woah, that’s a lot of BLE stuff going on xD
I’m not adding anything else to them even though I would like to. I don’t want to make it any more unstable than it is.
Are you using the github code or custom code?

brooksben11 · December 24, 2023, 6:22pm

You don’t need to do anything special. Just use a base YAML for your device, use the esp-idf framework (remove captive portal, if you have it) and add both the bluetooth-proxy and esp32_ble_tracker components.

Make sure you don’t add the scan parameters for the tracker configuration (unless you’re using an Ethernet board). Seems a lot of people misread the docs and add that rather than leaving it alone and letting it use th default settings.

I’ve simply added that to my already existing ESPHome projects (none of mine are/were dedicated BT Proxies).

Mikrofarad · December 25, 2023, 8:46am

I started from scratch on https://esphome.io/projects/ with two BT Proxies, one with M5Stack Atom Lite and the other on a generec ESP32 board.
Right now I cannot say, if both proxies are causing issues.
After Xmas I replace the generic ESP32 board with another M5Stack Atom Lite. My setup consists of 7 BTHome devices and 10 eQ-3 Bluetooth Smart Thermostats (dbuezas).
I know that two BT proxies are to less for my usecase, but nevertheless I wouldn’t expect that a BT proxy becomes unresponsive and needs a power reset to work again.

OiD-W · December 26, 2023, 7:34pm

So I followed your suggestions and made a BLE proxy yaml file with esphome, esp32, ethernet, api, logger, ota. esp32_ble_tracker, bluetooth_proxy and nothing else and it seems to have held up for the past 2 days…
Maybe the Ready-Made Projects — ESPHome and the Github code have some slight issues?

Will keep an eye on it. It has run for a few days before so… who knows xD

OiD-W · December 26, 2023, 7:38pm

Do you notice a group of radiators failing? I’m wondering if the internal bluetooth has anything to do with it too…

SpikeyGG · December 26, 2023, 7:39pm

This is the key, I have a device that is basically all it does. I’ve thoroughly tested with arduino and esp-idf and the latter is quite stable in comparison.

OiD-W · December 26, 2023, 7:44pm

Oh yeah, I’m using the esp-idf!

Mikrofarad · December 27, 2023, 10:08am

If one eQ-3 Bluetooth Smart Thermostats (dbuezas) fails, the others will follow if I don’t use my automation to reset all proxies. Since two days I use three Proxies, two with M5 Stack Atom Lite and one on a generic ESP32. But it’s nervertheless unstable and without my automation not usable.

BartV83 · September 28, 2024, 6:27am

I seem to have a similar setup.
2 esp32 devices with esphome Bluetooth proxy, 7 eq-3 trvs and 5 Xiaomi mija temperature sensors (advertising as ATC and configured that way in esphome)
I noticed similar behavior with the devices going no longer updating after a while but they can be restarted using a restart button configured in the esphome devices.

Did you find a way to make the Bluetooth gateways more stable? Or are you still using the automation? If so, how have you configured it, solely on time or another trigger?

Mikrofarad · September 28, 2024, 12:25pm

No nothing changed. This week I activated my eq-3 and the problems became much bigger. With only three XIAOMI temperature/humidity sensors and 2 BLU from shelly it worked quite well (but not perfect). My three BT proxies stop working several times a day, it’s absolutely inconvenient.

Sometimes the following happens and the BT proxy reboots after several minutes, but not always For me a watchdog timer is missing (as a work around).

[13:51:04][I][esp32_ble_client:084]: [1] [00:1A:22:1C:40:F5] Disconnecting.
[13:52:19][D][esp-idf:000][BTU_TASK]: W (340943) BT_HCI: hcif disc complete: hdl 0x1, rsn 0x16
***[13:59:24][E][esp32_ble_tracker:295]: ESP-IDF BLE scan never terminated, rebooting to restore BLE stack...
[13:59:24][I][app:125]: Forcing a reboot...***
INFO Processing expected disconnect from ESPHome API for m5stack-atom-lite-82fda8 @ 192.168.178.47
WARNING Disconnected from API
WARNING Can't connect to ESPHome API for m5stack-atom-lite-82fda8 @ 192.168.178.47: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='192.168.178.47', port=6053))]: [Errno 111] Connect call failed ('192.168.178.47', 6053) (SocketAPIError)
INFO Trying to connect to m5stack-atom-lite-82fda8 @ 192.168.178.47 in the background
INFO Successfully connected to m5stack-atom-lite-82fda8 @ 192.168.178.47 in 0.005s
INFO Successful handshake with m5stack-atom-lite-82fda8 @ 192.168.178.47 in 0.103s
[13:59:33][I][bluetooth_proxy:283]: [0] [00:1A:22:11:D7:D5] Connecting v3 with cache
[13:59:33][D][esp32_ble_tracker:219]: Pausing scan to make connection...
[13:59:33][I][esp32_ble_client:067]: [0] [00:1A:22:11:D7:D5] 0x00 Attempting BLE connection
[13:59:34][I][bluetooth_proxy:283]: [1] [00:1A:22:10:A9:AD] Connecting v3 with cache
[13:59:36][D][esp-idf:000][BTU_TASK]: W (11926) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
[13:59:40][D][esp-idf:000][BTU_TASK]: W (15919) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
lete: hdl 0x0, rsn 0x3e

Another BT proxy:

[13:59:18][D][esp-idf:000][BTU_TASK]: W (405230) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x16

[13:59:18][D][esp32_ble_client:172]: [0] [00:1A:22:1C:41:69] ESP_GATTC_DISCONNECT_EVT, reason 22
[13:59:18][D][esp32_ble_client:110]: [0] [] ESP_GATTC_CLOSE_EVT
[13:59:19][I][bluetooth_proxy:283]: [0] [00:1A:22:1C:3A:FB] Connecting v3 with cache
[13:59:19][I][esp32_ble_client:067]: [0] [00:1A:22:1C:3A:FB] 0x00 Attempting BLE connection
[13:59:19][D][esp-idf:000][BTU_TASK]: W (406115) BT_L2CAP: L2CAP - LE - cannot start new connection at conn st: 1

[13:59:39][I][esp32_ble_client:084]: [0] [00:1A:22:1C:3A:FB] Disconnecting.
**> [14:08:42][E][esp32_ble_tracker:295]: ESP-IDF BLE scan never terminated, rebooting to restore BLE stack...**
**> [14:08:42][I][app:125]: Forcing a reboot...**
INFO Processing expected disconnect from ESPHome API for m5stack-atom-lite-9d5500 @ 192.168.178.43
WARNING Disconnected from API
INFO Successfully connected to m5stack-atom-lite-9d5500 @ 192.168.178.43 in 1.100s
INFO Successful handshake with m5stack-atom-lite-9d5500 @ 192.168.178.43 in 0.204s
[14:08:48][C][factory_reset.button:011]: Factory Reset Button 'Factory reset'
[14:08:48][C][factory_reset.button:011]:   Icon: 'mdi:restart-alert'
[14:08:48][D][api.connection:1445]: Home Assistant 2024.9.3 (192.168.178.101): Connected successfully
[14:08:48][C][esp32_ble:391]: ESP32 BLE:
[14:08:48][C][esp32_ble:393]:   MAC address: D4:D4:DA:9D:55:02
[14:08:48][C][esp32_ble:394]:   IO Capability: none
[14:08:48][C][esp32_ble_tracker:655]: BLE Tracker:
[14:08:48][C][esp32_ble_tracker:656]:   Scan Duration: 300 s
[14:08:48][C][esp32_ble_tracker:657]:   Scan Interval: 320.0 ms
[14:08:48][C][esp32_ble_tracker:658]:   Scan Window: 30.0 ms
[14:08:48][C][esp32_ble_tracker:659]:   Scan Type: ACTIVE
[14:08:48][C][esp32_ble_tracker:660]:   Continuous Scanning: True
[14:08:48][C][mdns:116]: mDNS:
[14:08:48][C][mdns:117]:   Hostname: m5stack-atom-lite-9d5500
[14:08:48][C][esphome.ota:073]: Over-The-Air updates:
[14:08:48][C][esphome.ota:074]:   Address: m5stack-atom-lite-9d5500.local:3232
[14:08:48][C][esphome.ota:075]:   Version: 2
[14:08:49][C][safe_mode:018]: Safe Mode:
[14:08:49][C][safe_mode:020]:   Boot considered successful after 60 seconds
[14:08:49][C][safe_mode:021]:   Invoke after 10 boot attempts
[14:08:49][C][safe_mode:023]:   Remain in safe mode for 300 seconds
[14:08:49][C][api:139]: API Server:
[14:08:49][C][api:140]:   Address: m5stack-atom-lite-9d5500.local:6053
[14:08:49][C][api:142]:   Using noise encryption: YES
[14:08:50][I][bluetooth_proxy:283]: [0] [00:1A:22:1C:41:72] Connecting v3 with cache
[14:08:50][D][esp32_ble_tracker:219]: Pausing scan to make connection...
[14:08:50][I][esp32_ble_client:067]: [0] [00:1A:22:1C:41:72] 0x00 Attempting BLE connection
[14:08:53][D][esp32_ble_client:110]: [0] [00:1A:22:1C:41:72] ESP_GATTC_CONNECT_EVT
[14:08:53][D][esp32_ble_client:110]: [0] [00:1A:22:1C:41:72] ESP_GATTC_OPEN_EVT
[14:08:53][I][esp32_ble_client:154]: [0] [00:1A:22:1C:41:72] Connected
[14:08:53][D][esp32_ble_tracker:270]: Starting scan...
[14:08:53][D][esp-idf:000][BTU_TASK]: E (11474) BT_L2CAP: slave connection parameters update failed, the parameters are out of range

[14:08:53][D][esp-idf:000][BTU_TASK]: E (11490) BT_APPL: service change write ccc failed

[14:08:54][I][bluetooth_proxy:283]: [1] [00:1A:22:1C:40:F5] Connecting v3 with cache
[14:08:54][D][esp32_ble_client:110]: [0] [00:1A:22:1C:41:72] ESP_GATTC_REG_FOR_NOTIFY_EVT
[14:08:54][D][esp32_ble_client:188]: [0] [00:1A:22:1C:41:72] cfg_mtu status 0, mtu 23
[14:08:54][D][esp32_ble_tracker:219]: Pausing scan to make connection...
[14:08:54][D][esp32_ble_tracker:219]: Pausing scan to make connection...
[14:08:54][D][esp-idf:000][BTU_TASK]: E (11572) BT_BTM: BTM_BleScan scan not active

Also a Fatal Error could be observed in the log.

> 
> > [> 14:09:48][D][esp-idf:000][BTU_TASK]: W (66404) BT_HCI: hci cmd send: disconnect: hdl 0x0, rsn:0x13
> > 
> > [14:09:48][D][esp-idf:000][BTU_TASK]: W (66410) BT_APPL: gattc_conn_cb: if=3 st=0 id=515 rsn=0x16
> > **> ERROR Fatal error: protocol.data_received() call failed.**
> **> protocol: <aioesphomeapi._frame_helper.noise.APINoiseFrameHelper object at 0x7feb3cca8b40>**
> **> transport: <_SelectorSocketTransport fd=6 read=polling write=<idle, bufsize=0>>**
> **> Traceback (most recent call last):**
> **>   File "/usr/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received**
> **>     self._protocol.data_received(data)**
> **>   File "aioesphomeapi/_frame_helper/noise.py", line 136, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper.data_received**
> **>   File "aioesphomeapi/_frame_helper/noise.py", line 163, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper.data_received**
> **>   File "aioesphomeapi/_frame_helper/noise.py", line 319, in aioesphomeapi._frame_helper.noise.APINoiseFrameHelper._handle_frame**
> **>   File "/usr/local/lib/python3.11/dist-packages/noise/state.py", line 74, in decrypt_with_ad**
> **>     plaintext = self.cipher.decrypt(self.k, self.n, ad, ciphertext)**
> **>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^**
> **>   File "/usr/local/lib/python3.11/dist-packages/noise/backends/default/ciphers.py", line 13, in decrypt**
> **>     return self.cipher.decrypt(nonce=self.format_nonce(n), data=ciphertext, associated_data=ad)**
> **>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^**
> **> cryptography.exceptions.InvalidTag**
> > WARNING m5stack-atom-lite-9d5500 @ 192.168.178.43: Connection error occurred: m5stack-atom-lite-9d5500 @ 192.168.178.43: Invalid encryption key: received_name=m5stack-atom-lite-9d5500
> > INFO Processing unexpected disconnect from ESPHome API for m5stack-atom-lite-9d5500 @ 192.168.178.43
> > WARNING Disconnected from API
> > INFO Successfully connected to m5stack-atom-lite-9d5500 @ 192.168.178.43 in 0.006s
> > INFO Successful handshake with m5stack-atom-lite-9d5500 @ 192.168.178.43 in 0.085s
> > [14:09:50][I][bluetooth_proxy:283]: [0] [00:1A:22:15:CB:D3] Connecting v3 with cache
> > [14:09:52][I][bluetooth_proxy:283]: [2] [00:1A:22:1C:3A:FB] Connecting v3 with cache
> > [14:09:52][D][esp-idf:000][BTU_TASK]: W (70214) BT_HCI: hcif disc complete: hdl 0x2, rsn 0x3e
> > 
> > [14:09:56][D][esp-idf:000][BTU_TASK]: W (74226) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
> > 
> > [14:10:00][D][esp-idf:000][BTU_TASK]: W (78236) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
> > 
> > [14:10:01][D][esp-idf:000][BTU_TASK]: W (79240) BT_APPL: gattc_conn_cb: if=3 st=0 id=259 rsn=0x3e
> > 
> > [14:10:01][D][esp-idf:000][BTU_TASK]: W (79244) BT_APPL: gattc_conn_cb: if=4 st=0 id=260 rsn=0x3e
> > 
> > [14:10:01][D][esp-idf:000][BTU_TASK]: W (79246) BT_APPL: gattc_conn_cb: if=5 st=0 id=261 rsn=0x3e
> > 
> > [14:10:01][D][esp-idf:000][BTU_TASK]: W (79248) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
> > 
> > [14:10:01][D][esp32_ble_client:172]: [1] [00:1A:22:1C:41:69] ESP_GATTC_DISCONNECT_EVT, reason 62
> > [14:10:01][I][esp32_ble_client:067]: [0] [00:1A:22:15:CB:D3] 0x00 Attempting BLE connection
> > [14:10:02][I][bluetooth_proxy:283]: [1] [00:1A:22:1C:41:69] Connecting v3 with cache
> > [14:10:06][D][esp32_ble_client:110]: [0] [00:1A:22:15:CB:D3] ESP_GATTC_CONNECT_EVT

For me there must be a bug in the BT proxy, but I cannot determine the cause. As far as I know one BT proxy can connect up to three BT devices in parallel, but the eQ-3 are only connected to update data and then the connection is freed up.

Mikrofarad · September 28, 2024, 12:28pm

I observe some entites provided by e.g. eQ-3 and if one gets unavailable for a certain time I reboot all proxies.