esp32 with bluetooth_proxy keeps on rebooting/disconnecting api

[accelle17]

The problem

uptime sensor doesn't usually go beyond 5-20 mins even with reboot_timeout: 0s on api. This is after upgrading esphome to 2022.9.3 and homeassistant core to 2022.10.0. Removing active on bluetooth_proxy prolongs the uptime but it is still way below than what it is used to be pre 2022.9.3. I am tracking 3 BLE cllients so I also tried using a quinled esp32 solely for active bluetooth_proxy but it is the same.

Which version of ESPHome has the issue?

2022.9.3

What type of installation are you using?

Home Assistant Add-on

Which version of Home Assistant has the issue?

2022.10.0

What platform are you using?

ESP32

Board

mhetesp32devkit, featheresp32, esp32dev

Component causing the issue

bluetooth_proxy

Example YAML snippet

#
substitutions:
  board: mhetesp32devkit
  device_name: iot_garage_bleproxy
  friendly_name: iot_garage_bleproxy

esphome:
  name: ${device_name}
  platform: ESP32
  board: ${board}

packages:
  wifi: !include common/wifi.yaml
  esphome: !include common/esphome_esp32bletracker_active.yaml

sensor:
  - platform: uptime
    name: ${friendly_name} uptime
    filters:
      - lambda: return x / 60;
    unit_of_measurement: "min"

##wifi.yaml::

wifi: 
  ssid: !secret iotssid
  password: !secret iotssid_pw
  fast_connect: off
  # power_save_mode: none
  ap:
    ssid: !secret backup_iotssid
    password: !secret backup_iotssid_pw
    ap_timeout: 2min
  reboot_timeout: 5min

##esphome_esp32bletracker_active.yaml::
web_server:
  port: 80
  auth:
    username: !secret web_user
    password: !secret web_pw

# Enable logging
logger:
  baud_rate: 0
  level: VERY_VERBOSE

# Enable Home Assistant API
api:
  password: !secret esphome
  encryption: 
   key: !secret encrypt
  reboot_timeout: 0s
ota:
  password: !secret esphome

esp32_ble_tracker:
  scan_parameters:
    # interval: 320ms
    # window: 160ms
    interval: 1100ms
    window: 1100ms
    active: true

dashboard_import:
  package_import_url: github://esphome/bluetooth-proxies/esp32-generic.yaml@main

bluetooth_proxy:
    active: true

button:
  - platform: safe_mode
    name: ${device_name}_safemode_boot
    entity_category: diagnostic

switch:
  - platform: restart
    name: '${friendly_name} REBOOT'
    entity_category: diagnostic

Anything in the logs that might be useful for us?

Time    level   Tag Message
17:13:45    [VV ][esp32_ble_tracker:575]    
Parse Result:
17:13:45    [VV ][esp32_ble_tracker:592]    
  Address: 01:C2:5C:AA:D3:6A (RANDOM)
17:13:45    [VV ][esp32_ble_tracker:594]    
  RSSI: -83
17:13:45    [VV ][esp32_ble_tracker:595]    
  Name: ''
17:13:45    [VV ][esp32_ble_tracker:609]    
  Manufacturer data: 01.09.20.02.02.F0.04.F2.8D.83.FD.03.4C.F1.AD.08.04.D6.77.E9.D8.2F.10.E1.49.2C.50 (27)
17:13:45    [VV ][esp32_ble_tracker:625]    
Adv data: 1E.FF.06.00.01.09.20.02.02.F0.04.F2.8D.83.FD.03.4C.F1.AD.08.04.D6.77.E9.D8.2F.10.E1.49.2C.50 (31)
17:13:45    [V] [bluetooth_proxy:023]   
Proxying packet from  - 01:C2:5C:AA:D3:6A. RSSI: -83 dB
17:13:45    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:13:45    [V] [json:051]  
Size after shrink 132 bytes
17:15:01    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:15:01    [V] [json:051]  
Size after shrink 60 bytes
17:15:01    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:15:01    [V] [json:051]  
Size after shrink 132 bytes
17:15:01    [VV ][esp32_ble_tracker:575]    
Parse Result:
17:15:01    [VV ][esp32_ble_tracker:592]    
  Address: 01:C2:5C:AA:D3:6A (RANDOM)
