esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
293 stars 36 forks source link

bluetooth_proxy stop working after reboot #6270

Open tomaszduda23 opened 2 months ago

tomaszduda23 commented 2 months ago

The problem

Every a few reboots bluetooth_proxy stop reporting any data. It can be solved by rebooting device. When the issue occurs log [bluetooth_proxy:062]: Proxying packet from is never printed.

Which version of ESPHome has the issue?

2024.2.2

What type of installation are you using?

Docker

Which version of Home Assistant has the issue?

No response

What platform are you using?

ESP32

Board

No response

Component causing the issue

No response

Example YAML snippet

external_components:
  source: github://pr#7382
  components: [ bluetooth_proxy ]

substitutions:
  esp_name: esp

esphome:
  name: ${esp_name}

esp32:
  board: esp32doit-devkit-v1

<<: !include .common_wifi_api.yaml
<<: !include .common_time.yaml

logger:
  level: VERBOSE
  logs:
    bluetooth_proxy.component: VERBOSE
    esp32_ble.component: DEBUG

esp32_ble:
  io_capability: keyboard_only

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

bluetooth_proxy:
  # active: true

ble_client:
- mac_address: "x:x:x:x:x:x"
  id: pvvx_ble_display
  on_passkey_request:
    then:
      - logger.log: "Authenticating with passkey"
      - ble_client.passkey_reply:
          id: pvvx_ble_display
          passkey: xxxxxx

display:
- platform: pvvx_mithermometer
  ble_client_id: pvvx_ble_display
  update_interval: 24h
  validity_period: 0s
  disconnect_delay: 30s
  time_id: homeassistant_time
  id: display_bathroom

Anything in the logs that might be useful for us?

Incorrect logs:


