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

ESP32 BT Classic component #4736

Draft
wants to merge 6 commits into
base: dev
Choose a base branch
from

Conversation

RoboMagus
Copy link
Contributor

@RoboMagus RoboMagus commented Apr 24, 2023

What does this implement/fix?

BLE Presence is great, but cannot work with all devices. I've had a ported, slimmed down version of Andrewjfreyer's monitor running on a couple of ESP32's locally for over a year to take care of my BT (classic) presence sensing needs.

This PR brings the functionality of my first attempt at porting the BT presence monitor (ESP32-MQTT-Bluetooth-Monitor) to ESPHome.

In a nutshell, BT Classic devices are detected by performing a device name query for a known MAC address. If the device responds, it is present. If it does not respond in the allowed number of attempts, it is assumed absent.

This PR is currently kept W.I.P. untill the following items are dealt with:

  • Working implementation of Scan Triggers and Scan Result Listners
  • Documentation for esphome-docs
  • Tested with ESP-IDF framework
  • Binary device presence sensor implementation
  • Tests are added

Note:
Getting the ESP32 to setup using the correct BT Mode using esp-idf turned out to require some refactoring of other (ble) components. For this purpose I have extracted common definitions / functionality into a separate component: esp32_bt_common, though I'm not sure if that would be the best solution. Open to suggestions! 😉

Types of changes

  • Bugfix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • Other

Related issue or feature (if applicable): N/a

Pull request in esphome-docs with documentation (if applicable): esphome/esphome-docs#2873

Test Environment

  • ESP32
  • ESP32 IDF
  • ESP8266 incompatible
  • RP2040 incompatible

Example entry for config.yaml:

# Example config.yaml

light:
  # Led for blinking when BT Scan is active:
  - platform: status_led
    id: state_led
    pin: GPIO2

esp32_ble_tracker:

binary_sensor:
  # BT Classic can run side-by-side with BLE!
  - platform: ble_presence
    mac_address: AA:BB:CC:DD:EE:F0
    name: FitBit Presence

  - platform: bt_classic_presence
    name: Galaxy Phone Presence
    mac_address: AA:BB:CC:DD:EE:F1
    num_scans: 5
    update_interval: 60s

  - platform: bt_classic_presence
    name: Galaxy Watch Presence
    mac_address: AA:BB:CC:DD:EE:F2
    num_scans: 3
    update_interval: 30s

esp32_bt_classic:
  on_scan_start:
    - light.turn_on:
        id: state_led
  on_scan_result:
    # Can listen for ANY scan result:
    - then:
      - homeassistant.event:
          event: esphome.bt_scan_result
          data:
            node: "Test-esp32"
            status: !lambda "return status.str();"
            name: !lambda "return name;"
            address: !lambda "return address.str();"
      - light.turn_off:
          id: state_led
   # Can listen for specific MAC addresses:
   - mac_address:
       - AA:BB:CC:DD:EE:F0
       - AA:BB:CC:DD:EE:F2
     then:
       lambda: |-
         ESP_LOGI("BT_SCAN_RESULT", "Result for one of the Watches!\n  address: %s\n  name: %s\n  status: %s (%d)", address.c_str(), name, status.c_str(), status.bt_status());

Checklist:

  • The code change is tested and works locally.
  • Tests have been added to verify that the new code works (under tests/ folder).

If user exposed functionality or configuration variables are added/changed:

@probot-esphome
Copy link

Hey there @RoboMagus,
Thanks for submitting this pull request! Can you add yourself as a codeowner for this integration? This way we can notify you if a bug report for this integration is reported.
In __init__.py of the integration, please add:

CODEOWNERS = ["@RoboMagus"]

And run script/build_codeowners.py

(message by NeedsCodeownersLabel)

@nagyrobi
Copy link
Member

Can this integrate with HA as a drevice tracker, so that eg. a tracked bt mac address could be selected/registered to the user to contribute to the presence state of that user?

@RoboMagus
Copy link
Contributor Author

I guess that that should be possible, though I'm not sure if esphome can already expose device tracker entities.
My intention is definitely to have this be a home assistant centric integration myself. I.e. Not make entities in esphome specific but rather scan and listen all orchestrated within HA.