17:15:01    [VV ][esp32_ble_tracker:594]    
  RSSI: -68
17:15:01    [VV ][esp32_ble_tracker:595]    
  Name: ''
17:15:01    [VV ][esp32_ble_tracker:609]    
  Manufacturer data: 01.09.20.02.02.F0.04.F2.8D.83.FD.03.4C.F1.AD.08.04.D6.77.E9.D8.2F.10.E1.49.2C.50 (27)
17:15:01    [VV ][esp32_ble_tracker:625]    
Adv data: 1E.FF.06.00.01.09.20.02.02.F0.04.F2.8D.83.FD.03.4C.F1.AD.08.04.D6.77.E9.D8.2F.10.E1.49.2C.50 (31)
17:15:01    [V] [bluetooth_proxy:023]   
Proxying packet from  - 01:C2:5C:AA:D3:6A. RSSI: -68 dB
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 60 bytes
17:20:39    [V] [esp32_ble_client:096]  
[78:9c:85:06:d1:f2] ESP_GATTC_CONNECT_EVT
17:20:39    [D] [esp32_ble_client:099]  
[78:9c:85:06:d1:f2] Unexpected conn_id in CONNECT_EVT: param conn=0, open conn=65535
17:20:39    [D] [esp32_ble_client:099]  
[78:9c:85:06:d1:f2] Unexpected conn_id in CONNECT_EVT: param conn=0, open conn=65535
17:20:39    [V] [esp32_ble_client:086]  
[78:9c:85:06:d1:f2] ESP_GATTC_OPEN_EVT
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 132 bytes
17:20:39    [V] [json:051]  
Size after shrink 132 bytes
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 132 bytes
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 136 bytes
17:20:39    [V] [json:051]  
Size after shrink 148 bytes
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 152 bytes
17:20:39    [V] [json:031]  
Attempting to allocate 512 bytes for JSON serialization
17:20:39    [V] [json:051]  
Size after shrink 148 bytes
17:20:43    [VV ][scheduler:196]    
Running interval '' with interval=60000 last_execution=4294947420 (now=40127)
17:20:43    [V] [esp32_ble_client:114]  
cfg_mtu status 0, mtu 512
17:20:43    [V] [esp32_ble_client:140]  
[78:9c:85:06:d1:f2] ESP_GATTC_SEARCH_CMPL_EVT
17:20:43    [V] [esp32_ble_client:140]  
[78:9c:85:06:d1:f2] ESP_GATTC_SEARCH_CMPL_EVT
17:20:43    [I] [esp32_ble_client:142]  
Service UUID: 0x1800
17:20:43    [I] [esp32_ble_client:143]  
  start_handle: 0x1  end_handle: 0x5
17:20:43    [I] [esp32_ble_client:143]  
  start_handle: 0x1  end_handle: 0x5
17:20:43    [I] [esp32_ble_client.service:057]  
 characteristic 0x2A00, handle 0x3, properties 0x2
17:20:43    [I] [esp32_ble_client.service:057]  
 characteristic 0x2A00, handle 0x3, properties 0x2
17:20:43    [I] [esp32_ble_client.service:057]  
 characteristic 0x2A01, handle 0x5, properties 0x2
17:20:43    [I] [esp32_ble_client:142]  
Service UUID: 0x1801
17:20:43    [I] [esp32_ble_client:143]  
  start_handle: 0x6  end_handle: 0x6

Additional information

I have 3 switchbot curtain, 2 yale ble locks on my home assistant integrations and using ble dongle on it.

[accelle17]

Here's what the uptime looks like after updating esphome firmwares and addon:

[accelle17]

I have removed the bluetooth_proxy: with the five ESPs I have that is used for ble_client sensor and uptime goes ok. I have created another bluetooth_proxy using the . The uptime is ok too but it's going unavailable probably due to the recoupling of BT and wifi antenna on arduino side.