[10:37:22][C][bluetooth_proxy:094]: Bluetooth Proxy:
[10:37:22][C][bluetooth_proxy:095]:   Active: NO
[10:37:22][C][bluetooth_proxy:096]:   Connections: 0
[10:37:22][C][bluetooth_proxy:097]:   Raw advertisements: YES
[10:37:22][C][display.pvvx_mithermometer:011]: PVVX MiThermometer display:
[10:37:22][C][display.pvvx_mithermometer:012]:   MAC address           : xx:xx:xx:xx:xx:xx
[10:37:22][C][display.pvvx_mithermometer:013]:   Service UUID          : 00001F10-0000-1000-8000-00805F9B34FB
[10:37:23][C][display.pvvx_mithermometer:014]:   Characteristic UUID   : 00001F1F-0000-1000-8000-00805F9B34FB
[10:37:23][C][display.pvvx_mithermometer:015]:   Auto clear            : YES
[10:37:23][C][display.pvvx_mithermometer:017]:   Set time on connection: YES
[10:37:23][C][display.pvvx_mithermometer:019]:   Disconnect delay      : 30000ms
[10:37:23][C][display.pvvx_mithermometer:020]:   Update Interval: 86400.0s
[10:37:23][C][homeassistant.time:010]: Home Assistant Time:
[10:37:23][C][homeassistant.time:011]:   Timezone: 'CET-1CEST,M3.5.0,M10.5.0/3'
[10:37:23][C][esp32_ble:374]: ESP32 BLE:
[10:37:23][C][esp32_ble:376]:   MAC address: A4:CF:12:44:B0:A6
[10:37:23][C][esp32_ble:377]:   IO Capability: keyboard_only
[10:37:23][C][esp32_ble_tracker:645]: BLE Tracker:
[10:37:23][C][esp32_ble_tracker:646]:   Scan Duration: 300 s
[10:37:23][C][esp32_ble_tracker:647]:   Scan Interval: 1100.0 ms
[10:37:23][C][esp32_ble_tracker:648]:   Scan Window: 1100.0 ms
[10:37:23][C][esp32_ble_tracker:649]:   Scan Type: ACTIVE
[10:37:23][C][esp32_ble_tracker:650]:   Continuous Scanning: True
[10:37:23][C][ble_client:027]: BLE Client:
[10:37:23][C][ble_client:028]:   Address: xx:xx:xx:xx:xx:xx
[10:37:23][C][ble_client:029]:   Auto-Connect: TRUE
[10:56:50][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[10:56:50][D][esp32_ble_tracker:266]: Starting scan...
[10:56:50][V][esp32_ble:314]: (BLE) gap_event_handler - 2
[10:56:50][V][esp32_ble:314]: (BLE) gap_event_handler - 7

Correct logs:

[11:00:42][C][bluetooth_proxy:094]: Bluetooth Proxy:
[11:00:42][C][bluetooth_proxy:095]:   Active: NO
[11:00:42][C][bluetooth_proxy:096]:   Connections: 0
[11:00:42][C][bluetooth_proxy:097]:   Raw advertisements: YES
[11:00:42][C][display.pvvx_mithermometer:011]: PVVX MiThermometer display:
[11:00:42][C][display.pvvx_mithermometer:012]:   MAC address           : xx:xx:xx:xx:xx:xx
[11:00:42][C][display.pvvx_mithermometer:013]:   Service UUID          : 00001F10-0000-1000-8000-00805F9B34FB
[11:00:42][C][display.pvvx_mithermometer:014]:   Characteristic UUID   : 00001F1F-0000-1000-8000-00805F9B34FB
[11:00:42][C][display.pvvx_mithermometer:015]:   Auto clear            : YES
[11:00:42][C][display.pvvx_mithermometer:017]:   Set time on connection: YES
[11:00:42][C][display.pvvx_mithermometer:019]:   Disconnect delay      : 30000ms
[11:00:42][C][display.pvvx_mithermometer:020]:   Update Interval: 86400.0s
[11:00:42][C][homeassistant.time:010]: Home Assistant Time:
[11:00:42][C][homeassistant.time:011]:   Timezone: 'CET-1CEST,M3.5.0,M10.5.0/3'
[11:00:42][C][esp32_ble:374]: ESP32 BLE:
[11:00:42][C][esp32_ble:376]:   MAC address: xx:xx:xx:xx:xx:xx
[11:00:42][C][esp32_ble:377]:   IO Capability: keyboard_only
[11:00:42][C][esp32_ble_tracker:645]: BLE Tracker:
[11:00:42][C][esp32_ble_tracker:646]:   Scan Duration: 300 s
[11:00:42][C][esp32_ble_tracker:647]:   Scan Interval: 1100.0 ms
[11:00:42][C][esp32_ble_tracker:648]:   Scan Window: 1100.0 ms
[11:00:42][C][esp32_ble_tracker:649]:   Scan Type: ACTIVE
[11:00:42][C][esp32_ble_tracker:650]:   Continuous Scanning: True
[11:00:42][C][ble_client:027]: BLE Client:
[11:00:42][C][ble_client:028]:   Address: xx:xx:xx:xx:xx:xx
[11:00:43][C][ble_client:029]:   Auto-Connect: TRUE
[11:00:44][V][esp32_ble:342]: (BLE) gattc_event [esp_gatt_if: 4] - 40
[11:00:44][V][esp32_ble_client:121]: [0] [xx:xx:xx:xx:xx:xx] gattc_event_handler: event=40 gattc_if=4
[11:00:44][D][esp32_ble_client:110]: [0] [xx:xx:xx:xx:xx:xx] ESP_GATTC_CONNECT_EVT
[11:00:45][V][esp32_ble:342]: (BLE) gattc_event [esp_gatt_if: 4] - 2
[11:00:45][V][esp32_ble_client:121]: [0] [xx:xx:xx:xx:xx:xx] gattc_event_handler: event=2 gattc_if=4
[11:00:45][D][esp32_ble_client:110]: [0] [xx:xx:xx:xx:xx:xx] ESP_GATTC_OPEN_EVT
[11:00:45][V][display.pvvx_mithermometer:027]: [xx:xx:xx:xx:xx:xx] Connected successfully!
[11:00:45][D][esp32_ble_tracker:266]: Starting scan...
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 2
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 7
[11:00:45][D][api:102]: Accepted 192.168.0.20
[11:00:45][W][component:214]: Component api took a long time for an operation (0.06 s).
[11:00:45][W][component:215]: Components should block for at most 20-30ms.
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][D][time:049]: Synchronized time: 2024-09-23 11:00:45
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:45][V][bluetooth_proxy:062]: Proxying packet from xx:xx:xx:xx:xx:xx, length 40. RSSI: -82 dB
[11:00:45][V][bluetooth_proxy:064]: Proxying 1 packets
[11:00:46][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:46][V][esp32_ble:314]: (BLE) gap_event_handler - 3
[11:00:46][V][bluetooth_proxy:062]: Proxying packet from xx:xx:xx:xx:xx:xx, length 0. RSSI: -71 dB
[11:00:46][V][bluetooth_proxy:062]: Proxying packet from xx:xx:xx:xx:xx:xx, length 40. RSSI: -81 dB
[11:00:46][V][bluetooth_proxy:064]: Proxying 2 packets
[11:00:46][V][esp32_ble:314]: (BLE) gap_event_handler - 20
[11:00:46][V][esp32_ble:314]: (BLE) gap_event_handler - 8

Additional information

No response

derMicro commented 2 months ago

For example, you can update to 2024.9 You can leave the tracker running in its default configuration. (Remove interval and window) You can activate the scan only when the WLAN is connected, which works very well with single-core chips, for example.

My working config

...

api:
  encryption:
    key: "xxx"
  on_client_connected:
    - esp32_ble_tracker.start_scan:
        continuous: true

ota:
  platform: esphome
  password: "xxx"

wifi:
  networks:
  - ssid: !secret wifi_ssid
    password: !secret wifi_password
    hidden: True

esp32_ble_tracker:
  scan_parameters:
    continuous: false

bluetooth_proxy:
  active: true

...
tomaszduda23 commented 1 week ago

2024.9.2 has the same problem.