@RoboMagus
Copy link
Contributor Author

@nagyrobi After finding feature-request/204 I've done some minor tests that indicate it is possible to have these BT Classic scan results trigger a device_tracker update. Using the following snippet inside either a HA automation, or using an ESPHome service call:

service: device_tracker.see
data:
  host_name: TestDevice
  mac: aa:bb:cc:dd:ee:f3
  location_name: office
  source_type: bluetooth

Though for me personally it is a problem that the entitiy that this creates inside HA does not have a unique_id and as such it is not possible to edit the entity. Furthermore, not knowing beforehand what the device should be called (only providing a MAC address) causes the entity_id to forever be stuck as e.g. device_tracker.aa_bb_cc_dd_ee_ff.

However, these newly created entities can then be linked to a person to see if they are at home.

@nagyrobi
Copy link
Member

However, these newly created entities can then be linked to a person to see if they are at home.

This is important and worth to be documented.

@RoboMagus
Copy link
Contributor Author

In what sense though? All of the options that are currently provided are described in the esphome-docs PR:

  • binary_sensor
  • external trigger options to start scanning
  • use of scan_results for triggering external stuff

The external things in this case are all of the options EspHome provides, which should already be documented right?
At its current state there are a lot of possibilities, though none of them provide an automagical solution for presence detection. Documenting all of these options would provide more clutter than aid for users who'd want to configure a device of their own.

@nagyrobi
Copy link
Member

That's exactly what the Cookbook part of the site is for. You could link to the examples there.

@RoboMagus RoboMagus marked this pull request as ready for review April 26, 2023 09:33
@probot-esphome
Copy link

Hey there @jesserockz, mind taking a look at this pull request as it has been labeled with an integration (esp32_ble) you are listed as a code owner for? Thanks!
Hey there @jesserockz, mind taking a look at this pull request as it has been labeled with an integration (esp32_ble_server) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)

@RoboMagus
Copy link
Contributor Author

I'm reverting the state of this Pr back to draft for now.
Over some long term testing I have found some sporadic issues with the Espressif BT stack, where it rapidly fails each scan without indication that the stack itself is in error state.

@RoboMagus RoboMagus marked this pull request as draft June 3, 2023 14:32
@github-actions
Copy link
Contributor

github-actions bot commented Sep 2, 2023

There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. Thank you for your contributions.

@github-actions github-actions bot added the stale label Sep 2, 2023
@nagyrobi nagyrobi added not-stale Won't go stale and removed stale labels Sep 2, 2023
@krambriw
Copy link

krambriw commented Jan 6, 2024

Hey RoboMagus,
I have enjoyed testing this component running with ESPHome on an ESP32. It is normally working fine and I have just added one Iphone entry to be scanned for.
When it is found, it is correctly reported, no problems. But if I move away outside reach or simply turn off bluetooth in my phone, the whole firmware seems to be blocked after a number of scan attempts. When it is blocked, the ESPHome firmware does not respond to any commands (in my case via MQTT). I even implemented a reboot timer but it is not able to fire as I would expect. Once the phone again is within reach, the blocking is released and I can see that the ESPHome firmware is restarting. After that normal scans are executed until next time the phone is outside reach

Do you have any possibility to check why the whole device gets blocked as described above?
Best regards, Walter

@krambriw
Copy link

krambriw commented Jan 7, 2024

Added my Ipad to the list. But as soon my Iphone is out of reach, the ESPHome firmware freezes or waits. As soon as my Iphone is within reach, the freeze ends and the ESPHome firmware continues execution. I would have expected that if you have defined two or more devices (iphones, ipads), the scan would continue with the next etc and not wait "forever"

@RoboMagus
Copy link
Contributor Author

Hey @krambriw, thank you for testing this component as well!

What you're describing are exactly the edge-cases that caused my to mark this PR as draft again after some time of development. What exactly is causing these issues I'm not quite sure about, but its the ESP32's BT stack that starts producing garbage at some point. From what I've found is that resetting the BT stack has no impact, but a full reset of the device often solves the weird BT stack responses.