[12:09:51][W][api.connection:083]: Home Assistant 2022.10.0 (::FFFF:C0A8:1401): Connection closed [12:09:51][D][api:102]: Accepted ::FFFF:C0A8:1401 [12:09:51][D][api.connection:917]: Home Assistant 2022.10.0 (::FFFF:C0A8:1401): Connected successfully [12:10:16][W][api.connection:083]: Home Assistant 2022.10.0 (::FFFF:C0A8:1401): Connection closed [12:10:16][D][api:102]: Accepted ::FFFF:C0A8:1401 [12:10:16][D][api.connection:917]: Home Assistant 2022.10.0 (::FFFF:C0A8:1401): Connected successfully

[lolorc]

I also have the same issue. it reboots quite often with 2 connections to the api (HA & logs) but it still reboots without webserver and only hass connected to the api port.

[accelle17]

After moving from tplink UB500 (I know it's not on the supported device for HA ble) to ugreen cm390, and upgrading proxmox from 6.2 to 7.2, the error doesn't appear on the dedicated esphome active bluetooth proxy. I was using ub500 because HA cannot detect the cm390 even when on HAOS 9. I am still seeing API disconnects when the esp32 has different entities (e.g. ble_clients) and trying to connect to August smart lock pro 3rd gen.

[accelle17]

Spoke too soon, I have flashed another dedicated active bluetooth proxy on a wroom esp32 using the same code as the one on quinled esp32 and getting API disconnects.

Update: Adjusted the interval and window to 1100ms and the API disconnects were gone on the dedicated proxy. The one with ble_client already has that interval and window but still disconnects.

[nagyrobi]

Add to your config some memory sensors, and flash again:

debug:

sensor:
- platform: template
  name: Free HEAP
  lambda: return heap_caps_get_free_size(MALLOC_CAP_INTERNAL);
  icon: "mdi:memory"
  entity_category: diagnostic
  state_class: measurement
  unit_of_measurement: "b"
  update_interval: 60s
- platform: uptime
  name: Uptime
- platform: debug
  free:
    name: Free MEM

Wait for some time and look at the graphs.

[probot-esphome[bot]]

Hey there @jesserockz, mind taking a look at this issue as it has been labeled with an integration (bluetooth_proxy) you are listed as a code owner for? Thanks! _{^{(message by CodeOwnersMention)}}

[Laccolith]

I'm seeing the same issue connecting to an airthings wave plus since updating to 2022.9.3. If I have my esp32 connect to it using the airthings platform, the esp32 device seems to constantly crash until it stops responding all together. If I use it as an active proxy and use the airthings_ble home assistant integration to connect to it, the api connection to home assistant keeps disconnecting, though the esp32 doesn't crash.

Log of the airthings platform: https://gist.github.com/Laccolith/d9edc557ca43b009bf8723b8f2de339f Log of the active ble proxy: https://gist.github.com/Laccolith/791bd66f9865f6e0654acb4c4450041a

[accelle17]

I notice the same with the wroom esp32 I flashed and interface with Yale/August lock. However, the esp32 I used for switchbot has been stable. I will check the memory tomorrow.

[accelle17]

Here's what I got (1st disconnect started at 15:46 when I try to control yale lock and then it continuously disconnects the API):

logs_btproxy_garage_logs (1).txt

[lolorc]

the fix from https://github.com/esphome/issues/issues/3667#issuecomment-1279687007 fixes it for me.

[accelle17]

I updated to 2022.10 and still keeps on disconnecting (not that frequent anymore).

Here are the logs. logs_btproxy_garage_logs (3).txt

I noticed the crash after it tries to read the yale lock when I try to control it. Afterwards, HA won't try to use that proxy until I reboot it. The reboot/safe mode doesn't work, indicating an error "connection not done". Need to reload that device integration before reboot/safe mode can work.

[lolorc]

I should admit it crashed a few hours after I posted my last comment. unable to reflash it to make it restart, I'll have to unpower it when I return home.

[nagyrobi]

Please post your entire config.

[accelle17]

#
substitutions:
  board: esp32dev
  device_name: btproxy_garage
  friendly_name: btproxy_garage

esphome:
  name: ${device_name}
  platform: ESP32
  board: ${board}
  name_add_mac_suffix: false

packages:
  wifi: !include common/wifi_lite.yaml
  bt_proxy: !include common/bluetooth_proxy.yaml

WIFI_LITE.YAML:

wifi: 
  ssid: !secret iotssid
  password: !secret iotssid_pw

BLUETOOTH_PROXY.YAML:

api:
  reboot_timeout: 0s
logger:
  level: debug
ota:
improv_serial:
captive_portal:

esp32_ble_tracker:
  scan_parameters:
    interval: 1100ms
    window: 1100ms
    active: true

button:
  - platform: safe_mode
    name: ${device_name}_safemode_boot
    entity_category: diagnostic

switch:
  - platform: restart
    name: '${friendly_name} REBOOT'
    entity_category: diagnostic
bluetooth_proxy:
    active: true

sensor:
  - platform: uptime
    name: ${friendly_name} uptime
    filters:
      - lambda: return x / 60;
    unit_of_measurement: "min"

  - platform: template
    name: ${friendly_name} free heap
    lambda: return heap_caps_get_free_size(MALLOC_CAP_INTERNAL);
    icon: "mdi:memory"
    entity_category: diagnostic
    state_class: measurement
    unit_of_measurement: "b"
    update_interval: 60s

  - platform: debug
    free:
        name: ${friendly_name} free mem

debug:

[lolorc]

mine is

esphome:
  name: esp32_04
  project:
    name: esphome.bluetooth-proxy
    version: "1.0"

esp32:
  board: esp32dev
  framework:
    type: arduino

wifi:
  ssid: "ssid"
  password: "password"
  use_address: ip

debug:                                                                         
  update_interval: 5s           

mqtt:
  broker: ip

logger:
  level: VERBOSE

api:

ota:
  password: "password"

dashboard_import:
  package_import_url: github://esphome/bluetooth-proxies/esp32-generic.yaml@main

bluetooth_proxy:
  active: true

esp32_ble_tracker:
  scan_parameters:
    active: false

switch:
  - platform: safe_mode
    name: "esp32_04 safe_mode"
  - platform: restart
    name: "esp32_04 restart"
sensor:
  - platform: debug    
    free:          
      name: "esp32_04 Heap Free"
    block:            
      name: "esp32_04 Heap Max Block"
    loop_time:     
      name: "esp32_04 Loop Time"

  - platform: uptime
    name: esp32_04_uptime
  - platform: wifi_signal
    name: "esp32_04_rssi"
    update_interval: 60s

yep my configs need some factoring

this esp is in next to a street, it's catching from devices passing by in front of my house (cars, phones, etc... HomeAssistant with "track_new_devices: true" is getting flooded) I'll try to setup another one that I'll put next to this one, just in case they could be crashing at the exact same time. And I'll also try to set one in a "closet" :-)

