dalehumby / ESPHome-Apple-Watch-detection

ESPHome BLE Apple Watch presence detection
MIT License
332 stars 17 forks source link

Apple Watch Series 5 not detected #1

Closed dcgrove closed 3 years ago

dcgrove commented 3 years ago

Hello, I set this up this morning and immediately ran into a couple of issues.

  1. On boot, the device gets to the point where MQTT is set up then pauses for several minutes before it starts scanning. Is this expected behaivor? See log file below where there was no activity between 11:13 and 11:16.

  2. It is not picking up my apple watch series 5 very quickly if at all. Occaisionally it will pick it up and provide data on the RSSI, but will stop updating.

YAML

substitutions:
  roomname: office
  #static_ip: 10.0.0.14
  yourname: Clayton
  rssi_present: "-73"
  rssi_not_present: "-85"

esphome:
  name: office-ble-tracker
  platform: ESP32
  board: wemos_d1_mini32

wifi:
  ssid: nest
  password: *******
  manual_ip:
    static_ip: 192.168.1.178
    gateway: 192.168.1.1
    subnet: 255.255.255.0

  ap:
    ssid: ESPHome $roomname
    password: ******

captive_portal:

logger:

api:

ota:

mqtt:
  broker: 192.168.1.205
  username: clayton
  password: *******
  discovery: false  # Publish to MQTT, but not for Home Assistant (HA uses its own API)

esp32_ble_tracker:
  scan_parameters:
    interval: 1.2s
    window: 500ms
    active: false
  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 01 98 XXXXXX
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 && data.data[2] == 0x01 && data.data[3] == 0x98) {
              int16_t rssi = x.get_rssi();
              id(apple_watch_rssi).publish_state(rssi);
              ESP_LOGD("ble_adv", "Found Apple Watch, rssi %i", rssi);
            }
          }

sensor:
  - platform: template
    id: apple_watch_rssi
    name: "$yourname Apple Watch $roomname RSSI"
    device_class: signal_strength
    unit_of_measurement: dBm
    accuracy_decimals: 0
    filters:
      - exponential_moving_average:
          alpha: 0.3
          send_every: 1
    on_value:
      then:
        - lambda: |-
            if (id(apple_watch_rssi).state > $rssi_present) {
              id(room_presence_debounce).publish_state(1);
            } else if (id(apple_watch_rssi).state < $rssi_not_present) {
              id(room_presence_debounce).publish_state(0);
            }
        - script.execute: presence_timeout  # Publish 0 if no rssi received

  - platform: template
    id: room_presence_debounce
    filters:
      - sliding_window_moving_average:
          window_size: 3
          send_every: 1

binary_sensor:
  - platform: template
    id: room_presence
    name: "$yourname $roomname presence"
    device_class: occupancy
    lambda: |-
      if (id(room_presence_debounce).state > 0.99) {
        return true;
      } else if (id(room_presence_debounce).state < 0.01) {
        return false;
      } else {
        return id(room_presence).state;
      }

script:
  # Publish event every 30 seconds when no rssi received
  id: presence_timeout
  mode: restart
  then:
    - delay: 30s
    - lambda: |-
        id(room_presence_debounce).publish_state(0);
    - script.execute: presence_timeout

Log on boot where it gets stuck

INFO Reading configuration /config/esphome/officebletracker.yaml...
INFO Starting log output from 192.168.1.178 using esphome API
INFO Connecting to 192.168.1.178:6053 (192.168.1.178)
INFO Successfully connected to 192.168.1.178
[11:13:43][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 28 2021, 09:13:05
[11:13:43][C][wifi:499]: WiFi:
[11:13:43][C][wifi:359]:   SSID: [redacted]
[11:13:43][C][wifi:360]:   IP Address: 192.168.1.178
[11:13:43][C][wifi:362]:   BSSID: [redacted]
[11:13:43][C][wifi:363]:   Hostname: 'office-ble-tracker'
[11:13:43][C][wifi:367]:   Signal strength: -55 dB ▂▄▆█
[11:13:43][C][wifi:371]:   Channel: 6
[11:13:43][C][wifi:372]:   Subnet: 255.255.255.0
[11:13:43][C][wifi:373]:   Gateway: 192.168.1.1
[11:13:43][C][wifi:374]:   DNS1: 0.0.0.0
[11:13:43][C][wifi:375]:   DNS2: 0.0.0.0
[11:13:43][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch office RSSI'
[11:13:43][C][template.sensor:021]:   Device Class: 'signal_strength'
[11:13:43][C][template.sensor:021]:   State Class: ''
[11:13:43][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[11:13:43][C][template.sensor:021]:   Accuracy Decimals: 0
[11:13:43][C][template.sensor:022]:   Update Interval: 60.0s
[11:13:43][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[11:13:43][C][template.sensor:021]:   State Class: ''
[11:13:43][C][template.sensor:021]:   Unit of Measurement: ''
[11:13:43][C][template.sensor:021]:   Accuracy Decimals: 1
[11:13:43][C][template.sensor:022]:   Update Interval: 60.0s
[11:13:43][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton office presence'
[11:13:43][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[11:13:43][C][logger:189]: Logger:
[11:13:43][C][logger:190]:   Level: DEBUG
[11:13:43][C][logger:191]:   Log Baud Rate: 115200
[11:13:43][C][logger:192]:   Hardware UART: UART0
[11:13:43][C][esp32_ble_tracker:606]: BLE Tracker:
[11:13:43][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[11:13:43][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[11:13:43][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[11:13:43][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[11:13:43][C][captive_portal:148]: Captive Portal:
[11:13:43][C][ota:029]: Over-The-Air Updates:
[11:13:43][C][ota:030]:   Address: 192.168.1.178:3232
[11:13:43][C][api:095]: API Server:
[11:13:43][C][api:096]:   Address: 192.168.1.178:6053
[11:13:43][C][mqtt:061]: MQTT:
[11:13:43][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[11:13:43][C][mqtt:064]:   Username: [redacted]
[11:13:43][C][mqtt:065]:   Client ID: [redacted]
[11:13:43][C][mqtt:070]:   Topic Prefix: 'office-ble-tracker'
[11:13:43][C][mqtt:072]:   Log Topic: 'office-ble-tracker/debug'
[11:13:43][C][mqtt:075]:   Availability: 'office-ble-tracker/status'
[11:13:43][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[11:13:43][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/room_presence_debounce/state'
[11:13:43][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton office presence':
[11:13:43][C][mqtt.binary_sensor:019]:   State Topic: 'office-ble-tracker/binary_sensor/clayton_office_presence/state'
[11:13:43][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch office RSSI':
[11:13:43][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/clayton_apple_watch_office_rssi/state'
[11:16:54][I][ota:046]: Boot seems successful, resetting boot loop counter.
[11:16:55][D][esp32_ble_tracker:180]: Starting scan...
SteveB766 commented 3 years ago

I have the same issue with a series 5 on watch os 8.0 public beta

dalehumby commented 3 years ago

Hi @dcgrove (I hope you don't mind, I fixed formatting of your comment using `` instead of for code blocks.)

I'm not sure whether Starting scan... is only happening 3 minutes later, or is already running at 11:13 but just not finding your watch. I do know that the esp32_ble_tracker does restart from time to time, so you might just be seeing one of its restart debug messages.

I've not tested this on Series 5 watches (I only have a Series 3) so the Nearby Info message may be slightly different.

Could you change the lambda to the following? I'll need more debug info:

  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 XX XX XXXXXX
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05) {
              int16_t rssi = x.get_rssi();
              ESP_LOGD("ble_adv", "Possible Apple Watch: data[2]=%#04x data[3]=%#04x", data.data[2], data.data[3]);
              ESP_LOGD("ble_adv", "  rssi %i", rssi);
              ESP_LOGD("ble_adv", "  mac %s", x.address_str().c_str());
            }
          }

This will print out bytes 2 and 3 from the payload. It'll probably find other Apple devices, not just your watch, so bring your watch close to the ESP32 so the RSSI is low, like -30 or -40 for easy identification.

Please post that log, and we can see what the difference is in Nearby Info messages.

BTW if you want to try figure this out yourself the rough structure of Nearby Info is at https://github.com/furiousMAC/continuity/blob/master/messages/nearby_info.md. We're looking at the Status, Action and Data bytes in the payload.

dcgrove commented 3 years ago

So I made the changes. Logs are at the pastebin link below. It is picking up lots of devices now which isn't surprising as there are several apple devices in close proximity to this esp32.

https://pastebin.com/P2BKzaWs

I also changed the on_ble_advertise back, and increased the logging level to verbose.

This is the log on reboot:

INFO Reading configuration /config/esphome/officebletracker.yaml...
INFO Starting log output from 192.168.1.178 using esphome API
INFO Connecting to 192.168.1.178:6053 (192.168.1.178)
INFO Successfully connected to 192.168.1.178
[16:50:27][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 28 2021, 16:44:26
[16:50:27][C][wifi:499]: WiFi:
[16:50:27][C][wifi:359]:   SSID: [redacted]
[16:50:27][C][wifi:360]:   IP Address: 192.168.1.178
[16:50:27][C][wifi:362]:   BSSID: [redacted]
[16:50:27][C][wifi:363]:   Hostname: 'office-ble-tracker'
[16:50:27][C][wifi:367]:   Signal strength: -64 dB ▂▄▆█
[16:50:27][V][wifi:369]:   Priority: 0.0
[16:50:27][C][wifi:371]:   Channel: 6
[16:50:27][C][wifi:372]:   Subnet: 255.255.255.0
[16:50:27][C][wifi:373]:   Gateway: 192.168.1.1
[16:50:27][C][wifi:374]:   DNS1: 0.0.0.0
[16:50:27][C][wifi:375]:   DNS2: 0.0.0.0
[16:50:27][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch office RSSI'
[16:50:27][C][template.sensor:021]:   Device Class: 'signal_strength'
[16:50:27][C][template.sensor:021]:   State Class: ''
[16:50:27][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[16:50:27][C][template.sensor:021]:   Accuracy Decimals: 0
[16:50:27][C][template.sensor:022]:   Update Interval: 60.0s
[16:50:27][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[16:50:27][C][template.sensor:021]:   State Class: ''
[16:50:27][C][template.sensor:021]:   Unit of Measurement: ''
[16:50:27][C][template.sensor:021]:   Accuracy Decimals: 1
[16:50:27][C][template.sensor:022]:   Update Interval: 60.0s
[16:50:27][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton office presence'
[16:50:27][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[16:50:27][C][logger:189]: Logger:
[16:50:27][C][logger:190]:   Level: VERBOSE
[16:50:27][C][logger:191]:   Log Baud Rate: 115200
[16:50:27][C][logger:192]:   Hardware UART: UART0
[16:50:27][C][esp32_ble_tracker:606]: BLE Tracker:
[16:50:27][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[16:50:27][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[16:50:27][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[16:50:27][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[16:50:27][C][status:034]: Status Binary Sensor 'Office BLE Tracker Status'
[16:50:27][C][status:034]:   Device Class: 'connectivity'
[16:50:27][C][captive_portal:148]: Captive Portal:
[16:50:27][C][ota:029]: Over-The-Air Updates:
[16:50:27][C][ota:030]:   Address: 192.168.1.178:3232
[16:50:27][C][api:095]: API Server:
[16:50:27][C][api:096]:   Address: 192.168.1.178:6053
[16:50:27][C][mqtt:061]: MQTT:
[16:50:27][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[16:50:27][C][mqtt:064]:   Username: [redacted]
[16:50:27][C][mqtt:065]:   Client ID: [redacted]
[16:50:27][C][mqtt:070]:   Topic Prefix: 'office-ble-tracker'
[16:50:27][C][mqtt:072]:   Log Topic: 'office-ble-tracker/debug'
[16:50:27][C][mqtt:075]:   Availability: 'office-ble-tracker/status'
[16:50:27][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[16:50:27][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/room_presence_debounce/state'
[16:50:27][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Office BLE Tracker Status':
[16:50:27][C][mqtt.binary_sensor:019]:   State Topic: 'office-ble-tracker/status'
[16:50:27][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton office presence':
[16:50:27][C][mqtt.binary_sensor:019]:   State Topic: 'office-ble-tracker/binary_sensor/clayton_office_presence/state'
[16:50:27][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch office RSSI':
[16:50:27][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/clayton_apple_watch_office_rssi/state'
[16:50:31][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:00][D][api:067]: Disconnecting 192.168.1.205
[16:51:05][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:06][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:07][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:12][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:19][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:20][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:27][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:40][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:51:57][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:52:02][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:52:03][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:52:08][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
[16:52:12][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12
dalehumby commented 3 years ago

Thanks for the logs and pastebin.

I'm going to make the assumption that the strongest signal is your Watch, with an RSSI of about -50, and the mac address (at the time) of 47:4B:FA:C6:36:57.

If this is the case, then bytes 2 and 3 are 0x0D and 0x98, respectively.

In the original code on line 49 could you try changing byte 2 from 0x01 to 0x0D, and see if that detects your watch?

It should be:

if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 && data.data[2] == 0x0D && data.data[3] == 0x98) {

If that works, great! Then please take your watch off (so that it auto-locks.) The rssi should stop updating and after 90 seconds presence should go from Detected to Clear in HA. Put watch back on, unlock and detection should resume after a few seconds.

dcgrove commented 3 years ago

I will give this a shot. I was able to pull this from a BLE scanner app on y phone. Is it helpful?

image

image

image

image

image

dalehumby commented 3 years ago

Yes, that's helpful, thanks – Specifically the MODEL NUMBER STRING being Watch5,2 means that we can differentiate between multiple watches in the same house, provided they have different major/minor (5,2) revision numbers.

dcgrove commented 3 years ago

I made the changes you recommended above to line 49. Here is the log file. It is not picking up my watch.

Using 'COM5' as serial port.
Showing logs:
[15:15:33][D][wifi:395]: Found networks:
[15:15:33][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█
[15:15:33][D][wifi:442]:     Channel: 6
[15:15:33][D][wifi:443]:     RSSI: -50 dB
[15:15:33][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█
[15:15:33][D][wifi:442]:     Channel: 1
[15:15:33][D][wifi:443]:     RSSI: -73 dB
[15:15:33][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█
[15:15:33][D][wifi:442]:     Channel: 11
[15:15:33][D][wifi:443]:     RSSI: -75 dB
[15:15:33][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█
[15:15:33][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█
[15:15:33][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█
[15:15:33][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█
[15:15:33][D][wifi:445]: - 'prettyfly4awifi' (E2:63:DA:74:2D:3A) ▂▄▆█
[15:15:33][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█
[15:15:33][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█
[15:15:33][D][wifi:445]: - 'NETGEAR78' (50:6A:03:BD:D1:B4) ▂▄▆█
[15:15:33][D][wifi:445]: - 'Cloud Mesh' (E8:9F:80:59:F9:4D) ▂▄▆█
[15:15:33][D][wifi:445]: - 'Cloud Mesh' (E8:9F:80:59:F8:C1) ▂▄▆█
[15:15:33][D][wifi:445]: - '' (EE:9F:80:59:F8:C1) ▂▄▆█
[15:15:33][D][wifi:445]: - '' (EE:9F:80:59:F9:4D) ▂▄▆█
[15:15:33][I][wifi:250]: WiFi Connecting to 'nest'...
[15:15:34][W][esp32_ble_tracker:077]: Too many BLE events to process. Some devices may not show up.
[15:15:35][I][wifi:513]: WiFi Connected!
[15:15:35][C][wifi:359]:   SSID: 'nest'
[15:15:35][C][wifi:360]:   IP Address: 192.168.1.207
[15:15:35][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[15:15:35][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[15:15:35][C][wifi:367]:   Signal strength: -51 dB ▂▄▆█
[15:15:35][C][wifi:371]:   Channel: 6
[15:15:35][C][wifi:372]:   Subnet: 255.255.255.0
[15:15:35][C][wifi:373]:   Gateway: 192.168.1.1
[15:15:35][C][wifi:374]:   DNS1: 192.168.1.195
[15:15:35][C][wifi:375]:   DNS2: 0.0.0.0
[15:15:35][D][wifi:522]: Disabling AP...
[15:15:35][C][ota:029]: Over-The-Air Updates:
[15:15:35][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[15:15:35][W][ota:036]: Last Boot was an unhandled reset, will proceed to safe mode in 7 restarts
[15:15:35][C][api:022]: Setting up Home Assistant API server...
[15:15:35][C][mqtt:027]: Setting up MQTT...
[15:15:35][I][mqtt:172]: Connecting to MQTT...
[15:15:35][I][mqtt:212]: MQTT Connected!
[15:15:35][I][app:060]: setup() finished successfully!
[15:15:35][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 29 2021, 15:10:04
[15:15:35][C][wifi:499]: WiFi:
[15:15:35][C][wifi:359]:   SSID: 'nest'
[15:15:35][C][wifi:360]:   IP Address: 192.168.1.207
[15:15:35][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[15:15:35][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[15:15:35][C][wifi:367]:   Signal strength: -52 dB ▂▄▆█
[15:15:35][C][wifi:371]:   Channel: 6
[15:15:35][C][wifi:372]:   Subnet: 255.255.255.0
[15:15:35][C][wifi:373]:   Gateway: 192.168.1.1
[15:15:35][C][wifi:374]:   DNS1: 192.168.1.195
[15:15:35][C][wifi:375]:   DNS2: 0.0.0.0
[15:15:35][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully!
[15:15:35][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI'
[15:15:35][C][template.sensor:021]:   Device Class: 'signal_strength'
[15:15:35][C][template.sensor:021]:   State Class: ''
[15:15:35][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[15:15:35][C][template.sensor:021]:   Accuracy Decimals: 0
[15:15:35][C][template.sensor:022]:   Update Interval: 60.0s
[15:15:35][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[15:15:35][C][template.sensor:021]:   State Class: ''
[15:15:35][C][template.sensor:021]:   Unit of Measurement: ''
[15:15:35][C][template.sensor:021]:   Accuracy Decimals: 1
[15:15:35][C][template.sensor:022]:   Update Interval: 60.0s
[15:15:35][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton famlr-ble-tracker presence'
[15:15:35][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[15:15:35][C][logger:189]: Logger:
[15:15:35][C][logger:190]:   Level: DEBUG
[15:15:35][C][logger:191]:   Log Baud Rate: 115200
[15:15:35][C][logger:192]:   Hardware UART: UART0
[15:15:35][C][esp32_ble_tracker:606]: BLE Tracker:
[15:15:35][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[15:15:35][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[15:15:35][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[15:15:35][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[15:15:35][D][esp-idf:000]: E (6865) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 268 bytes)
[15:15:35]
[15:15:35][C][captive_portal:148]: Captive Portal:
[15:15:35][C][ota:029]: Over-The-Air Updates:
[15:15:35][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[15:15:35][W][ota:036]: Last Boot was an unhandled reset, will proceed to safe mode in 7 restarts
[15:15:35][C][api:095]: API Server:
[15:15:35][C][api:096]:   Address: famlr-ble-tracker.local:6053
[15:15:35][C][mqtt:061]: MQTT:
[15:15:35][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[15:15:35][C][mqtt:064]:   Username: 'clayton'
[15:15:35][C][mqtt:065]:   Client ID: 'famlr-ble-tracker-94b97ee653b8'
[15:15:35][C][mqtt:070]:   Topic Prefix: 'famlr-ble-tracker'
[15:15:35][C][mqtt:072]:   Log Topic: 'famlr-ble-tracker/debug'
[15:15:35][C][mqtt:075]:   Availability: 'famlr-ble-tracker/status'
[15:15:35][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[15:15:35][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/room_presence_debounce/state'
[15:15:35][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton famlr-ble-tracker presence':
[15:15:35][C][mqtt.binary_sensor:019]:   State Topic: 'famlr-ble-tracker/binary_sensor/clayton_famlr-ble-tracker_presence/state'
[15:15:35][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI':
[15:15:35][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/clayton_apple_watch_famlr-ble-tracker_rssi/state'
[15:17:04][D][esp-idf:000]: E (95894) MDNS: Cannot allocate memory (line: 128, free heap: 252 bytes)
[15:17:04]
[15:17:04][D][esp-idf:000]: E (95896) MDNS: Cannot allocate memory (line: 128, free heap: 252 bytes)
[15:17:04]

image

dalehumby commented 3 years ago

Ah that's a shame. Perhaps as a next step you could try going back to the original 'debug' code I posted above to log out bytes 2 and 3 as well as the mac address and rssi. Place your watch (unlocked) and arm within ~30cm of the ESP32, so the signal strength is really strong (rssi about -30 to -50.) When it's much stronger than all other Apple devices it will be easier to find in the logs.

From there, you should see a pattern in bytes 2 and 3, hopefully something like 1 (0x01) or 13 (0x0D) for byte 2 and 152 (0x98) for byte 3.

Once you've found the pattern, then program that in on line 49 of the original code.

I'll ask my friends who has a Watch 5 this week and get them to help me debug in person, incase we don't come right here.

dcgrove commented 3 years ago

I changed the code, and I suspect this is my watch as it was the consistently the lowest RSSI and the closest device to the ESP32. Where do I find bytes 2 & 3?

[15:52:51][D][ble_adv:052]: Possible Apple Watch 11 152
[15:52:51][D][ble_adv:053]:   rssi -53
[15:52:51][D][ble_adv:054]:   mac 6A:5F:9D:C4:D0:CD
dalehumby commented 3 years ago

Byte 2 is the 11 that you see in your debug log (and byte 3 is 152.)

From this log and your previous one, it looks like the possible values for bytes 2 are 1 (for my watch series 3), and 11 and 13 for your series 5 watch.

Can you try this code to detect your watch? (From line 44 onwards.)

  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 YY 98 XXXXXX
      # Where YY can be 01, 0B, 0D; and XXXXXX is ignored
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 
            && data.data[3] == 0x98
            && (data.data[2] == 0x01 || data.data[2] == 0x0B || data.data[2] == 0x0D)) {
              int16_t rssi = x.get_rssi();
              id(apple_watch_rssi).publish_state(rssi);
              ESP_LOGD("ble_adv", "Found Apple Watch, rssi %i", rssi);
            }
          }
dcgrove commented 3 years ago

Good morning, here are the logs after making the changes above. Could the error messages w.r.t MDNS_networking be the issue?

Showing logs:
[07:46:45]ets Jun  8 2016 00:22:57
[07:46:45]
[07:46:45]rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[07:46:45]configsip: 0, SPIWP:0xee
[07:46:45]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[07:46:45]mode:DIO, clock div:2
[07:46:45]load:0x3fff0018,len:4
[07:46:45]load:0x3fff001c,len:1044
[07:46:45]load:0x40078000,len:8896
[07:46:45]load:0x40080400,len:5828
[07:46:45]entry 0x400806ac
[07:46:46][I][logger:170]: Log initialized
[07:46:46][C][ota:378]: There have been 0 suspected unsuccessful boot attempts.
[07:46:46][I][app:029]: Running through setup()...
[07:46:46][D][esp32_ble_tracker:180]: Starting scan...
[07:46:46][C][wifi:037]: Setting up WiFi...
[07:46:47][D][wifi:380]: Starting scan...
[07:46:47][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state OFF
[07:46:50][D][wifi:395]: Found networks:
[07:46:50][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 11
[07:46:50][D][wifi:443]:     RSSI: -65 dB
[07:46:50][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 6
[07:46:50][D][wifi:443]:     RSSI: -66 dB
[07:46:50][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 1
[07:46:50][D][wifi:443]:     RSSI: -71 dB
[07:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (E2:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█
[07:46:50][D][wifi:445]: - 'Linksys07248' (B4:75:0E:35:E9:DB) ▂▄▆█
[07:46:50][D][wifi:445]: - '' (EE:9F:80:59:F9:4D) ▂▄▆█
[07:46:50][I][wifi:250]: WiFi Connecting to 'nest'...
[07:46:52][I][wifi:513]: WiFi Connected!
[07:46:52][C][wifi:359]:   SSID: 'nest'
[07:46:52][C][wifi:360]:   IP Address: 192.168.1.207
[07:46:52][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[07:46:52][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[07:46:52][C][wifi:367]:   Signal strength: -63 dB ▂▄▆█
[07:46:52][C][wifi:371]:   Channel: 11
[07:46:52][C][wifi:372]:   Subnet: 255.255.255.0
[07:46:52][C][wifi:373]:   Gateway: 192.168.1.1
[07:46:52][C][wifi:374]:   DNS1: 192.168.1.195
[07:46:52][C][wifi:375]:   DNS2: 0.0.0.0
[07:46:52][D][wifi:522]: Disabling AP...
[07:46:52][C][ota:029]: Over-The-Air Updates:
[07:46:52][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[07:46:52][C][api:022]: Setting up Home Assistant API server...
[07:46:52][C][mqtt:027]: Setting up MQTT...
[07:46:52][I][mqtt:172]: Connecting to MQTT...
[07:46:52][I][mqtt:212]: MQTT Connected!
[07:46:53][I][app:060]: setup() finished successfully!
[07:46:53][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 30 2021, 07:45:37
[07:46:53][C][wifi:499]: WiFi:
[07:46:53][C][wifi:359]:   SSID: 'nest'
[07:46:53][C][wifi:360]:   IP Address: 192.168.1.207
[07:46:53][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[07:46:53][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[07:46:53][C][wifi:367]:   Signal strength: -63 dB ▂▄▆█
[07:46:53][C][wifi:371]:   Channel: 11
[07:46:53][C][wifi:372]:   Subnet: 255.255.255.0
[07:46:53][C][wifi:373]:   Gateway: 192.168.1.1
[07:46:53][C][wifi:374]:   DNS1: 192.168.1.195
[07:46:53][C][wifi:375]:   DNS2: 0.0.0.0
[07:46:53][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI'
[07:46:53][C][template.sensor:021]:   Device Class: 'signal_strength'
[07:46:53][C][template.sensor:021]:   State Class: ''
[07:46:53][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[07:46:53][C][template.sensor:021]:   Accuracy Decimals: 0
[07:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[07:46:53][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[07:46:53][C][template.sensor:021]:   State Class: ''
[07:46:53][C][template.sensor:021]:   Unit of Measurement: ''
[07:46:53][C][template.sensor:021]:   Accuracy Decimals: 1
[07:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[07:46:53][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton famlr-ble-tracker presence'
[07:46:53][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[07:46:53][C][logger:189]: Logger:
[07:46:53][C][logger:190]:   Level: DEBUG
[07:46:53][C][logger:191]:   Log Baud Rate: 115200
[07:46:53][C][logger:192]:   Hardware UART: UART0
[07:46:53][C][esp32_ble_tracker:606]: BLE Tracker:
[07:46:53][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[07:46:53][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[07:46:53][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[07:46:53][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[07:46:53][C][captive_portal:148]: Captive Portal:
[07:46:53][C][ota:029]: Over-The-Air Updates:
[07:46:53][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[07:46:53][C][api:095]: API Server:
[07:46:53][C][api:096]:   Address: famlr-ble-tracker.local:6053
[07:46:53][C][mqtt:061]: MQTT:
[07:46:53][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[07:46:53][C][mqtt:064]:   Username: 'clayton'
[07:46:53][C][mqtt:065]:   Client ID: 'famlr-ble-tracker-94b97ee653b8'
[07:46:53][C][mqtt:070]:   Topic Prefix: 'famlr-ble-tracker'
[07:46:53][C][mqtt:072]:   Log Topic: 'famlr-ble-tracker/debug'
[07:46:53][C][mqtt:075]:   Availability: 'famlr-ble-tracker/status'
[07:46:53][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[07:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/room_presence_debounce/state'
[07:46:53][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton famlr-ble-tracker presence':
[07:46:53][C][mqtt.binary_sensor:019]:   State Topic: 'famlr-ble-tracker/binary_sensor/clayton_famlr-ble-tracker_presence/state'
[07:46:53][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI':
[07:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/clayton_apple_watch_famlr-ble-tracker_rssi/state'
[07:46:54][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully!
[07:48:22][D][api:067]: Disconnecting 192.168.1.205
[07:48:27][D][esp-idf:000]: E (102211) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:48:27]
[07:48:31][D][esp-idf:000]: E (106202) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:31]
[07:48:47][D][esp-idf:000]: E (122167) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:47]
[07:48:49][D][esp-idf:000]: E (124009) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:48:49]
[07:48:57][D][esp-idf:000]: E (131991) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:48:57]
[07:48:59][D][esp-idf:000]: E (134140) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:59]
[07:49:53][D][esp-idf:000]: E (188172) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:49:53]
[07:50:01][D][esp-idf:000]: E (196154) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 288 bytes)
[07:50:01]
[07:50:19][D][esp-idf:000]: E (214574) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:50:19]
[07:50:35][D][esp-idf:000]: E (230231) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:50:35]
[07:50:53][D][esp-idf:000]: E (248037) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:50:53][D][esp-idf:000]: E (248039) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:50:53][D][esp-idf:000]: E (248048) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:51:23][D][esp-idf:000]: E (278124) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:51:23]
[07:51:23][D][esp-idf:000]: E (278431) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:23]
[07:51:23][D][esp-idf:000]: E (278433) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:23]
[07:51:25][D][esp-idf:000]: E (280273) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 288 bytes)
[07:51:25]
[07:51:25][D][esp-idf:000]: E (280580) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:25]
[07:51:25][D][esp-idf:000]: E (280582) MDNS: Cannot allocate memory (line: 128, free heap: 156 bytes)
[07:51:25]
[07:51:33][D][esp-idf:000]: E (288256) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:33]
[07:51:46][I][ota:046]: Boot seems successful, resetting boot loop counter.
[07:51:46][D][esp32_ble_tracker:180]: Starting scan...
[07:52:01][D][esp-idf:000]: E (316193) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:52:01]
[07:52:03][D][esp-idf:000]: E (318346) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:52:03]
[07:53:01][D][esp-idf:000]: E (376365) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376367) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376375) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376384) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:09][D][esp-idf:000]: E (384347) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:53:09]
[07:53:15][D][esp-idf:000]: E (390180) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:15]
[07:53:49][D][esp-idf:000]: E (424257) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:53:49]
[07:54:05][D][esp-idf:000]: E (440528) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:54:05]
[07:54:07][D][esp-idf:000]: E (442370) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:54:07]
[07:54:07][D][esp-idf:000]: E (442372) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:54:07]
[07:54:15][D][esp-idf:000]: E (450352) MDNS: Cannot allocate memory (line: 128, free heap: 220 bytes)
[07:54:15]
[07:54:31][D][esp-idf:000]: E (466317) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:54:31]

image

dcgrove commented 3 years ago

Well, it seems to have started working. The watch was detected as you can see around 8:00:29, and I took it off which caused it to clear around 8:02:00 and it sent a state of 0. Still getting quite a bit of the MDNS errors so I am not sure if that is normal or not.

Using 'COM5' as serial port.
Writing at 0x000f4000... (100 %)Wrote 1567520 bytes (937195 compressed) at 0x00010000 in 22.3 seconds (effective 563.4 kbit/s)...
Hash of data verified.

Leaving...
Hard Resetting...
Done! Flashing is complete!

Showing logs:
[07:46:45]ets Jun  8 2016 00:22:57
[07:46:45]
[07:46:45]rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[07:46:45]configsip: 0, SPIWP:0xee
[07:46:45]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[07:46:45]mode:DIO, clock div:2
[07:46:45]load:0x3fff0018,len:4
[07:46:45]load:0x3fff001c,len:1044
[07:46:45]load:0x40078000,len:8896
[07:46:45]load:0x40080400,len:5828
[07:46:45]entry 0x400806ac
[07:46:46][I][logger:170]: Log initialized
[07:46:46][C][ota:378]: There have been 0 suspected unsuccessful boot attempts.
[07:46:46][I][app:029]: Running through setup()...
[07:46:46][D][esp32_ble_tracker:180]: Starting scan...
[07:46:46][C][wifi:037]: Setting up WiFi...
[07:46:47][D][wifi:380]: Starting scan...
[07:46:47][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state OFF
[07:46:50][D][wifi:395]: Found networks:
[07:46:50][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 11
[07:46:50][D][wifi:443]:     RSSI: -65 dB
[07:46:50][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 6
[07:46:50][D][wifi:443]:     RSSI: -66 dB
[07:46:50][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:442]:     Channel: 1
[07:46:50][D][wifi:443]:     RSSI: -71 dB
[07:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█
[07:46:50][D][wifi:445]: - 'prettyfly4awifi' (E2:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█
[07:46:50][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█
[07:46:50][D][wifi:445]: - 'Linksys07248' (B4:75:0E:35:E9:DB) ▂▄▆█
[07:46:50][D][wifi:445]: - '' (EE:9F:80:59:F9:4D) ▂▄▆█
[07:46:50][I][wifi:250]: WiFi Connecting to 'nest'...
[07:46:52][I][wifi:513]: WiFi Connected!
[07:46:52][C][wifi:359]:   SSID: 'nest'
[07:46:52][C][wifi:360]:   IP Address: 192.168.1.207
[07:46:52][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[07:46:52][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[07:46:52][C][wifi:367]:   Signal strength: -63 dB ▂▄▆█
[07:46:52][C][wifi:371]:   Channel: 11
[07:46:52][C][wifi:372]:   Subnet: 255.255.255.0
[07:46:52][C][wifi:373]:   Gateway: 192.168.1.1
[07:46:52][C][wifi:374]:   DNS1: 192.168.1.195
[07:46:52][C][wifi:375]:   DNS2: 0.0.0.0
[07:46:52][D][wifi:522]: Disabling AP...
[07:46:52][C][ota:029]: Over-The-Air Updates:
[07:46:52][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[07:46:52][C][api:022]: Setting up Home Assistant API server...
[07:46:52][C][mqtt:027]: Setting up MQTT...
[07:46:52][I][mqtt:172]: Connecting to MQTT...
[07:46:52][I][mqtt:212]: MQTT Connected!
[07:46:53][I][app:060]: setup() finished successfully!
[07:46:53][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 30 2021, 07:45:37
[07:46:53][C][wifi:499]: WiFi:
[07:46:53][C][wifi:359]:   SSID: 'nest'
[07:46:53][C][wifi:360]:   IP Address: 192.168.1.207
[07:46:53][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[07:46:53][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[07:46:53][C][wifi:367]:   Signal strength: -63 dB ▂▄▆█
[07:46:53][C][wifi:371]:   Channel: 11
[07:46:53][C][wifi:372]:   Subnet: 255.255.255.0
[07:46:53][C][wifi:373]:   Gateway: 192.168.1.1
[07:46:53][C][wifi:374]:   DNS1: 192.168.1.195
[07:46:53][C][wifi:375]:   DNS2: 0.0.0.0
[07:46:53][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI'
[07:46:53][C][template.sensor:021]:   Device Class: 'signal_strength'
[07:46:53][C][template.sensor:021]:   State Class: ''
[07:46:53][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[07:46:53][C][template.sensor:021]:   Accuracy Decimals: 0
[07:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[07:46:53][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[07:46:53][C][template.sensor:021]:   State Class: ''
[07:46:53][C][template.sensor:021]:   Unit of Measurement: ''
[07:46:53][C][template.sensor:021]:   Accuracy Decimals: 1
[07:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[07:46:53][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton famlr-ble-tracker presence'
[07:46:53][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[07:46:53][C][logger:189]: Logger:
[07:46:53][C][logger:190]:   Level: DEBUG
[07:46:53][C][logger:191]:   Log Baud Rate: 115200
[07:46:53][C][logger:192]:   Hardware UART: UART0
[07:46:53][C][esp32_ble_tracker:606]: BLE Tracker:
[07:46:53][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[07:46:53][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[07:46:53][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[07:46:53][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[07:46:53][C][captive_portal:148]: Captive Portal:
[07:46:53][C][ota:029]: Over-The-Air Updates:
[07:46:53][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[07:46:53][C][api:095]: API Server:
[07:46:53][C][api:096]:   Address: famlr-ble-tracker.local:6053
[07:46:53][C][mqtt:061]: MQTT:
[07:46:53][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[07:46:53][C][mqtt:064]:   Username: 'clayton'
[07:46:53][C][mqtt:065]:   Client ID: 'famlr-ble-tracker-94b97ee653b8'
[07:46:53][C][mqtt:070]:   Topic Prefix: 'famlr-ble-tracker'
[07:46:53][C][mqtt:072]:   Log Topic: 'famlr-ble-tracker/debug'
[07:46:53][C][mqtt:075]:   Availability: 'famlr-ble-tracker/status'
[07:46:53][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[07:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/room_presence_debounce/state'
[07:46:53][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton famlr-ble-tracker presence':
[07:46:53][C][mqtt.binary_sensor:019]:   State Topic: 'famlr-ble-tracker/binary_sensor/clayton_famlr-ble-tracker_presence/state'
[07:46:53][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI':
[07:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/clayton_apple_watch_famlr-ble-tracker_rssi/state'
[07:46:54][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully!
[07:48:22][D][api:067]: Disconnecting 192.168.1.205
[07:48:27][D][esp-idf:000]: E (102211) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:48:27]
[07:48:31][D][esp-idf:000]: E (106202) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:31]
[07:48:47][D][esp-idf:000]: E (122167) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:47]
[07:48:49][D][esp-idf:000]: E (124009) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:48:49]
[07:48:57][D][esp-idf:000]: E (131991) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:48:57]
[07:48:59][D][esp-idf:000]: E (134140) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:48:59]
[07:49:53][D][esp-idf:000]: E (188172) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:49:53]
[07:50:01][D][esp-idf:000]: E (196154) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 288 bytes)
[07:50:01]
[07:50:19][D][esp-idf:000]: E (214574) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:50:19]
[07:50:35][D][esp-idf:000]: E (230231) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:50:35]
[07:50:53][D][esp-idf:000]: E (248037) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:50:53][D][esp-idf:000]: E (248039) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:50:53][D][esp-idf:000]: E (248048) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:50:53]
[07:51:23][D][esp-idf:000]: E (278124) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:51:23]
[07:51:23][D][esp-idf:000]: E (278431) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:23]
[07:51:23][D][esp-idf:000]: E (278433) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:23]
[07:51:25][D][esp-idf:000]: E (280273) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 288 bytes)
[07:51:25]
[07:51:25][D][esp-idf:000]: E (280580) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:25]
[07:51:25][D][esp-idf:000]: E (280582) MDNS: Cannot allocate memory (line: 128, free heap: 156 bytes)
[07:51:25]
[07:51:33][D][esp-idf:000]: E (288256) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:51:33]
[07:51:46][I][ota:046]: Boot seems successful, resetting boot loop counter.
[07:51:46][D][esp32_ble_tracker:180]: Starting scan...
[07:52:01][D][esp-idf:000]: E (316193) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:52:01]
[07:52:03][D][esp-idf:000]: E (318346) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:52:03]
[07:53:01][D][esp-idf:000]: E (376365) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376367) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376375) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:01][D][esp-idf:000]: E (376384) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:01]
[07:53:09][D][esp-idf:000]: E (384347) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:53:09]
[07:53:15][D][esp-idf:000]: E (390180) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:53:15]
[07:53:49][D][esp-idf:000]: E (424257) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:53:49]
[07:54:05][D][esp-idf:000]: E (440528) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:54:05]
[07:54:07][D][esp-idf:000]: E (442370) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:54:07]
[07:54:07][D][esp-idf:000]: E (442372) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:54:07]
[07:54:15][D][esp-idf:000]: E (450352) MDNS: Cannot allocate memory (line: 128, free heap: 220 bytes)
[07:54:15]
[07:54:31][D][esp-idf:000]: E (466317) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:54:31]
[07:55:09][D][esp-idf:000]: E (504692) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:55:09]
[07:55:11][D][esp-idf:000]: E (506227) MDNS: Cannot allocate memory (line: 128, free heap: 156 bytes)
[07:55:11]
[07:55:11][D][esp-idf:000]: E (506229) MDNS: Cannot allocate memory (line: 128, free heap: 156 bytes)
[07:55:11]
[07:55:19][D][esp-idf:000]: E (514210) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 156 bytes)
[07:55:19]
[07:55:21][D][esp-idf:000]: E (516358) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:55:21]
[07:55:21][D][esp-idf:000]: E (516360) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 160 bytes)
[07:55:21]
[07:55:23][D][esp-idf:000]: E (518201) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:55:23]
[07:55:29][D][esp-idf:000]: E (524340) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:55:29]
[07:55:31][D][esp-idf:000]: E (526489) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:55:31]
[07:55:31][D][esp-idf:000]: E (526491) MDNS: Cannot allocate memory (line: 128, free heap: 160 bytes)
[07:55:31]
[07:55:41][D][esp-idf:000]: E (536314) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:55:41]
[07:55:41][D][esp-idf:000]: E (536316) MDNS: Cannot allocate memory (line: 128, free heap: 164 bytes)
[07:55:41]
[07:55:41][D][esp-idf:000]: E (536621) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 228 bytes)
[07:55:41]
[07:55:51][D][esp-idf:000]: E (546444) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 224 bytes)
[07:55:51]
[07:56:01][D][esp-idf:000]: E (556268) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:56:01]
[07:56:37][D][esp-idf:000]: E (592494) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 288 bytes)
[07:56:37]
[07:56:46][D][esp32_ble_tracker:180]: Starting scan...
[07:56:47][D][esp-idf:000]: E (602319) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 216 bytes)
[07:56:47]
[07:56:47][D][esp-idf:000]: E (602321) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 216 bytes)
[07:56:47]
[07:56:49][D][esp-idf:000]: E (604468) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 152 bytes)
[07:56:49]
[07:57:01][D][esp-idf:000]: E (616444) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:57:01]
[07:57:01][D][esp-idf:000]: E (616446) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[07:57:01]
[07:57:17][D][esp-idf:000]: E (632406) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:57:17]
[07:57:43][D][esp-idf:000]: E (658500) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 216 bytes)
[07:57:43]
[07:57:55][D][esp-idf:000]: E (670474) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 280 bytes)
[07:57:55]
[07:58:03][D][esp-idf:000]: E (678455) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 212 bytes)
[07:58:03]
[07:58:14][D][esp-idf:000]: E (688894) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[07:58:14]
[07:58:14][D][esp-idf:000]: E (688896) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[07:58:14]
[07:58:23][D][esp-idf:000]: E (698103) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:58:23]
[07:58:23][D][esp-idf:000]: E (698105) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[07:58:23]
[07:58:58][D][esp-idf:000]: E (733102) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[07:58:58]
[08:00:08][D][esp-idf:000]: E (803098) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 220 bytes)
[08:00:08]
[08:00:08][D][esp-idf:000]: E (803100) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[08:00:08]
[08:00:08][D][esp-idf:000]: E (803108) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[08:00:08]
[08:00:08][D][esp-idf:000]: E (803117) MDNS: Cannot allocate memory (line: 128, free heap: 152 bytes)
[08:00:08]
[08:00:10][D][esp-idf:000]: E (805863) MDNS: Cannot allocate memory (line: 128, free heap: 148 bytes)
[08:00:10]
[08:00:10][D][esp-idf:000]: E (805865) MDNS: Cannot allocate memory (line: 128, free heap: 148 bytes)
[08:00:10]
[08:00:29][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.00000 dBm with 0 decimals of accuracy
[08:00:29][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:29][D][ble_adv:055]: Found Apple Watch, rssi -57
[08:00:29][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state ON
[08:00:29][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.50000 dBm with 0 decimals of accuracy
[08:00:29][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:29][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:29][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:30][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -59.55000 dBm with 0 decimals of accuracy
[08:00:30][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:30][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:30][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:31][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -60.28500 dBm with 0 decimals of accuracy
[08:00:31][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:31][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:31][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:32][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.69950 dBm with 0 decimals of accuracy
[08:00:32][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:32][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:32][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:32][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.28965 dBm with 0 decimals of accuracy
[08:00:32][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:32][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:32][D][ble_adv:055]: Found Apple Watch, rssi -54
[08:00:35][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -59.30275 dBm with 0 decimals of accuracy
[08:00:35][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:35][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:35][D][ble_adv:055]: Found Apple Watch, rssi -64
[08:00:36][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -59.21193 dBm with 0 decimals of accuracy
[08:00:36][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:36][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:36][D][ble_adv:055]: Found Apple Watch, rssi -59
[08:00:36][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.24835 dBm with 0 decimals of accuracy
[08:00:36][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:36][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:36][D][ble_adv:055]: Found Apple Watch, rssi -56
[08:00:37][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.47384 dBm with 0 decimals of accuracy
[08:00:37][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:37][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:37][D][ble_adv:055]: Found Apple Watch, rssi -59
[08:00:38][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.03169 dBm with 0 decimals of accuracy
[08:00:38][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:38][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:38][D][ble_adv:055]: Found Apple Watch, rssi -57
[08:00:39][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.72219 dBm with 0 decimals of accuracy
[08:00:39][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:39][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:39][D][ble_adv:055]: Found Apple Watch, rssi -57
[08:00:39][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -56.30553 dBm with 0 decimals of accuracy
[08:00:39][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:39][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:39][D][ble_adv:055]: Found Apple Watch, rssi -53
[08:00:40][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.31387 dBm with 0 decimals of accuracy
[08:00:40][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:40][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:40][D][ble_adv:055]: Found Apple Watch, rssi -53
[08:00:42][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.21971 dBm with 0 decimals of accuracy
[08:00:42][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:42][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:42][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:43][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.15380 dBm with 0 decimals of accuracy
[08:00:43][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:43][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:43][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:43][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.40766 dBm with 0 decimals of accuracy
[08:00:43][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:43][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:43][D][ble_adv:055]: Found Apple Watch, rssi -56
[08:00:44][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.58536 dBm with 0 decimals of accuracy
[08:00:44][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:44][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:44][D][ble_adv:055]: Found Apple Watch, rssi -56
[08:00:45][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.40975 dBm with 0 decimals of accuracy
[08:00:45][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:45][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:45][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:45][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.38683 dBm with 0 decimals of accuracy
[08:00:45][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:45][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:45][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:46][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -59.07078 dBm with 0 decimals of accuracy
[08:00:46][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:46][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:46][D][ble_adv:055]: Found Apple Watch, rssi -63
[08:00:47][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.84954 dBm with 0 decimals of accuracy
[08:00:47][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:47][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:47][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:47][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -56.99468 dBm with 0 decimals of accuracy
[08:00:47][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:47][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:47][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:48][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -56.39628 dBm with 0 decimals of accuracy
[08:00:48][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:48][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:48][D][ble_adv:055]: Found Apple Watch, rssi -55
[08:00:49][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.07740 dBm with 0 decimals of accuracy
[08:00:49][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:49][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:49][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:50][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.45418 dBm with 0 decimals of accuracy
[08:00:50][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:50][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:50][D][ble_adv:055]: Found Apple Watch, rssi -56
[08:00:51][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -57.01792 dBm with 0 decimals of accuracy
[08:00:51][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:51][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:52][D][ble_adv:055]: Found Apple Watch, rssi -56
[08:00:53][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -58.21254 dBm with 0 decimals of accuracy
[08:00:53][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:53][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:53][D][ble_adv:055]: Found Apple Watch, rssi -61
[08:00:53][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -59.34878 dBm with 0 decimals of accuracy
[08:00:53][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:53][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:53][D][ble_adv:055]: Found Apple Watch, rssi -62
[08:00:55][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -56.84415 dBm with 0 decimals of accuracy
[08:00:55][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:55][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:55][D][ble_adv:055]: Found Apple Watch, rssi -51
[08:00:55][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.99090 dBm with 0 decimals of accuracy
[08:00:55][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:55][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:55][D][ble_adv:055]: Found Apple Watch, rssi -54
[08:00:56][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -54.49363 dBm with 0 decimals of accuracy
[08:00:56][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[08:00:56][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:00:56][D][ble_adv:055]: Found Apple Watch, rssi -51
[08:01:26][D][sensor:131]: 'room_presence_debounce': Sending state 0.66667  with 1 decimals of accuracy
[08:01:26][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:01:40][D][esp-idf:000]: E (894893) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 240 bytes)
[08:01:40]
[08:01:40][D][esp-idf:000]: E (894895) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 244 bytes)
[08:01:40]
[08:01:43][D][esp-idf:000]: E (897963) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 236 bytes)
[08:01:43]
[08:01:43][D][esp-idf:000]: E (897965) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 240 bytes)
[08:01:43]
[08:01:46][D][esp32_ble_tracker:180]: Starting scan...
[08:01:56][D][sensor:131]: 'room_presence_debounce': Sending state 0.33333  with 1 decimals of accuracy
[08:01:56][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:02:26][D][sensor:131]: 'room_presence_debounce': Sending state 0.00000  with 1 decimals of accuracy
[08:02:26][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:02:26][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state OFF
[08:02:30][D][esp-idf:000]: E (945855) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 236 bytes)
[08:02:30]
[08:02:55][D][esp-idf:000]: E (970108) MDNS: Cannot allocate memory (line: 128, free heap: 164 bytes)
[08:02:55]
[08:02:56][D][sensor:131]: 'room_presence_debounce': Sending state 0.00000  with 1 decimals of accuracy
[08:02:56][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[08:03:26][D][sensor:131]: 'room_presence_debounce': Sending state 0.00000  with 1 decimals of accuracy
[08:03:26][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
dalehumby commented 3 years ago

That's fantastic news, I am glad that it is working!

As for the mDNS issue, I am not sure about that. I did a very quick search, and found an issue where it seems like the device may be too memory constrained; or something to do with the wifi network.

For example, I am using a wemos_d1_mini3 with HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash and ESPHome says

Compiling .pioenvs/lounge/src/main.cpp.o
Linking .pioenvs/lounge/firmware.elf
Retrieving maximum program size .pioenvs/lounge/firmware.elf
Checking size .pioenvs/lounge/firmware.elf
RAM:   [==        ]  16.6% (used 54252 bytes from 327680 bytes)
Flash: [========= ]  85.4% (used 1567402 bytes from 1835008 bytes)

My wifi is using b/g/n mode. (Not sure if this is relevant.)

Does your device restart often? Or just give those error messages but otherwise work correctly?

dcgrove commented 3 years ago

This is what it looks like when I compile. I have this set up on two different boards thinking maybe the first was defective. Both take several minutes to begin scanning for BLE with the MDNS errors. If either actually start scanning, they pick up my watch fine for some time, then stop scanning.

HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
PACKAGES: 
 - framework-arduinoespressif32 3.10006.210326 (1.0.6) 
 - tool-esptoolpy 1.30000.201119 (3.0.0) 
 - toolchain-xtensa32 2.50200.97 (5.2.0)
Library Manager: Installing Hash
Library Manager: Already installed, built-in library
Dependency Graph
|-- <AsyncTCP-esphome> 1.2.2
|-- <ESPmDNS> 1.0
|   |-- <WiFi> 1.0
|-- <AsyncMqttClient-esphome> 0.8.4
|   |-- <AsyncTCP-esphome> 1.2.2
|-- <ArduinoJson-esphomelib> 5.13.3
|-- <Update> 1.0
|-- <WiFi> 1.0
Retrieving maximum program size /data/famlr-ble-tracker/.pioenvs/famlr-ble-tracker/firmware.elf
Checking size /data/famlr-ble-tracker/.pioenvs/famlr-ble-tracker/firmware.elf
RAM:   [==        ]  16.4% (used 53780 bytes from 327680 bytes)
Flash: [========  ]  82.4% (used 1511874 bytes from 1835008 bytes)
dcgrove commented 3 years ago

So I am not entirely sure this doesn't have something to do with my wifi or esphome/home assistant setup. Both boards are currently plugged into my office, and both boards just started detecting my watch at exactly the same time. Log from the famlr board is below. You can see where it started working at 11:04

Using 'COM6' as serial port.
Writing at 0x000ec000... (100 %)Wrote 1511984 bytes (905862 compressed) at 0x00010000 in 21.6 seconds (effective 560.7 kbit/s)...
Hash of data verified.

Leaving...
Hard Resetting...
Done! Flashing is complete!

Showing logs:
[10:46:45]ets Jun  8 2016 00:22:57
[10:46:45]
[10:46:45]rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[10:46:45]configsip: 0, SPIWP:0xee
[10:46:45]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[10:46:45]mode:DIO, clock div:2
[10:46:45]load:0x3fff0018,len:4
[10:46:45]load:0x3fff001c,len:1044
[10:46:45]load:0x40078000,len:8896
[10:46:45]load:0x40080400,len:5828
[10:46:45]entry 0x400806ac
[10:46:46][I][logger:170]: Log initialized
[10:46:46][C][ota:378]: There have been 0 suspected unsuccessful boot attempts.
[10:46:46][I][app:029]: Running through setup()...
[10:46:47][D][esp32_ble_tracker:180]: Starting scan...
[10:46:47][C][wifi:037]: Setting up WiFi...
[10:46:47][D][wifi:380]: Starting scan...
[10:46:47][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state OFF
[10:46:50][D][wifi:395]: Found networks:
[10:46:50][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█
[10:46:50][D][wifi:442]:     Channel: 11
[10:46:50][D][wifi:443]:     RSSI: -55 dB
[10:46:50][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█
[10:46:50][D][wifi:442]:     Channel: 1
[10:46:50][D][wifi:443]:     RSSI: -60 dB
[10:46:50][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█
[10:46:50][D][wifi:442]:     Channel: 6
[10:46:50][D][wifi:443]:     RSSI: -72 dB
[10:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█
[10:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█
[10:46:50][D][wifi:445]: - 'prettyfly4awifi' (E2:63:DA:74:2D:3A) ▂▄▆█
[10:46:50][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█
[10:46:50][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█
[10:46:50][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█
[10:46:50][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█
[10:46:50][D][wifi:445]: - 'SpectrumSetup-DF' (02:78:71:37:36:DD) ▂▄▆█
[10:46:50][D][wifi:445]: - 'NETGEAR78' (50:6A:03:BD:D1:B4) ▂▄▆█
[10:46:50][D][wifi:445]: - '' (3E:04:61:AD:23:72) ▂▄▆█
[10:46:50][D][wifi:445]: - 'ATTDspkpPi' (3C:04:61:AD:23:70) ▂▄▆█
[10:46:50][I][wifi:250]: WiFi Connecting to 'nest'...
[10:46:51][W][esp32_ble_tracker:077]: Too many BLE events to process. Some devices may not show up.
[10:46:52][I][wifi:513]: WiFi Connected!
[10:46:52][C][wifi:359]:   SSID: 'nest'
[10:46:52][C][wifi:360]:   IP Address: 192.168.1.134
[10:46:52][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[10:46:52][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[10:46:52][C][wifi:367]:   Signal strength: -60 dB ▂▄▆█
[10:46:52][C][wifi:371]:   Channel: 11
[10:46:52][C][wifi:372]:   Subnet: 255.255.255.0
[10:46:52][C][wifi:373]:   Gateway: 192.168.1.1
[10:46:52][C][wifi:374]:   DNS1: 192.168.1.195
[10:46:52][C][wifi:375]:   DNS2: 0.0.0.0
[10:46:52][C][ota:029]: Over-The-Air Updates:
[10:46:53][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[10:46:53][C][api:022]: Setting up Home Assistant API server...
[10:46:53][C][mqtt:027]: Setting up MQTT...
[10:46:53][I][mqtt:172]: Connecting to MQTT...
[10:46:53][I][mqtt:212]: MQTT Connected!
[10:46:53][I][app:060]: setup() finished successfully!
[10:46:53][I][app:106]: ESPHome version 2021.8.2 compiled on Aug 30 2021, 10:45:17
[10:46:53][C][wifi:499]: WiFi:
[10:46:53][C][wifi:359]:   SSID: 'nest'
[10:46:53][C][wifi:360]:   IP Address: 192.168.1.134
[10:46:53][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[10:46:53][C][wifi:363]:   Hostname: 'famlr-ble-tracker'
[10:46:53][C][wifi:367]:   Signal strength: -59 dB ▂▄▆█
[10:46:53][C][wifi:371]:   Channel: 11
[10:46:53][C][wifi:372]:   Subnet: 255.255.255.0
[10:46:53][C][wifi:373]:   Gateway: 192.168.1.1
[10:46:53][C][wifi:374]:   DNS1: 192.168.1.195
[10:46:53][C][wifi:375]:   DNS2: 0.0.0.0
[10:46:53][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI'
[10:46:53][C][template.sensor:021]:   Device Class: 'signal_strength'
[10:46:53][C][template.sensor:021]:   State Class: ''
[10:46:53][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[10:46:53][C][template.sensor:021]:   Accuracy Decimals: 0
[10:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[10:46:53][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[10:46:53][C][template.sensor:021]:   State Class: ''
[10:46:53][C][template.sensor:021]:   Unit of Measurement: ''
[10:46:53][C][template.sensor:021]:   Accuracy Decimals: 1
[10:46:53][C][template.sensor:022]:   Update Interval: 60.0s
[10:46:53][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton famlr-ble-tracker presence'
[10:46:53][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[10:46:53][C][logger:189]: Logger:
[10:46:53][C][logger:190]:   Level: DEBUG
[10:46:53][C][logger:191]:   Log Baud Rate: 115200
[10:46:53][C][logger:192]:   Hardware UART: UART0
[10:46:53][C][esp32_ble_tracker:606]: BLE Tracker:
[10:46:53][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[10:46:53][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[10:46:53][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[10:46:53][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[10:46:53][C][ota:029]: Over-The-Air Updates:
[10:46:53][C][ota:030]:   Address: famlr-ble-tracker.local:3232
[10:46:53][C][api:095]: API Server:
[10:46:53][C][api:096]:   Address: famlr-ble-tracker.local:6053
[10:46:53][C][mqtt:061]: MQTT:
[10:46:53][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[10:46:53][C][mqtt:064]:   Username: 'clayton'
[10:46:53][C][mqtt:065]:   Client ID: 'famlr-ble-tracker-94b97ee53324'
[10:46:53][C][mqtt:070]:   Topic Prefix: 'famlr-ble-tracker'
[10:46:53][C][mqtt:072]:   Log Topic: 'famlr-ble-tracker/debug'
[10:46:53][C][mqtt:075]:   Availability: 'famlr-ble-tracker/status'
[10:46:53][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[10:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/room_presence_debounce/state'
[10:46:53][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton famlr-ble-tracker presence':
[10:46:53][C][mqtt.binary_sensor:019]:   State Topic: 'famlr-ble-tracker/binary_sensor/clayton_famlr-ble-tracker_presence/state'
[10:46:53][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch famlr-ble-tracker RSSI':
[10:46:53][C][mqtt.sensor:028]:   State Topic: 'famlr-ble-tracker/sensor/clayton_apple_watch_famlr-ble-tracker_rssi/state'
[10:46:54][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully!
[10:51:46][I][ota:046]: Boot seems successful, resetting boot loop counter.
[10:51:47][D][esp32_ble_tracker:180]: Starting scan...
[10:52:16][D][esp-idf:000]: E (331529) MDNS: Cannot allocate memory (line: 128, free heap: 200 bytes)
[10:52:16]
[10:52:16][D][esp-idf:000]: E (331531) MDNS: Cannot allocate memory (line: 128, free heap: 200 bytes)
[10:52:16]
[10:52:32][D][esp-idf:000]: E (347495) MDNS: Cannot allocate memory (line: 128, free heap: 204 bytes)
[10:52:32]
[10:53:00][D][esp-idf:000]: E (375124) MDNS_Networking: Cannot allocate memory (line: 123, free heap: 272 bytes)
[10:53:00]
[10:56:47][D][esp32_ble_tracker:180]: Starting scan...
[11:01:47][D][esp32_ble_tracker:180]: Starting scan...
[11:04:25][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -69.00000 dBm with 0 decimals of accuracy
[11:04:25][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:25][D][ble_adv:055]: Found Apple Watch, rssi -69
[11:04:25][D][binary_sensor:036]: 'Clayton famlr-ble-tracker presence': Sending state ON
[11:04:27][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -67.50000 dBm with 0 decimals of accuracy
[11:04:27][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:27][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:27][D][ble_adv:055]: Found Apple Watch, rssi -64
[11:04:28][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -67.05000 dBm with 0 decimals of accuracy
[11:04:28][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:28][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:28][D][ble_adv:055]: Found Apple Watch, rssi -66
[11:04:29][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -72.73500 dBm with 0 decimals of accuracy
[11:04:29][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:29][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:29][D][ble_adv:055]: Found Apple Watch, rssi -86
[11:04:29][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -75.81450 dBm with 0 decimals of accuracy
[11:04:29][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:29][D][ble_adv:055]: Found Apple Watch, rssi -83
[11:04:30][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -72.87015 dBm with 0 decimals of accuracy
[11:04:30][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:30][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:30][D][ble_adv:055]: Found Apple Watch, rssi -66
[11:04:31][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -71.10910 dBm with 0 decimals of accuracy
[11:04:31][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:31][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:31][D][ble_adv:055]: Found Apple Watch, rssi -67
[11:04:32][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -69.57637 dBm with 0 decimals of accuracy
[11:04:32][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:32][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:32][D][ble_adv:055]: Found Apple Watch, rssi -66
[11:04:33][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -74.20346 dBm with 0 decimals of accuracy
[11:04:33][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:33][D][ble_adv:055]: Found Apple Watch, rssi -85
[11:04:34][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -70.54242 dBm with 0 decimals of accuracy
[11:04:34][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:34][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:34][D][ble_adv:055]: Found Apple Watch, rssi -62
[11:04:35][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -68.27969 dBm with 0 decimals of accuracy
[11:04:35][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:35][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:35][D][ble_adv:055]: Found Apple Watch, rssi -63
[11:04:35][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -66.09579 dBm with 0 decimals of accuracy
[11:04:35][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:35][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:35][D][ble_adv:055]: Found Apple Watch, rssi -61
[11:04:36][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -68.16705 dBm with 0 decimals of accuracy
[11:04:36][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:36][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:36][D][ble_adv:055]: Found Apple Watch, rssi -73
[11:04:39][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -60.61694 dBm with 0 decimals of accuracy
[11:04:39][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:39][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:39][D][ble_adv:055]: Found Apple Watch, rssi -43
[11:04:40][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -55.33186 dBm with 0 decimals of accuracy
[11:04:40][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:40][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:40][D][ble_adv:055]: Found Apple Watch, rssi -43
[11:04:41][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -51.93230 dBm with 0 decimals of accuracy
[11:04:41][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:41][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:41][D][ble_adv:055]: Found Apple Watch, rssi -44
[11:04:42][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -49.25261 dBm with 0 decimals of accuracy
[11:04:42][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:42][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:42][D][ble_adv:055]: Found Apple Watch, rssi -43
[11:04:43][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -47.67683 dBm with 0 decimals of accuracy
[11:04:43][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:43][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:43][D][ble_adv:055]: Found Apple Watch, rssi -44
[11:04:43][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -47.17378 dBm with 0 decimals of accuracy
[11:04:43][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:43][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:43][D][ble_adv:055]: Found Apple Watch, rssi -46
[11:04:44][D][sensor:131]: 'Clayton Apple Watch famlr-ble-tracker RSSI': Sending state -47.12165 dBm with 0 decimals of accuracy
[11:04:44][D][sensor:131]: 'room_presence_debounce': Sending state 1.00000  with 1 decimals of accuracy
[11:04:44][D][script:020]: Script 'presence_timeout' restarting (mode: restart)
[11:04:44][D][ble_adv:055]: Found Apple Watch, rssi -47
dalehumby commented 3 years ago

It could very well be a wifi/router issue. What confuses me is that you didn't have the mdns errors in your original pastebin logs. Maybe the ESP is connected to a different AP now? I also noticed in the pastebin that DNS1: 0.0.0.0, although not sure if that's helpful.

I tried decreasing interval and increasing window and removing the if statement so it finds all bluetooth devices to try overload the ESP but never go the mdns error.

If you have a BLE tag, you could try setting up a basic ble_presence or ble_rssi sensor as described in https://esphome.io/components/esp32_ble_tracker.html, and see if you get the same issue. If you don't have a tag you can use your Apple Watch until it changes its mac address. Use this debug log to find its current mac:

ESP_LOGD("ble_adv", "Found Apple Watch (mac %s) rssi %i", x.address_str().c_str(), rssi);
dcgrove commented 3 years ago

I found the MDNS errors when watching the logs after I flashed it over USB with esphomeflasher. The log viewer in ESPhome does not show the mdns error for some reason. I can't get it to flash OTA at all as it says the peer has reset the connection at about 20-30% completion. Both boards have been plugged in all day, and were working this morning. You can see from the graphs below of the RSSI values that they stop picking anything up around 12:15and then start working again around 3:40. famlrgraph office graph

dalehumby commented 3 years ago

Maybe there are too many BLE devices detected and not enough time to process them all? I managed to recreate the "not able to upgrade via OTA" by setting interval from 1.2s to 800ms, and mine said peer reset connection at about 60%. Perhaps running out of RAM to store firmware during download.

Ref: BLE Tracker configuration

dalehumby commented 3 years ago

I've added some more debug, in case the problem with your watch not being detected is that there are more flags that the code should be detecting:

  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 YY 98 XXXXXX
      # Where YY can be 01, 0B, 0D; and XXXXXX is ignored
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 && data.data[3] == 0x98) {
              int16_t ac = data.data[2];
              int16_t rssi = x.get_rssi();
              if (ac == 0x01 || ac == 0x0B || ac == 0x0D) {
                id(apple_watch_rssi).publish_state(rssi);
                ESP_LOGD("ble_adv", "Found Apple Watch (mac %s) rssi %i", x.address_str().c_str(), rssi);
              } else {
                ESP_LOGD("ble_adv", "Possible Apple Watch? (mac %s) rssi %i, unrecognised action code %#04x", x.address_str().c_str(), rssi, ac);
              }
            }
          }

If you see the "Possible Apple Watch?" message please send me those debug messages.

dcgrove commented 3 years ago

Thanks for the continued troubleshooting! Here are the logs with the new on_ble_advertise code.

Using 'COM5' as serial port.
Writing at 0x000f4000... (100 %)Wrote 1578528 bytes (942406 compressed) at 0x00010000 in 22.4 seconds (effective 564.5 kbit/s)...
Hash of data verified.

Leaving...
Hard Resetting...
Done! Flashing is complete!

Showing logs:
[12:39:36][I][logger:170]: Log initialized
[12:39:36][V][preferences:260]: nvs_get_blob('0'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[12:39:36][C][ota:378]: There have been 0 suspected unsuccessful boot attempts.
[12:39:36][I][app:029]: Running through setup()...
[12:39:36][V][app:030]: Sorting components by setup priority...
[12:39:37][D][esp32_ble_tracker:180]: Starting scan...
[12:39:37][D][binary_sensor:034]: 'Office BLE Tracker Status': Sending initial state OFF
[12:39:37][C][wifi:037]: Setting up WiFi...
[12:39:37][V][preferences:260]: nvs_get_blob('1'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[12:39:37][V][wifi_esp32:036]: Enabling STA.
[12:39:37][V][esp-idf:000]: I (846) wifi:
[12:39:37][V][esp-idf:000]: wifi driver task: 3ffe3b78, prio:23, stack:3584, core=0
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (1966) wifi:
[12:39:37][V][esp-idf:000]: wifi firmware version: dc30037
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (1967) wifi:
[12:39:37][V][esp-idf:000]: config NVS flash: enabled
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (1979) wifi:
[12:39:37][V][esp-idf:000]: config nano formating: disabled
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (1991) wifi:
[12:39:37][V][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2004) wifi:
[12:39:37][V][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2017) wifi:
[12:39:37][V][esp-idf:000]: Init management short buffer num: 32
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2030) wifi:
[12:39:37][V][esp-idf:000]: Init dynamic tx buffer num: 32
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2042) wifi:
[12:39:37][V][esp-idf:000]: Init static rx buffer size: 1600
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2054) wifi:
[12:39:37][V][esp-idf:000]: Init static rx buffer num: 16
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2066) wifi:
[12:39:37][V][esp-idf:000]: Init dynamic rx buffer num: 32
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][V][esp-idf:000]: I (2090) wifi:
[12:39:37][V][esp-idf:000]: mode : sta (94:b9:7e:e6:53:b8)
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 0 - WIFI_READY
[12:39:37][V][wifi_esp32:394]: Event: WiFi ready[D][WiFiGeneric.cpp:374] _eventCallback(): Event: 2 - STA_START
[12:39:37][V][wifi_esp32:407]: Event: WiFi STA start
[12:39:37][V][esp-idf:000]: I (2116) wifi:
[12:39:37][V][esp-idf:000]: Set ps type: 1
[12:39:37]
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][D][wifi:380]: Starting scan...
[12:39:37][V][esp-idf:000]: W (2126) wifi:
[12:39:37][V][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!
[12:39:37]
[12:39:37][V][esp-idf:000]: 
[12:39:37]
[12:39:37][D][binary_sensor:036]: 'Clayton office presence': Sending state OFF
[12:39:37][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -56, unrecognised action code 0x0a
[12:39:38][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -66, unrecognised action code 0x0a
[12:39:38][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -64, unrecognised action code 0x0a
[12:39:40][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -63, unrecognised action code 0x0a
[12:39:40][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 1 - SCAN_DONE
[12:39:40][V][wifi_esp32:403]: Event: WiFi Scan Done status=0 number=13 scan_id=128
[12:39:40][D][wifi:395]: Found networks:
[12:39:40][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█
[12:39:40][D][wifi:442]:     Channel: 6
[12:39:40][D][wifi:443]:     RSSI: -69 dB
[12:39:40][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█
[12:39:40][D][wifi:442]:     Channel: 1
[12:39:40][D][wifi:443]:     RSSI: -72 dB
[12:39:40][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█
[12:39:40][D][wifi:442]:     Channel: 11
[12:39:40][D][wifi:443]:     RSSI: -81 dB
[12:39:40][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█
[12:39:40][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█
[12:39:40][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█
[12:39:40][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█
[12:39:40][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█
[12:39:40][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█
[12:39:40][D][wifi:445]: - 'SpectrumSetup-DF' (02:78:71:37:36:DD) ▂▄▆█
[12:39:40][D][wifi:445]: - 'Cloud Mesh' (E8:9F:80:59:F8:C1) ▂▄▆█
[12:39:40][D][wifi:445]: - 'ATTDspkpPi' (3C:04:61:AD:23:70) ▂▄▆█
[12:39:40][D][wifi:445]: - '' (3E:04:61:AD:23:72) ▂▄▆█
[12:39:40][I][wifi:250]: WiFi Connecting to 'nest'...
[12:39:40][V][wifi:252]: Connection Params:
[12:39:40][V][wifi:253]:   SSID: 'nest'
[12:39:40][V][wifi:256]:   BSSID: 80:2A:A8:57:22:F0
[12:39:40][V][wifi:276]:   Password: 'leftycj7'
[12:39:40][V][wifi:281]:   Channel: 6
[12:39:40][V][wifi:289]:   Manual IP: Static IP=192.168.1.178 Gateway=192.168.1.1 Subnet=255.255.255.0 DNS1=0.0.0.0 DNS2=0.0.0.0
[12:39:40][V][wifi:293]:   Hidden: NO
[12:39:40][V][esp-idf:000]: I (5502) wifi:
[12:39:40][V][esp-idf:000]: new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
[12:39:40][V][esp-idf:000]: 
[12:39:40]
[12:39:41][V][esp-idf:000]: I (6248) wifi:
[12:39:41][V][esp-idf:000]: state: init -> auth (b0)
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][V][esp-idf:000]: I (6266) wifi:
[12:39:41][V][esp-idf:000]: state: auth -> assoc (0)
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][V][esp-idf:000]: I (6283) wifi:
[12:39:41][V][esp-idf:000]: state: assoc -> run (10)
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][V][esp-idf:000]: I (6326) wifi:
[12:39:41][V][esp-idf:000]: connected with nest, aid = 8, channel 6, BW20, bssid = 80:2a:a8:57:22:f0
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][V][esp-idf:000]: I (6332) wifi:
[12:39:41][V][esp-idf:000]: security type: 3, phy: bgn, rssi: -63
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][V][esp-idf:000]: I (6345) wifi:
[12:39:41][V][esp-idf:000]: pm start, type: 1
[12:39:41]
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 7 - STA_GOT_IP
[12:39:41][D][WiFiGeneric.cpp:419] _eventCallback(): STA IP: 192.168.1.178, MASK: 255.255.255.0, GW: 192.168.1.1
[12:39:41][V][wifi:513]: WiFi Connected![I][wifi:513]: WiFi Connected!
[12:39:41][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 7 - STA_GOT_IP
[12:39:41][C][wifi:359]:   SSID: 'nest'[D][WiFiGeneric.cpp:419] _eventCallback(): STA IP: 192.168.1.178, MASK: 255.255.255.0, GW: 192.168.1.1
[12:39:41][C][wifi_esp32:470]: Event: Got IP static_ip=1[V][wifi_esp32:470]: Event: Got IP static_ip=192.168.1.178 gateway=192.168.1.1
[12:39:41][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[12:39:41]
[12:39:41][C][wip-idf:000]: I (6419) wifi:
[12:39:41][V][esp-idf:000]: I (6419) wifi:
[12:39:41][V][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 3
[12:39:41][V][esp-idf:000]: 
[12:39:41]
[12:39:41][C][wifi:367]:   Signal strength: -64 dB ▂▄▆█
[12:39:41][V][wifi:369]:   Priority: 0.0
[12:39:41][C][wifi:371]:   Channel: 6
[12:39:41][C][wifi:372]:   Subnet: 255.255.255.0
[12:39:41][C][wifi:373]:   Gateway: 192.168.1.1
[12:39:41][C][wifi:374]:   DNS1: 0.0.0.0
[12:39:41][C][wifi:375]:   DNS2: 0.0.0.0
[12:39:41][D][wifi:522]: Disabling AP...
[12:39:41][C][ota:029]: Over-The-Air Updates:
[12:39:41][C][ota:030]:   Address: 192.168.1.178:3232
[12:39:41][C][api:022]: Setting up Home Assistant API server...
[12:39:41][C][mqtt:027]: Setting up MQTT...
[12:39:41][I][mqtt:172]: Connecting to MQTT...
[12:39:42][W][AsyncTCP.cpp:966] _poll(): pcb is NULL
[12:39:42][I][mqtt:212]: MQTT Connected!
[12:39:42][V][mqtt:402]: Publish(topic='office-ble-tracker/binary_sensor/clayton_office_presence/state' payload='OFF' retain=1)
[12:39:42][I][app:060]: setup() finished successfully!
[12:39:42][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -59, unrecognised action code 0x0a
[12:39:42][V][mqtt:402]: Publish(topic='office-ble-tracker/status' payload='online' retain=1)
[12:39:42][I][app:106]: ESPHome version 2021.8.2 compiled on Sep  1 2021, 12:37:36
[12:39:42][C][wifi:499]: WiFi:
[12:39:42][C][wifi:359]:   SSID: 'nest'
[12:39:42][C][wifi:360]:   IP Address: 192.168.1.178
[12:39:42][C][wifi:362]:   BSSID: 80:2A:A8:57:22:F0
[12:39:42][C][wifi:363]:   Hostname: 'office-ble-tracker'
[12:39:42][C][wifi:367]:   Signal strength: -65 dB ▂▄▆█
[12:39:42][V][wifi:369]:   Priority: 0.0
[12:39:42][C][wifi:371]:   Channel: 6
[12:39:42][C][wifi:372]:   Subnet: 255.255.255.0
[12:39:42][C][wifi:373]:   Gateway: 192.168.1.1
[12:39:42][C][wifi:374]:   DNS1: 0.0.0.0
[12:39:42][C][wifi:375]:   DNS2: 0.0.0.0
[12:39:42][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch office RSSI'
[12:39:42][C][template.sensor:021]:   Device Class: 'signal_strength'
[12:39:42][C][template.sensor:021]:   State Class: ''
[12:39:42][C][template.sensor:021]:   Unit of Measurement: 'dBm'
[12:39:42][C][template.sensor:021]:   Accuracy Decimals: 0
[12:39:42][C][template.sensor:022]:   Update Interval: 60.0s
[12:39:42][C][template.sensor:021]: Template Sensor 'room_presence_debounce'
[12:39:42][C][template.sensor:021]:   State Class: ''
[12:39:42][C][template.sensor:021]:   Unit of Measurement: ''
[12:39:42][C][template.sensor:021]:   Accuracy Decimals: 1
[12:39:42][C][template.sensor:022]:   Update Interval: 60.0s
[12:39:42][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton office presence'
[12:39:42][C][template.binary_sensor:018]:   Device Class: 'occupancy'
[12:39:42][C][logger:189]: Logger:
[12:39:42][C][logger:190]:   Level: VERBOSE
[12:39:42][C][logger:191]:   Log Baud Rate: 115200
[12:39:42][C][logger:192]:   Hardware UART: UART0
[12:39:42][C][esp32_ble_tracker:606]: BLE Tracker:
[12:39:42][C][esp32_ble_tracker:607]:   Scan Duration: 300 s
[12:39:42][C][esp32_ble_tracker:608]:   Scan Interval: 1200.0 ms
[12:39:42][C][esp32_ble_tracker:609]:   Scan Window: 500.0 ms
[12:39:42][C][esp32_ble_tracker:610]:   Scan Type: PASSIVE
[12:39:42][C][status:034]: Status Binary Sensor 'Office BLE Tracker Status'
[12:39:42][C][status:034]:   Device Class: 'connectivity'
[12:39:42][C][captive_portal:148]: Captive Portal:
[12:39:42][C][ota:029]: Over-The-Air Updates:
[12:39:42][C][ota:030]:   Address: 192.168.1.178:3232
[12:39:42][C][api:095]: API Server:
[12:39:42][C][api:096]:   Address: 192.168.1.178:6053
[12:39:42][C][mqtt:061]: MQTT:
[12:39:42][C][mqtt:063]:   Server Address: 192.168.1.205:1883 (192.168.1.205)
[12:39:42][C][mqtt:064]:   Username: 'clayton'
[12:39:42][C][mqtt:065]:   Client ID: 'office-ble-tracker-94b97ee653b8'
[12:39:42][C][mqtt:070]:   Topic Prefix: 'office-ble-tracker'
[12:39:42][C][mqtt:072]:   Log Topic: 'office-ble-tracker/debug'
[12:39:42][C][mqtt:075]:   Availability: 'office-ble-tracker/status'
[12:39:42][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce':
[12:39:42][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/room_presence_debounce/state'
[12:39:42][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Office BLE Tracker Status':
[12:39:42][C][mqtt.binary_sensor:019]:   State Topic: 'office-ble-tracker/status'
[12:39:42][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton office presence':
[12:39:42][C][mqtt.binary_sensor:019]:   State Topic: 'office-ble-tracker/binary_sensor/clayton_office_presence/state'
[12:39:42][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch office RSSI':
[12:39:42][C][mqtt.sensor:028]:   State Topic: 'office-ble-tracker/sensor/clayton_apple_watch_office_rssi/state'
[12:39:43][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -61, unrecognised action code 0x0a
[12:39:44][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -60, unrecognised action code 0x0a
[12:39:46][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -57, unrecognised action code 0x0a
[12:39:47][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -62, unrecognised action code 0x0a
[12:39:48][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -58, unrecognised action code 0x0a
[12:39:48][D][binary_sensor:036]: 'Office BLE Tracker Status': Sending state ON
[12:39:48][V][api.connection:714]: Hello from client: 'Home Assistant 2021.8.8 (192.168.1.205)'
[12:39:48][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully!
[12:39:49][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -56, unrecognised action code 0x0a
[12:39:49][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -58, unrecognised action code 0x0a
[12:39:50][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -58, unrecognised action code 0x0a
[12:39:53][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -60, unrecognised action code 0x0a
[12:39:53][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -57, unrecognised action code 0x0a
[12:39:54][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -61, unrecognised action code 0x0a
[12:39:55][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -52, unrecognised action code 0x0a
[12:39:56][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -51, unrecognised action code 0x0a
[12:39:56][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -50, unrecognised action code 0x0a
[12:39:57][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -51, unrecognised action code 0x0a
[12:39:58][D][ble_adv:058]: Possible Apple Watch? (mac 4F:8A:F9:51:6D:F3) rssi -51, unrecognised action code 0x0a
dalehumby commented 3 years ago

Thanks for the debug log. I have updated the code to detect the new 0x0a value:

  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 YY 98 XXXXXX
      # Where YY can be 01, 0A, 0B, 0D; and XXXXXX is ignored
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 && data.data[3] == 0x98) {
              int16_t ac = data.data[2];
              int16_t rssi = x.get_rssi();
              if (ac == 0x01 || ac == 0x0A || ac == 0x0B || ac == 0x0D) {
                id(apple_watch_rssi).publish_state(rssi);
                ESP_LOGD("ble_adv", "Found Apple Watch (mac %s) rssi %i", x.address_str().c_str(), rssi);
              } else {
                ESP_LOGD("ble_adv", "Possible Apple Watch? (mac %s) rssi %i, unrecognised action code %#04x", x.address_str().c_str(), rssi, ac);
              }
            }
          }

You'll see I added || ac == 0x0A to the if statement. If you come across any "Possible Apple Watch?" messages and you are sure it's your watch, you can add another "or" clause to the if statement.

dcgrove commented 3 years ago

I made the changes. Here is the log file.

https://pastebin.com/3hRzcM8B

You can see from the very beginning I started getting this message :

Possible Apple Watch? (mac 79:F5:61:70:E2:29) rssi -53, unrecognised action code 0x0f

I left the house at 15:33:04 and the messages stopped. I am not sure what the error at 15:33:33 means. I got home at 15:49:05 and the watch was picked up, but it looks to be a different mac address.

dcgrove commented 3 years ago

I restarted the esp32 with my watch off my wrist so that it was unlocked as I wanted to run a test. I put the watch on and unlocked it at 16:10:30, and took it off again at 16:10:59. I repeated this at 16:13:10 and 16:13:57. This has to match my watch as it was the only messages I received in the log while my watch was on.

Using 'COM5' as serial port. Showing logs: [16:07:29]ets Jun 8 2016 00:22:57 [16:07:29] [16:07:29]rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) [16:07:29]flash read err, 1000 [16:07:29]ets_main.c 371 [16:07:30]ets Jun 8 2016 00:22:57 [16:07:30] [16:07:30]rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) [16:07:30]configsip: 0, SPIWP:0xee [16:07:30]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 [16:07:30]mode:DIO, clock div:2 [16:07:30]load:0x3fff0018,len:4 [16:07:30]load:0x3fff001c,len:1044 [16:07:30]load:0x40078000,len:8896 [16:07:30]load:0x40080400,len:5828 [16:07:30]entry 0x400806ac [16:07:30][I][logger:170]: Log initialized [16:07:30][C][ota:378]: There have been 1 suspected unsuccessful boot attempts. [16:07:30][I][app:029]: Running through setup()... [16:07:30][V][app:030]: Sorting components by setup priority... [16:07:31][D][esp32_ble_tracker:180]: Starting scan... [16:07:31][D][binary_sensor:034]: 'Office BLE Tracker Status': Sending initial state OFF [16:07:31][C][wifi:037]: Setting up WiFi... [16:07:31][V][preferences:260]: nvs_get_blob('1'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet [16:07:31][V][wifi_esp32:036]: Enabling STA. [16:07:31][V][esp-idf:000]: I (791) wifi: [16:07:31][V][esp-idf:000]: wifi driver task: 3ffe3ba4, prio:23, stack:3584, core=0 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1816) wifi: [16:07:31][V][esp-idf:000]: wifi firmware version: dc30037 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1817) wifi: [16:07:31][V][esp-idf:000]: config NVS flash: enabled [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1829) wifi: [16:07:31][V][esp-idf:000]: config nano formating: disabled [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1841) wifi: [16:07:31][V][esp-idf:000]: Init data frame dynamic rx buffer num: 32 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1854) wifi: [16:07:31][V][esp-idf:000]: Init management frame dynamic rx buffer num: 32 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1867) wifi: [16:07:31][V][esp-idf:000]: Init management short buffer num: 32 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1880) wifi: [16:07:31][V][esp-idf:000]: Init dynamic tx buffer num: 32 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1892) wifi: [16:07:31][V][esp-idf:000]: Init static rx buffer size: 1600 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1905) wifi: [16:07:31][V][esp-idf:000]: Init static rx buffer num: 16 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1916) wifi: [16:07:31][V][esp-idf:000]: Init dynamic rx buffer num: 32 [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][V][esp-idf:000]: I (1939) wifi: [16:07:31][V][esp-idf:000]: mode : sta (94:b9:7e:e6:53:b8) [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 0 - WIFI_READY [16:07:31][V][wifi_esp32:394]: Event: WiFi ready [16:07:31][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 2 - STA_START [16:07:31][V][wifi_esp32:407]: Event: WiFi STA start [16:07:31][V][esp-idf:000]: I (1961) wifi: [16:07:31][V][esp-idf:000]: Set ps type: 1 [16:07:31] [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][D][wifi:380]: Starting scan... [16:07:31][V][esp-idf:000]: W (1976) wifi: [16:07:31][V][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!! [16:07:31] [16:07:31][V][esp-idf:000]: [16:07:31] [16:07:31][D][binary_sensor:036]: 'Clayton office presence': Sending state OFF [16:07:31][W][esp32_ble_tracker:077]: Too many BLE events to process. Some devices may not show up. [16:07:35][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 1 - SCAN_DONE [16:07:35][V][wifi_esp32:403]: Event: WiFi Scan Done status=0 number=12 scan_id=128 [16:07:35][D][wifi:395]: Found networks: [16:07:35][I][wifi:441]: - 'nest' (80:2A:A8:57:22:F0) ▂▄▆█ [16:07:35][D][wifi:442]: Channel: 6 [16:07:35][D][wifi:443]: RSSI: -60 dB [16:07:35][I][wifi:441]: - 'nest' (E0:63:DA:74:2D:3A) ▂▄▆█ [16:07:35][D][wifi:442]: Channel: 11 [16:07:35][D][wifi:443]: RSSI: -74 dB [16:07:35][I][wifi:441]: - 'nest' (80:2A:A8:44:7F:AB) ▂▄▆█ [16:07:35][D][wifi:442]: Channel: 1 [16:07:35][D][wifi:443]: RSSI: -78 dB [16:07:35][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:57:22:F0) ▂▄▆█ [16:07:35][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:57:22:F0) ▂▄▆█ [16:07:35][D][wifi:445]: - 'daddyisawesome' (F2:63:DA:74:2D:3A) ▂▄▆█ [16:07:35][D][wifi:445]: - 'prettyfly4awifi' (E2:63:DA:74:2D:3A) ▂▄▆█ [16:07:35][D][wifi:445]: - 'Linksys07248_2GEXT' (C0:FF:D4:85:E0:0B) ▂▄▆█ [16:07:35][D][wifi:445]: - 'prettyfly4awifi' (86:2A:A8:44:7F:AB) ▂▄▆█ [16:07:35][D][wifi:445]: - 'daddyisawesome' (8A:2A:A8:44:7F:AB) ▂▄▆█ [16:07:35][D][wifi:445]: - 'NETGEAR78' (50:6A:03:BD:D1:B4) ▂▄▆█ [16:07:35][D][wifi:445]: - 'Home' (F0:2F:74:91:C5:E9) ▂▄▆█ [16:07:35][I][wifi:250]: WiFi Connecting to 'nest'... [16:07:35][V][wifi:252]: Connection Params:

[16:07:35][V][wifi:256]: BSSID: 80:2A:A8:57:22:F0

[16:07:35][V][wifi:281]: Channel: 6 [16:07:35][V][wifi:289]: Manual IP: Static IP=192.168.1.178 Gateway=192.168.1.1 Subnet=255.255.255.0 DNS1=0.0.0.0 DNS2=0.0.0.0 [16:07:35][V][wifi:293]: Hidden: NO [16:07:35][V][esp-idf:000]: I (5391) wifi: [16:07:35][V][esp-idf:000]: new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1 [16:07:35][V][esp-idf:000]: [16:07:35] [16:07:36][V][esp-idf:000]: I (6137) wifi: [16:07:36][V][esp-idf:000]: state: init -> auth (b0) [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6155) wifi: [16:07:36][V][esp-idf:000]: state: auth -> assoc (0) [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6166) wifi: [16:07:36][V][esp-idf:000]: state: assoc -> run (10) [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6199) wifi: [16:07:36][V][esp-idf:000]: connected with nest, aid = 8, channel 6, BW20, bssid = 80:2a:a8:57:22:f0 [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6204) wifi: [16:07:36][V][esp-idf:000]: security type: 3, phy: bgn, rssi: -54 [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6217) wifi: [16:07:36][V][esp-idf:000]: pm start, type: 1 [16:07:36] [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][V][esp-idf:000]: I (6229) wifi: [16:07:36][V][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 3 [16:07:36][V][esp-idf:000]: [16:07:36] [16:07:36][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 7 - STA_GOT_IP [16:07:36][D][WiFiGeneric.cpp:419] _eventCallback(): STA IP: 192.168.1.178, MASK: 255.255.255.0, GW: 192.168.1.1 [16:07:36][V][wifi_esp32:470]: Event: Got IP static_ip=192.168.1.178 gateway=192.168.1.1 [16:07:36][D][WiFiGeneric.cpp:374] _eventCallback(): Event: 7 - STA_GOT_IP [16:07:36][D][WiFiGeneric.cpp:419] _eventCallback(): STA IP: 192.168.1.178, MASK: 255.255.255.0, GW: 192.168.1.1 [16:07:36][V][wifi_esp32:470]: Event: Got IP static_ip=192.168.1.178 gateway=192.168.1.1 [16:07:36][I][wifi:513]: WiFi Connected!

[16:07:36][C][wifi:360]: IP Address: 192.168.1.178 [16:07:36][C][wifi:362]: BSSID: 80:2A:A8:57:22:F0

[16:07:36][C][wifi:367]: Signal strength: -55 dB ▂▄▆█ [16:07:36][V][wifi:369]: Priority: 0.0 [16:07:36][C][wifi:371]: Channel: 6 [16:07:36][C][wifi:372]: Subnet: 255.255.255.0 [16:07:36][C][wifi:373]: Gateway: 192.168.1.1 [16:07:36][C][wifi:374]: DNS1: 0.0.0.0 [16:07:36][C][wifi:375]: DNS2: 0.0.0.0 [16:07:36][D][wifi:522]: Disabling AP... [16:07:36][C][ota:029]: Over-The-Air Updates: [16:07:36][C][ota:030]: Address: 192.168.1.178:3232 [16:07:36][C][api:022]: Setting up Home Assistant API server... [16:07:36][C][mqtt:027]: Setting up MQTT... [16:07:36][I][mqtt:172]: Connecting to MQTT... [16:07:36][I][mqtt:212]: MQTT Connected! [16:07:36][V][mqtt:402]: Publish(topic='office-ble-tracker/binary_sensor/clayton_office_presence/state' payload='OFF' retain=1) [16:07:36][I][app:060]: setup() finished successfully! [16:07:36][V][mqtt:402]: Publish(topic='office-ble-tracker/status' payload='online' retain=1) [16:07:36][I][app:106]: ESPHome version 2021.8.2 compiled on Sep 1 2021, 15:24:35

[16:07:36][C][wifi:360]: IP Address: 192.168.1.178 [16:07:36][C][wifi:362]: BSSID: 80:2A:A8:57:22:F0

[16:07:36][C][wifi:367]: Signal strength: -55 dB ▂▄▆█ [16:07:36][V][wifi:369]: Priority: 0.0 [16:07:36][C][wifi:371]: Channel: 6 [16:07:36][C][wifi:372]: Subnet: 255.255.255.0 [16:07:36][C][wifi:373]: Gateway: 192.168.1.1 [16:07:36][C][wifi:374]: DNS1: 0.0.0.0 [16:07:36][C][wifi:375]: DNS2: 0.0.0.0 [16:07:36][C][template.sensor:021]: Template Sensor 'Clayton Apple Watch office RSSI' [16:07:36][C][template.sensor:021]: Device Class: 'signal_strength' [16:07:36][C][template.sensor:021]: State Class: '' [16:07:36][C][template.sensor:021]: Unit of Measurement: 'dBm' [16:07:36][C][template.sensor:021]: Accuracy Decimals: 0 [16:07:36][C][template.sensor:022]: Update Interval: 60.0s [16:07:36][C][template.sensor:021]: Template Sensor 'room_presence_debounce' [16:07:36][C][template.sensor:021]: State Class: '' [16:07:36][C][template.sensor:021]: Unit of Measurement: '' [16:07:36][C][template.sensor:021]: Accuracy Decimals: 1 [16:07:36][C][template.sensor:022]: Update Interval: 60.0s [16:07:36][C][template.binary_sensor:018]: Template Binary Sensor 'Clayton office presence' [16:07:36][C][template.binary_sensor:018]: Device Class: 'occupancy'

[16:07:36][C][logger:190]: Level: VERBOSE [16:07:36][C][logger:191]: Log Baud Rate: 115200 [16:07:36][C][logger:192]: Hardware UART: UART0 [16:07:36][C][esp32_ble_tracker:606]: BLE Tracker: [16:07:36][C][esp32_ble_tracker:607]: Scan Duration: 300 s [16:07:36][C][esp32_ble_tracker:608]: Scan Interval: 1200.0 ms [16:07:36][C][esp32_ble_tracker:609]: Scan Window: 500.0 ms [16:07:36][C][esp32_ble_tracker:610]: Scan Type: PASSIVE [16:07:36][C][status:034]: Status Binary Sensor 'Office BLE Tracker Status' [16:07:36][C][status:034]: Device Class: 'connectivity' [16:07:36][C][captive_portal:148]: Captive Portal: [16:07:36][C][ota:029]: Over-The-Air Updates: [16:07:36][C][ota:030]: Address: 192.168.1.178:3232 [16:07:36][C][api:095]: API Server: [16:07:36][C][api:096]: Address: 192.168.1.178:6053

[16:07:37][C][mqtt:063]: Server Address: 192.168.1.205:1883 (192.168.1.205)

[16:07:37][C][mqtt:065]: Client ID: 'office-ble-tracker-94b97ee653b8' [16:07:37][C][mqtt:070]: Topic Prefix: 'office-ble-tracker' [16:07:37][C][mqtt:072]: Log Topic: 'office-ble-tracker/debug'

[16:07:37][C][mqtt.sensor:024]: MQTT Sensor 'room_presence_debounce': [16:07:37][C][mqtt.sensor:028]: State Topic: 'office-ble-tracker/sensor/room_presence_debounce/state' [16:07:37][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Office BLE Tracker Status': [16:07:37][C][mqtt.binary_sensor:019]: State Topic: 'office-ble-tracker/status' [16:07:37][C][mqtt.binary_sensor:018]: MQTT Binary Sensor 'Clayton office presence': [16:07:37][C][mqtt.binary_sensor:019]: State Topic: 'office-ble-tracker/binary_sensor/clayton_office_presence/state' [16:07:37][C][mqtt.sensor:024]: MQTT Sensor 'Clayton Apple Watch office RSSI': [16:07:37][C][mqtt.sensor:028]: State Topic: 'office-ble-tracker/sensor/clayton_apple_watch_office_rssi/state' [16:07:43][D][binary_sensor:036]: 'Office BLE Tracker Status': Sending state ON [16:07:43][V][api.connection:714]: Hello from client: 'Home Assistant 2021.8.8 (192.168.1.205)' [16:07:43][D][api.connection:730]: Client 'Home Assistant 2021.8.8 (192.168.1.205)' connected successfully! [16:08:10][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:28][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:38][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:47][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:53][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:57][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:09:58][V][esp32_ble_tracker:591]: Unhandled type: advType: 0x12 [16:10:30][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -63, unrecognised action code 0x09 [16:10:30][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -76, unrecognised action code 0x09 [16:10:31][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:10:31][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -74, unrecognised action code 0x09 [16:10:33][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -87, unrecognised action code 0x09 [16:10:33][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:10:34][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:10:34][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -68, unrecognised action code 0x09 [16:10:35][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -77, unrecognised action code 0x09 [16:10:36][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -86, unrecognised action code 0x09 [16:10:38][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:10:39][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -62, unrecognised action code 0x09 [16:10:40][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -61, unrecognised action code 0x09 [16:10:40][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:10:41][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -92, unrecognised action code 0x09 [16:10:42][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:10:43][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -71, unrecognised action code 0x09 [16:10:44][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:10:44][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -83, unrecognised action code 0x09 [16:10:45][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -82, unrecognised action code 0x09 [16:10:46][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -77, unrecognised action code 0x09 [16:10:47][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -76, unrecognised action code 0x09 [16:10:47][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:10:48][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -75, unrecognised action code 0x09 [16:10:48][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -92, unrecognised action code 0x09 [16:10:49][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -74, unrecognised action code 0x09 [16:10:51][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -72, unrecognised action code 0x09 [16:10:52][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -76, unrecognised action code 0x09 [16:10:53][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -60, unrecognised action code 0x09 [16:10:53][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -61, unrecognised action code 0x09 [16:10:54][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -62, unrecognised action code 0x09 [16:10:54][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -61, unrecognised action code 0x09 [16:10:55][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:10:57][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -62, unrecognised action code 0x09 [16:10:57][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -62, unrecognised action code 0x09 [16:10:58][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:10:59][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -57, unrecognised action code 0x09 [16:12:30][I][ota:046]: Boot seems successful, resetting boot loop counter. [16:12:31][D][esp32_ble_tracker:180]: Starting scan... [16:13:10][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:13:11][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:11][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -68, unrecognised action code 0x09 [16:13:12][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -82, unrecognised action code 0x09 [16:13:13][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -64, unrecognised action code 0x09 [16:13:14][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -64, unrecognised action code 0x09 [16:13:14][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:15][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -71, unrecognised action code 0x09 [16:13:16][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -80, unrecognised action code 0x09 [16:13:17][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -73, unrecognised action code 0x09 [16:13:17][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -70, unrecognised action code 0x09 [16:13:18][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:13:21][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:21][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:13:22][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:23][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:24][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -74, unrecognised action code 0x09 [16:13:24][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:25][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -68, unrecognised action code 0x09 [16:13:28][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:13:28][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:29][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -69, unrecognised action code 0x09 [16:13:30][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:31][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -71, unrecognised action code 0x09 [16:13:32][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -70, unrecognised action code 0x09 [16:13:33][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -79, unrecognised action code 0x09 [16:13:34][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -81, unrecognised action code 0x09 [16:13:35][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -77, unrecognised action code 0x09 [16:13:35][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -87, unrecognised action code 0x09 [16:13:36][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -86, unrecognised action code 0x09 [16:13:37][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:38][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:39][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -63, unrecognised action code 0x09 [16:13:40][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -61, unrecognised action code 0x09 [16:13:40][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -62, unrecognised action code 0x09 [16:13:41][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -66, unrecognised action code 0x09 [16:13:42][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:13:43][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -63, unrecognised action code 0x09 [16:13:44][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -65, unrecognised action code 0x09 [16:13:45][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -84, unrecognised action code 0x09 [16:13:46][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -77, unrecognised action code 0x09 [16:13:46][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -78, unrecognised action code 0x09 [16:13:47][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -67, unrecognised action code 0x09 [16:13:48][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -72, unrecognised action code 0x09 [16:13:51][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -81, unrecognised action code 0x09 [16:13:51][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -79, unrecognised action code 0x09 [16:13:52][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -75, unrecognised action code 0x09 [16:13:53][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -60, unrecognised action code 0x09 [16:13:55][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -56, unrecognised action code 0x09 [16:13:56][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -47, unrecognised action code 0x09 [16:13:57][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -51, unrecognised action code 0x09 [16:13:57][D][ble_adv:058]: Possible Apple Watch? (mac 49:B6:FE:D5:F8:4A) rssi -57, unrecognised action code 0x09

dalehumby commented 3 years ago

Thanks for your ongoing debugging. I am sorry this is so painful, but hopefully we get it sorted soon.

... but it looks to be a different mac address.

Apple randomises the mac address to prevent tracking (for privacy.) This would be a lot easier if they didn't!

Yesterday I also found other actions codes 02 and 04, and with yours of 09 and 0f, it's probable that valid codes are 0x01 through 0x0F.

I've modified the code:

  on_ble_advertise:
    - then:
      # Look for manufacturer data of form: 4c00 10 05 YY 98 XXXXXX
      # Where YY can be 01..0F; and XXXXXX is ignored
      - lambda: |-
          for (auto data : x.get_manufacturer_datas()) {
            if (data.uuid.to_string() == "0x004C" && data.data[0] == 0x10 && data.data[1] == 0x05 && data.data[3] == 0x98) {
              uint8_t ac = data.data[2];
              int16_t rssi = x.get_rssi();
              if (ac <= 0x0F) {
                id(apple_watch_rssi).publish_state(rssi);
                ESP_LOGD("ble_adv", "Found Apple Watch (mac %s) rssi %i", x.address_str().c_str(), rssi);
              } else {
                ESP_LOGD("ble_adv", "Possible Apple Watch? (mac %s) rssi %i, unrecognised action code %#04x", x.address_str().c_str(), rssi, ac);
              }
            }
          }
dcgrove commented 3 years ago

So this have been running since about 8:30AM CST and has worked well. Have you seen an increase in battery drain on your watch? My watch was fully charged at 8AM when I put it on, and as of 12:43 CST it is at 38%.

dalehumby commented 3 years ago

I'm glad it's detecting your watch now.

I have not noticed any appreciable increased battery usage and I have 3 BLE receivers around my apartment. I put my watch on at 7am and 13 hours later it still has 70% remaining.

Jus to confirm the following:

esp32_ble_tracker:
  scan_parameters:
    interval: 1.2s
    window: 500ms
    active: false

active: false means only passive scanning, so the receiver picks up what your watch is already broadcasting, and should not increase battery usage.

You could try increase the interval. That may reduce battery usage but it will take longer to detect your watch. (It takes minimum 3 x interval seconds to change from present/not-present or vice versa.)

dcgrove commented 3 years ago

I have those same paremeters in the configs of both of my ESP32s. I will restart my watch to see if battery drain is resolved. It is entirely possible something else is going on. Thanks!

dalehumby commented 3 years ago

Hi @dcgrove Did the high battery drain continued after you restarted your watch?

dcgrove commented 3 years ago

A reset fixed the issue. It has been running on both ESP32's for nearly 48 hours now with no issues.