Over the holidays I've resumed testing with newer frameworks and though this looks promising so far (no BT stack issues in about 3 days of up-time) I do need to perform more testing before I'd consider the whole thing to be stable enough for integration.
(Kind of a shame really because this bluetooth presence has been part of my home presence detection for well over a year and much faster than WiFi or GPS based detection could ever be. But with any randomly recurring inexplainable issues not something one can fully rely on.)

If you're able to test on ESP-IDF versions greater than 5.1.0 and report back what this does for you that'd be great!
(Needs platform_version >= 6.4.0 as well for the esp tooling. See snippet: )

esp32:
  framework:
    type: esp-idf
    version: 5.1.2
    platform_version: 6.4.0

Also, could you set logging to VERBOSE and provide logging of your findings?

@krambriw
Copy link

krambriw commented Jan 7, 2024

Hello and thank you!
Made the changes and it is running fine now, no freezing so far (scanning continous as expected now even if one device cannot be found, it continues with the next and so on). I will let it run this way over night
Best regards, Walter

@krambriw
Copy link

krambriw commented Jan 8, 2024

So it freezed again. Below is part of the log with my comments inserted. My feeling, just a feeling, is that everything works fine as expected as long as ALL listed devices can be found during the scans. But as soon as one is not found, the scan continues and finds the others but after a while, the scan stopps completely and (part of) the firmware freezes or stops in a kind of waiting state

Like in my case, it freezes at 23:56 and just waits. During the following time period the ESPHome is not responding to any mqtt commands. The bluetooth on my ipad is still on but since it is off in my iphone the scan seems halted. At 06:35 bluetooth in my iphone was turned on again. The freeze automatically ended, the ESPHome rebooted, scan started and both my iphone and ipad were found at the first scan

Would it not be possible to internally detect this freeze state and then simpy reboot to restart?

Best regards, Walter

(lines with 'blue' is just turning the LED on/off, lines with blrestart timer is just a watchdog that is supposed to fire & reboot if the the esp would stop executing but it is also not working while the whole firmware is freezed)