[nagyrobi]

Verbose logging and debug always eat up resources. Try logging set to INFO. Do you need both MQTT and API?

[PaleoW]

Hi guys,

Are any of you with crashes using grouped Switchbot Curtains devices ?

I had similar crashes, and it was caused by a misconfiguration in my HA instance. I was sending Open/Close commands to both units of a group, and it seems to confuse the bluetooth proxies.

Sending the bluetooth commands to the "Master" unit of the group only resolved all my issues.

[lolorc]

I've just remotely flashed with mqtt disabled, logger set to INFO and I've also disabled debug. https://github.com/esphome/esphome/pull/3905 has been helping significantly, so I guess it's going take time to reproduce. I my case I'm not having any active connection with any devices. Thanks, will keep you informed

[nagyrobi]

Note that Bluetooth Proxy currently only supports active connection with one single Bluetooth device.

[accelle17]

removing the debugs made it better. but I sometimes keep getting api disconnects when trying to control yale august lock (it works once-twice). After the api disconnect, I have to reload the esphome integration for reboot to work due to connection not done. Perhaps the disconnects is a bug on the yale ble integration itself but I was hoping the api reconnect will work after the crash. I had also tried the reboot timeout: 0s on the api.

[lolorc]

just to let you know: since then, I've not had any reboot or issue whatsoever, more than 18days uptime, in my use case I'm not having any active connections at all. Cheers

I've just remotely flashed with mqtt disabled, logger set to INFO and I've also disabled debug. esphome/esphome#3905 has been helping significantly, so I guess it's going take time to reproduce. I my case I'm not having any active connection with any devices. Thanks, will keep you informed