INFO Upload took 11.77 seconds, waiting for result...
INFO OTA successful
INFO Successfully uploaded program.
INFO Starting log output from btclassic/debug
INFO Connected to MQTT broker!
[21:24:04][I][app:134]: Rebooting safely...
[21:24:07][I][mqtt:274]: MQTT Connected!
[21:24:07][D][esp-idf:000]: I (4364) wifi:
[21:24:07][D][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 1
[21:24:07][D][esp-idf:000]:

[21:24:07][I][app:062]: setup() finished successfully!
[21:24:07][I][app:102]: ESPHome version 2023.12.2 compiled on Jan 7 2024, 21:23:11
[2

21:24:04 Updated and uploaded version started. Both my iphone and ipad where found during scans

[21:24:09][D][esp32_bt_classic:136]: Start scanning for 00:11:22:33:44:55
[21:24:09][D][switch:012]: 'blue' Turning ON.
[21:24:09][D][switch:055]: 'blue': Sending state ON
[21:24:09][D][main:225]: Restarting blrestart timer
[21:24:12][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 9 scans remaining
[21:24:12][D][esp32_bt_classic:231]: Scan complete. No more devices left to scan.
[21:24:12][D][binary_sensor:036]: 'Walters Iphone Presence': Sending state ON
[21:24:12][D][switch:016]: 'blue' Turning OFF.
[21:24:12][D][switch:055]: 'blue': Sending state OFF
[21:24:12][D][main:120]: Stopping blrestart timer
[21:24:19][D][esp32_bt_classic:136]: Start scanning for 55:44:33:22:11:00
[21:24:19][D][switch:012]: 'blue' Turning ON.
[21:24:19][D][switch:055]: 'blue': Sending state ON
[21:24:19][D][main:225]: Restarting blrestart timer
[21:24:20][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[21:24:20][D][esp32_bt_classic:231]: Scan complete. No more devices left to scan.

21:25:56 iphone was not found since I turned bluetooth off in the phone

[21:25:56][D][esp32_bt_classic:209]: Device '00:11:22:33:44:55' scan result: ESP_BT_STATUS_FAIL (1)
[21:26:01][D][esp32_bt_classic:217]: Device '00:11:22:33:44:55' not found. 4 scans remaining

22:51:35 was last time it found my iPad

[22:51:00][D][esp32_bt_classic:136]: Start scanning for 55:44:33:22:11:00
[22:51:00][D][switch:012]: 'blue' Turning ON.
[22:51:00][D][switch:055]: 'blue': Sending state ON
[22:51:00][D][main:225]: Restarting blrestart timer
[22:51:01][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining

23:05:04 last entry in log, firmware freeze, ESPHome freeze, not possible to communicate via mqtt

[23:04:59][D][esp32_bt_classic:136]: Start scanning for 55:44:33:22:11:00
[23:04:59][D][switch:012]: 'blue' Turning ON.
[23:04:59][D][switch:055]: 'blue': Sending state ON
[23:04:59][D][main:225]: Restarting blrestart timer
[23:05:04][D][esp32_bt_classic:209]: Device '55:44:33:22:11:00' scan result: ESP_BT_STATUS_FAIL (1)
[23:05:04][D][esp32_bt_classic:217]: Device '55:44:33:22:11:00' not found. 66 scans remaining
[23:05:04][D][switch:016]: 'blue' Turning OFF.
[23:05:04][D][switch:055]: 'blue': Sending state OFF
[23:05:04][D][main:120]: Stopping blrestart timer
[23:05:04][D][esp32_bt_classic:136]: Start scanning for 00:11:22:33:44:55
[23:05:04][D][switch:012]: 'blue' Turning ON.
[23:05:04][D][switch:055]: 'blue': Sending state ON
[23:05:04][D][main:225]: Restarting blrestart timer
[06:35:52][I][mqtt:274]: MQTT Connected!
[06:35:52][I][app:062]: setup() finished successfully!
[06:35:52][I][app:102]: ESPHome version 2023.12.2 compiled on Jan 7 2024, 11:09:33

06:35:53 turning bluetooth on in my iPhone, ESPHome restarts and scanning starts, my iphone and ipad are now found again

[06:36:23][D][esp32_bt_classic:136]: Start scanning for 00:11:22:33:44:55
[06:36:23][D][switch:012]: 'blue' Turning ON.
[06:36:23][D][switch:055]: 'blue': Sending state ON
[06:36:23][D][main:215]: Restarting blrestart timer
[06:36:27][I][esp32_bt_classic:204]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[06:36:27][D][switch:016]: 'blue' Turning OFF.
[06:36:27][D][switch:055]: 'blue': Sending state OFF
[06:36:27][D][main:114]: Stopping blrestart timer
[06:36:27][D][esp32_bt_classic:136]: Start scanning for 55:44:33:22:11:00
[06:36:27][D][switch:012]: 'blue' Turning ON.
[06:36:27][D][switch:055]: 'blue': Sending state ON
[06:36:27][D][main:215]: Restarting blrestart timer
[06:36:27][I][esp32_bt_classic:204]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[06:36:27][D][esp32_bt_classic:231]: Scan complete. No more devices left to scan.

@RoboMagus
Copy link
Contributor Author

So with the freezing of the device you mean that the whole ESPHome device becomes unresponsive? I first assumed it'd be only the Bluetooth scanning parts, as that would align with the issues I ran into myself.

Would it not be possible to internally detect this freeze state and then simply reboot to restart?

I did implement a crude BT stack error detection in my local code-base for just this purpose, but simply restarting an ESP device not something I'd want anyone to rely on considering any other tasks that this device could be running. Based on current testing with newer IDF frameworks this error state previously observed seems to have been resolved. Though this probably won't help you much right now, as the symptoms you've shared indicate another issue.

Could you share the full device config you're using to test this component with, as well as the specific ESP device you're using?
As the BT stack is a HUGE memory hog, my best guess at the moment is that memory allocation may fail at some point causing your device to lock up, being no longer able to communicate. But if that's the case, wireless / remote logs won't show this occurring. Are you able to re-do these tests with the device hooked up to your PC and provide logging using USB / UART instead?

To check how close your device is to hitting memory issues, could you also please add sensors from the debug component to your config? Values that these sensors expose could help in figuring out what exactly is going on.

Thanks for your testing btw, even though the issues you're facing could be different from what I'm expecting its good to know if there are some incompatibilities with the BT Classic component so that these can be documented :)

@krambriw
Copy link

krambriw commented Jan 8, 2024

So with the freezing of the device you mean that the whole ESPHome device becomes unresponsive?

Yes, exactly. But it can't be completely dead since it recovers as soon as I turns the bluetooth in the phone on again. So it is listening somehow. Once it then moves on it reboots, I think this is due to the setting for the mqtt server connection (reboot timeout: 5 min)
I will re-do the test accordingly, add debug components and provide the log as .txt file from usb

Attached is my .yaml file as .txt with the modifications (scanning every 10 sec to stress test)

Best regards, Walter

btclassic.yaml.txt

@krambriw
Copy link

krambriw commented Jan 9, 2024

An update. Happy to report, it has worked just perfectly since I made the update and restarted the device yesterday. It does not freeze anymore, I can send and receieve messages via MQTT. So I cannot see the problem anymore. What I additionally did in the .yaml file was commented out the things controlling the blue LED and the restart timer, don't know if this helped to save some memory or so. Attached is the updated .yaml

I have also pasted some parts of the log below, including some debug sensor values (free and fragmentation could however not be used since I have an ESP32)

I will let it run like this and we will see how it behaves but for the moment, everything looks ok

Best regards, Walter

[08:24:34][D][sensor:093]: 'Free PSRAM': Sending state 0.00000 B with 0 decimals of accuracy
[08:24:34][V][mqtt:473]: Publish(topic='btclassic/sensor/free_psram/state' payload='0' retain=1)
[08:24:35][V][esp32_bt_classic:154]: Found AA:BB:CC:DD:EE:F0 already in active scan list. Increased scans remaining to 174
[08:24:37][V][esp32_bt_classic:154]: Found AA:BB:CC:DD:EE:F0 already in active scan list. Increased scans remaining to 175
[08:24:39][V][esp32_bt_classic:175]: (BT) gap_event_handler - 12
[08:24:39][D][esp32_bt_classic:209]: Device 'AA:BB:CC:DD:EE:F0' scan result: ESP_BT_STATUS_FAIL (1)
[08:24:39][D][esp32_bt_classic:217]: Device 'AA:BB:CC:DD:EE:F0' not found. 174 scans remaining
[08:24:39][V][mqtt:473]: Publish(topic='btclassic/response' payload='Found during scan: , 34:42:62:14:60:75' retain=0)
[08:24:39][D][esp32_bt_classic:136]: Start scanning for AA:BB:CC:DD:EE:F0
[08:24:39][D][switch:012]: 'blue' Turning ON.
[08:24:39][V][sensor:043]: 'Heap Max Block': Received new state 15360.000000
[08:24:39][D][sensor:093]: 'Heap Max Block': Sending state 15360.00000 B with 0 decimals of accuracy
[08:24:39][V][mqtt:473]: Publish(topic='btclassic/sensor/heap_max_block/state' payload='15360' retain=1)
[08:24:39][V][sensor:043]: 'Loop Time': Received new state 59.000000
[08:24:39][D][sensor:093]: 'Loop Time': Sending state 59.00000 ms with 0 decimals of accuracy
[08:24:39][V][mqtt:473]: Publish(topic='btclassic/sensor/loop_time/state' payload='59' retain=1)
[08:24:39][V][sensor:043]: 'Free PSRAM': Received new state 0.000000
[08:24:39][D][sensor:093]: 'Free PSRAM': Sending state 0.00000 B with 0 decimals of accuracy
[08:24:39][V][mqtt:473]: Publish(topic='btclassic/sensor/free_psram/state' payload='0' retain=1)

btclassic.yaml.txt

@krambriw
Copy link

Unfortunately there is something not working. After hours in operation, the scanning does not find my devices any longer. The ESP is not frozen, it still reports log events via MQTT and it can receive commands

Below is the log from the time when it stopped working. It did find my iphone perfectly until I left my house (bluetooth in my ipad was off at that time). A short while thereafter, it seems it restarted for some reason. Later when I returned home, it could not find my phone. I then turned on bluetooth in my ipad but same result, it was not able to find it either. I then did reboot the ESP and it finds both. Don't know if this helps

[09:57:58][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[09:58:11][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[09:58:41][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 12 scans remaining
[09:58:47][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[09:59:01][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[09:59:08][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[10:16:46][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[10:20:16][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[10:27:52][I][mqtt:274]: MQTT Connected!
[10:27:52][I][app:062]: setup() finished successfully!
[10:27:52][I][app:102]: ESPHome version 2023.12.2 compiled on Jan 10 2024, 07:38:25
[10:28:58][I][esp-idf:000]: I (69992) wifi:
[10:28:58][I][esp-idf:000]: idx:1 (ifx:0, c8:7f:54:20:b4:0e), tid:7, ssn:39, winSize:64
[10:28:58][I][esp-idf:000]:

[10:32:49][I][ota:117]: Boot seems successful, resetting boot loop counter.
[10:40:02][I][esp-idf:000]: E (734743) BT_BTM: btm_inq_rmt_name_failed() remname_active=1

[10:40:04][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[10:40:04][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[10:40:05][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[10:40:08][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[10:40:14][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[10:40:18][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
.
.
.
[15:00:55][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[15:00:58][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[15:01:04][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[15:01:08][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[15:01:14][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[15:01:18][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
.
.
.
[15:04:55][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[15:04:58][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[15:05:03][I][restart:016]: Restarting device...
[15:05:03][I][app:134]: Rebooting safely...
[15:05:03][I][esp-idf:000]: I (16635951) mqtt_client: Client asked to disconnect

[15:05:09][I][mqtt:274]: MQTT Connected!
[15:05:10][I][esp-idf:000]: I (4443) wifi:
[15:05:10][I][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 1
[15:05:10][I][esp-idf:000]:

[15:05:10][I][app:062]: setup() finished successfully!
[15:05:10][I][app:102]: ESPHome version 2023.12.2 compiled on Jan 10 2024, 07:38:25
[15:05:12][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[15:05:12][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[15:05:14][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[15:05:16][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[15:05:23][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[15:05:26][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[15:05:33][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[15:05:37][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[15:05:43][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[15:05:47][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining

@krambriw
Copy link

krambriw commented Jan 10, 2024

Just some additional info, I now got this error message in the log

[17:04:16][I][esp32_bt_classic:203]: Found device '00:11:22:33:44:55' (Walters iPhone 13) with 4 scans remaining
[17:04:23][I][esp32_bt_classic:203]: Found device '55:44:33:22:11:00' (Walters iPad) with 4 scans remaining
[17:23:22][I][esp-idf:000]: E (8297301) BT_BTM: btm_inq_rmt_name_failed() remname_active=1

[17:23:31][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[17:23:31][W][esp32_bt_classic:213]: Device '00:11:22:33:44:55' not found on final scan. Removing from scan list.
[17:23:32][W][esp32_bt_classic:213]: Device '55:44:33:22:11:00' not found on final scan. Removing from scan list.
[

@krambriw
Copy link

BT_BTM: btm_inq_rmt_name_failed() remname_active=1

It is definitely when I receive this error message the scanning stops from working. I have made a logger in Node-RED that waits for this error message and when it comes, it restarts the ESP device. It can run for many hours before the error happens. I will let it run for some days/weeks to see how frequent it is (I realize restarting upon error is not the cure but it keeps the device running for now)

image

@RoboMagus
Copy link
Contributor Author

Thanks for the additional information. It seems that I have not set the BT stack trace levels correctly myself, as the btm_inq_rmt_name_failed logging has not occurred during my tests.
High level the behavior is that the scan reports that the device cannot be found, which is indistinguishable from the device being actually absent. But perhaps more meaning can be found when digging through the stack internal states.

At first glance btm_inq_rmt_name_failed seems to be called also when the requested device is just not present. But it's definitely something I should look into. 👍

@krambriw
Copy link

Hello, thanks for looking into it. If it helps, I provide the current log result from my setup using Node-RED to restart the device when the error occurs (the restarting has worked fine every time, just to keep the device in operation). The time between errors is random. Sometimes it can work for more than a day, sometimes just some hours
Best regards, Walter

2024-01-14T06:20:13.208Z Begin looking for errors
2024-01-14T10:15:47.682Z �[0;32m[I][esp-idf:000]: �[0;31mE (6009121) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-14T14:32:59.259Z �[0;32m[I][esp-idf:000]: �[0;31mE (14567809) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-16T03:49:33.810Z �[0;32m[I][esp-idf:000]: �[0;31mE (55013595) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-17T12:26:21.072Z �[0;32m[I][esp-idf:000]: �[0;31mE (2386509) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-17T18:26:18.417Z �[0;32m[I][esp-idf:000]: �[0;31mE (21590020) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-17T19:37:13.309Z �[0;32m[I][esp-idf:000]: �[0;31mE (4247592) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-18T12:35:23.590Z �[0;32m[I][esp-idf:000]: �[0;31mE (4420674) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-19T08:19:06.685Z �[0;32m[I][esp-idf:000]: �[0;31mE (2696386) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-20T09:35:44.622Z �[0;32m[I][esp-idf:000]: �[0;31mE (25790324) BT_BTM: btm_inq_rmt_name_failed() remname_active=1

@krambriw
Copy link

Just a follow up. The time between errors is random. Sometimes it can work for more than a day, sometimes just some hours
Best seen so far is 10 days without issue
Best regards, Walter

......
2024-01-21T22:58:46.690Z �[0;32m[I][esp-idf:000]: �[0;31mE (28272276) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-22T12:20:11.114Z �[0;32m[I][esp-idf:000]: �[0;31mE (11119548) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-01-23T14:19:41.751Z �[0;32m[I][esp-idf:000]: �[0;31mE (1167123) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-02-03T02:32:47.363Z �[0;32m[I][esp-idf:000]: �[0;31mE (17291790) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
2024-02-05T04:45:07.322Z �[0;32m[I][esp-idf:000]: �[0;31mE (23231190) BT_BTM: btm_inq_rmt_name_failed() remname_active=1
......

@krambriw
Copy link

krambriw commented Feb 11, 2024

I tried now also to build it for a WEMOS LOLIN C3 Mini. Such a small device would be nice to use if you plan to have multiple "checkpoints" around for various automation use cases

In my .yaml I have
esp32_ble_tracker:
external_components:

  • source: github://pr#4736
    components: [ esp32_bt_classic, bt_classic_presence, esp32_bt_common ]

but as soon as I add esp32_bt_classic: I get the following errors below. Could it be something about the C3 does not support BT classic?
/Users/walterkrambring/.platformio/packages/toolchain-riscv32-esp@8.4.0+2021r2-patch5/bin/../lib/gcc/riscv32-esp-elf/8.4.0/../../../../riscv32-esp-elf/bin/ld: .pioenvs/base/src/esphome/components/esp32_bt_classic/bt_classic.o: in functionesphome::esp32_bt_classic::ESP32BtClassic::gap_startup()':
/Users/walterkrambring/Desktop/ESPHome/.esphome/build/base/src/esphome/components/esp32_bt_classic/bt_classic.cpp:243: undefined reference to esp_bt_gap_set_scan_mode' /Users/walterkrambring/.platformio/packages/toolchain-riscv32-esp@8.4.0+2021r2-patch5/bin/../lib/gcc/riscv32-esp-elf/8.4.0/../../../../riscv32-esp-elf/bin/ld: /Users/walterkrambring/Desktop/ESPHome/.esphome/build/base/src/esphome/components/esp32_bt_classic/bt_classic.cpp:104: undefined reference to esp_bt_gap_register_callback'
/Users/walterkrambring/.platformio/packages/toolchain-riscv32-esp@8.4.0+2021r2-patch5/bin/../lib/gcc/riscv32-esp-elf/8.4.0/../../../../riscv32-esp-elf/bin/ld: .pioenvs/base/src/esphome/components/esp32_bt_classic/bt_classic.o: in function esphome::esp32_bt_classic::ESP32BtClassic::startScan(unsigned long long)': /Users/walterkrambring/Desktop/ESPHome/.esphome/build/base/src/esphome/components/esp32_bt_classic/bt_classic.cpp:141: undefined reference to esp_bt_gap_read_remote_name'

`

@krambriw
Copy link

Found the answer & reason here:
https://www.esp32.com/viewtopic.php?t=22613

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants