esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
290 stars 34 forks source link

ESP Home Entity not available in Deepsleep in latest Version #5013

Open MatthiasDenkler opened 10 months ago

MatthiasDenkler commented 10 months ago

The problem

As the Title says as soon as the ESP goes into deep sleep, the Entitys in Homeassistant are going to "Currently not available" in the latest Version. When this happens in the Logs I get this Message:

Which version of ESPHome has the issue?

2023.10.1

What type of installation are you using?

Home Assistant Add-on

Which version of Home Assistant has the issue?

core-2023.10.3

What platform are you using?

ESP32

Board

Lolin32 ESP32 Lite 4MB

Component causing the issue

api?

Example YAML snippet

esphome:
name: air-out
friendly_name: air-out
esp32:
board: esp32dev
framework:
type: arduino
i2c:
sda: GPIO16
scl: GPIO17
# Enable logging
logger:
# Enable Home Assistant API
api:
encryption:
key: "snip"
ota:
password: "snip"
wifi:
ssid: !secret wifi_ssid
password: !secret wifi_password
fast_connect: true
manual_ip:
static_ip: 192.168.128.14
gateway: 192.168.178.1
subnet: 255.255.128.0
dns1: 192.168.178.1
# Enable fallback hotspot (captive portal) in case wifi connection fails
ap:
ssid: "Air-Out Fallback Hotspot"
password: "snip"
captive_portal:
sensor:
- platform: bme280
temperature:
name: "Outside_Temp"
id: bme280_temperature
pressure:
name: "Outside_Pressure"
id: bme280_pressure
humidity:
name: "Outside_Humidity"
id: bme280_humidity
address: 0x76
update_interval: 40s
- platform: template
name: "Outside_Dew"
lambda: |-
return (243.5*(log(id(bme280_humidity).state/100)+((17.67*id(bme280_temperature).state)/
(243.5+id(bme280_temperature).state)))/(17.67-log(id(bme280_humidity).state/100)-
((17.67*id(bme280_temperature).state)/(243.5+id(bme280_temperature).state))));
unit_of_measurement: °C
icon: 'mdi:thermometer-alert'
update_interval: 40s
- platform: adc
pin: GPIO32
name: "Outside_Battery"
update_interval: 40s
filters:
- multiply: 3.5
deep_sleep:
run_duration: 30s
sleep_duration: 1min

Anything in the logs that might be useful for us?

Logger: aioesphomeapi.reconnect_logic
Source: runner.py:186
First occurred: 15:43:18 (233 occurrences)
Last logged: 22:12:48

    Can't connect to ESPHome API for air-out @ 192.168.128.14: Error connecting to ('192.168.128.14', 6053): [Errno 113] Connect call failed ('192.168.128.14', 6053) (SocketAPIError)
    Can't connect to ESPHome API for air-out @ 192.168.128.14: Error connecting to ('192.168.128.14', 6053): [Errno 111] Connect call failed ('192.168.128.14', 6053) (SocketAPIError)
    Can't connect to ESPHome API for air-out @ 192.168.128.14: Error connecting to ('192.168.128.14', 6053): (SocketAPIError)

-----------------------------------------------------------------------------------

[22:13:33]
[22:13:33]rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[22:13:33]configsip: 0, SPIWP:0xee
[22:13:33]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[22:13:33]mode:DIO, clock div:2
[22:13:33]load:0x3fff0030,len:1184
[22:13:33]load:0x40078000,len:12784
[22:13:33]load:0x40080400,len:3032
[22:13:33]entry 0x400805e4
[22:13:33][I][logger:271]: Log initialized
[22:13:33][C][ota:473]: There have been 0 suspected unsuccessful boot attempts.
[22:13:33][D][esp32.preferences:114]: Saving 1 preferences to flash...
[22:13:33][D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[22:13:33][I][app:029]: Running through setup()...
[22:13:33][I][i2c.arduino:183]: Performing I2C bus recovery
[22:13:33][C][bme280.sensor:086]: Setting up BME280...
[22:13:33][C][adc:047]: Setting up ADC 'Outside_Battery'...
[22:13:33][C][adc:093]: ADC 'Outside_Battery' setup finished!
[22:13:33][C][wifi:038]: Setting up WiFi...
[22:13:33][C][wifi:051]: Starting WiFi...
[22:13:33][C][wifi:052]:   Local MAC: C8:C9:A3:C9:10:14
[22:13:33][I][wifi:277]: WiFi Connecting to 'Adnexus'...
[22:13:33][D][sensor:094]: 'Outside_Dew': Sending state -nan °C with 1 decimals of accuracy
[22:13:33][D][sensor:094]: 'Outside_Battery': Sending state 3.76600 V with 2 decimals of accuracy
[22:13:34][D][sensor:094]: 'Outside_Temp': Sending state 24.20000 °C with 1 decimals of accuracy
[22:13:34][D][sensor:094]: 'Outside_Pressure': Sending state 962.18268 hPa with 1 decimals of accuracy
[22:13:34][D][sensor:094]: 'Outside_Humidity': Sending state 57.40430 % with 1 decimals of accuracy
[22:13:37][I][wifi:560]: WiFi Connected!
[22:13:37][C][wifi:382]:   Local MAC: C8:C9:A3:C9:10:14
[22:13:37][C][wifi:383]:   SSID: 'Adnexus'
[22:13:37][C][wifi:384]:   IP Address: 192.168.128.14
[22:13:37][C][wifi:386]:   BSSID: DC:39:6F:BE:E2:7C
[22:13:37][C][wifi:387]:   Hostname: 'air-out'
[22:13:37][C][wifi:389]:   Signal strength: -47 dB ▂▄▆█
[22:13:37][C][wifi:393]:   Channel: 11
[22:13:37][C][wifi:394]:   Subnet: 255.255.128.0
[22:13:37][C][wifi:395]:   Gateway: 192.168.178.1
[22:13:37][C][wifi:396]:   DNS1: 192.168.178.1
[22:13:37][C][wifi:397]:   DNS2: 0.0.0.0
[22:13:37][D][wifi:569]: Disabling AP...
[22:13:37][C][ota:097]: Over-The-Air Updates:
[22:13:37][C][ota:098]:   Address: 192.168.128.14:3232
[22:13:37][C][ota:101]:   Using Password.
[22:13:37][C][api:025]: Setting up Home Assistant API server...
[22:13:37][C][deep_sleep:037]: Setting up Deep Sleep...
[22:13:37][I][deep_sleep:042]: Scheduling Deep Sleep to start in 30000 ms
[22:13:37][I][app:062]: setup() finished successfully!
[22:13:37][I][app:102]: ESPHome version 2023.10.1 compiled on Oct 20 2023, 22:01:40
[22:13:37][C][wifi:546]: WiFi:
[22:13:37][C][wifi:382]:   Local MAC: C8:C9:A3:C9:10:14
[22:13:37][C][wifi:383]:   SSID: 'Adnexus'
[22:13:37][C][wifi:384]:   IP Address: 192.168.128.14
[22:13:37][C][wifi:386]:   BSSID: DC:39:6F:BE:E2:7C
[22:13:37][C][wifi:387]:   Hostname: 'air-out'
[22:13:37][C][wifi:389]:   Signal strength: -46 dB ▂▄▆█
[22:13:37][C][wifi:393]:   Channel: 11
[22:13:37][C][wifi:394]:   Subnet: 255.255.128.0
[22:13:37][C][wifi:395]:   Gateway: 192.168.178.1
[22:13:37][C][wifi:396]:   DNS1: 192.168.178.1
[22:13:37][C][wifi:397]:   DNS2: 0.0.0.0
[22:13:37][C][logger:361]: Logger:
[22:13:37][C][logger:362]:   Level: DEBUG
[22:13:37][C][logger:363]:   Log Baud Rate: 115200
[22:13:37][C][logger:365]:   Hardware UART: UART0
[22:13:37][C][i2c.arduino:053]: I2C Bus:
[22:13:37][C][i2c.arduino:054]:   SDA Pin: GPIO16
[22:13:37][C][i2c.arduino:055]:   SCL Pin: GPIO17
[22:13:37][C][i2c.arduino:056]:   Frequency: 50000 Hz
[22:13:37][C][i2c.arduino:059]:   Recovery: bus successfully recovered
[22:13:37][I][i2c.arduino:069]: Results from i2c bus scan:
[22:13:37][I][i2c.arduino:075]: Found i2c device at address 0x76
[22:13:37][C][template.sensor:022]: Template Sensor 'Outside_Dew'
[22:13:37][C][template.sensor:022]:   State Class: ''
[22:13:37][C][template.sensor:022]:   Unit of Measurement: '°C'
[22:13:37][C][template.sensor:022]:   Accuracy Decimals: 1
[22:13:37][C][template.sensor:022]:   Icon: 'mdi:thermometer-alert'
[22:13:37][C][template.sensor:023]:   Update Interval: 40.0s
[22:13:37][C][bme280.sensor:177]: BME280:
[22:13:37][C][bme280.sensor:178]:   Address: 0x76
[22:13:37][C][bme280.sensor:190]:   IIR Filter: OFF
[22:13:37][C][bme280.sensor:191]:   Update Interval: 40.0s
[22:13:37][C][bme280.sensor:193]:   Temperature 'Outside_Temp'
[22:13:37][C][bme280.sensor:193]:     Device Class: 'temperature'
[22:13:37][C][bme280.sensor:193]:     State Class: 'measurement'
[22:13:37][C][bme280.sensor:193]:     Unit of Measurement: '°C'
[22:13:37][C][bme280.sensor:193]:     Accuracy Decimals: 1
[22:13:37][C][bme280.sensor:194]:     Oversampling: 16x
[22:13:37][C][bme280.sensor:195]:   Pressure 'Outside_Pressure'
[22:13:37][C][bme280.sensor:195]:     Device Class: 'pressure'
[22:13:37][C][bme280.sensor:195]:     State Class: 'measurement'
[22:13:37][C][bme280.sensor:195]:     Unit of Measurement: 'hPa'
[22:13:37][C][bme280.sensor:195]:     Accuracy Decimals: 1
[22:13:37][C][bme280.sensor:196]:     Oversampling: 16x
[22:13:37][C][bme280.sensor:197]:   Humidity 'Outside_Humidity'
[22:13:37][C][bme280.sensor:197]:     Device Class: 'humidity'
[22:13:37][C][bme280.sensor:197]:     State Class: 'measurement'
[22:13:37][C][bme280.sensor:197]:     Unit of Measurement: '%'
[22:13:37][C][bme280.sensor:197]:     Accuracy Decimals: 1
[22:13:37][C][bme280.sensor:198]:     Oversampling: 16x
[22:13:37][C][adc:097]: ADC Sensor 'Outside_Battery'
[22:13:37][C][adc:097]:   Device Class: 'voltage'
[22:13:37][C][adc:097]:   State Class: 'measurement'
[22:13:37][C][adc:097]:   Unit of Measurement: 'V'
[22:13:37][C][adc:097]:   Accuracy Decimals: 2
[22:13:37][C][adc:107]:   Pin: GPIO32
[22:13:37][C][adc:113]:  Attenuation: 0db
[22:13:37][C][adc:142]:   Update Interval: 40.0s
[22:13:37][C][captive_portal:088]: Captive Portal:
[22:13:37][C][mdns:115]: mDNS:
[22:13:37][C][mdns:116]:   Hostname: air-out
[22:13:37][C][ota:097]: Over-The-Air Updates:
[22:13:37][C][ota:098]:   Address: 192.168.128.14:3232
[22:13:37][C][ota:101]:   Using Password.
[22:13:37][C][api:138]: API Server:
[22:13:37][C][api:139]:   Address: 192.168.128.14:6053
[22:13:37][C][api:141]:   Using noise encryption: YES
[22:13:37][C][deep_sleep:049]: Setting up Deep Sleep...
[22:13:37][C][deep_sleep:052]:   Sleep Duration: 60000 ms
[22:13:37][C][deep_sleep:055]:   Run Duration: 30000 ms
[22:13:38][D][api:102]: Accepted 192.168.128.1
[22:13:38][D][api.connection:1032]: Home Assistant 2023.10.3 (192.168.128.1): Connected successfully
[22:13:55][D][sensor:094]: 'Outside_Temp': Sending state 24.23000 °C with 1 decimals of accuracy
[22:13:55][D][sensor:094]: 'Outside_Pressure': Sending state 962.15643 hPa with 1 decimals of accuracy
[22:13:55][D][sensor:094]: 'Outside_Humidity': Sending state 56.80859 % with 1 decimals of accuracy
[22:13:57][D][sensor:094]: 'Outside_Dew': Sending state 15.12963 °C with 1 decimals of accuracy
[22:13:59][D][sensor:094]: 'Outside_Battery': Sending state 3.76600 V with 2 decimals of accuracy
[22:14:07][I][deep_sleep:116]: Beginning Deep Sleep
[22:14:07][I][deep_sleep:118]: Sleeping for 60000000us
[22:14:07][D][esp32.preferences:114]: Saving 1 preferences to flash...
[22:14:07][D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[22:15:07]ets Jun  8 2016 00:22:57
[22:15:07]
[22:15:07]rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[22:15:07]configsip: 0, SPIWP:0xee
[22:15:07]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[22:15:07]mode:DIO, clock div:2
[22:15:07]load:0x3fff0030,len:1184
[22:15:07]load:0x40078000,len:12784
[22:15:07]load:0x40080400,len:3032
[22:15:07]entry 0x400805e4
[22:15:07][I][logger:271]: Log initialized
[22:15:07][C][ota:473]: There have been 0 suspected unsuccessful boot attempts.
[22:15:07][D][esp32.preferences:114]: Saving 1 preferences to flash...
[22:15:07][D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[22:15:07][I][app:029]: Running through setup()...
[22:15:07][I][i2c.arduino:183]: Performing I2C bus recovery
[22:15:07][C][bme280.sensor:086]: Setting up BME280...
[22:15:07][C][adc:047]: Setting up ADC 'Outside_Battery'...
[22:15:07][C][adc:093]: ADC 'Outside_Battery' setup finished!
[22:15:07][C][wifi:038]: Setting up WiFi...
[22:15:07][C][wifi:051]: Starting WiFi...
[22:15:07][C][wifi:052]:   Local MAC: C8:C9:A3:C9:10:14
[22:15:07][I][wifi:277]: WiFi Connecting to 'Adnexus'...
[22:15:07][D][sensor:094]: 'Outside_Battery': Sending state 3.76600 V with 2 decimals of accuracy
[22:15:07][D][sensor:094]: 'Outside_Dew': Sending state -nan °C with 1 decimals of accuracy
[22:15:07][D][sensor:094]: 'Outside_Temp': Sending state 24.28000 °C with 1 decimals of accuracy
[22:15:07][D][sensor:094]: 'Outside_Pressure': Sending state 962.03943 hPa with 1 decimals of accuracy
[22:15:07][D][sensor:094]: 'Outside_Humidity': Sending state 56.30078 % with 1 decimals of accuracy
[22:15:11][D][esp-idf:000]: E (7551) wifi:
[22:15:11][D][esp-idf:000]: Association refused temporarily, comeback time 1024 mSec
[22:15:11][D][esp-idf:000]: 
[22:15:11]
[22:15:13][D][esp-idf:000]: E (9601) wifi:
[22:15:13][D][esp-idf:000]: Association refused temporarily, comeback time 1024 mSec
[22:15:13][D][esp-idf:000]: 
[22:15:13]

Additional information

No response

MatthiasDenkler commented 9 months ago

After latest Homeassistant Coreupdate, this works again as intended. But now the measured and sended States dont get displayed anymore. Can this be a Bug of ESPHome or is it more a Homeassistant Problem?

VIMVa commented 9 months ago

I'm on latest updates of everything but devices in deep sleep still are unavailable regularly. Screenshot_2023-11-10-13-15-46-34_c3a231c25ed346e59462e84656a70e50 Screenshot_2023-11-13-20-28-15-40_c3a231c25ed346e59462e84656a70e50

jesserockz commented 9 months ago

With a run_duration of only 30 seconds, and update_interval of 40s for the sensors, its likely that they just dont update in time. The first update they do is at a random time between 0 and the update interval to spread out updates.

The best way to solve this is to use an on_boot automation to wait until the api is connected, then force an update on each sensor, delay for a second or 2 to allow network traffic to be sent, then manually enter deep_sleep once that is done.

esphome:
  on_boot:
    - wait_until: api.connected
    - component.update: bme280_id # give this id to the parent bme sensor
    - component.update: outside_dew # give this id to the Outside_Dew template sensor
    - component.update: outside_battery # give this id to the adc sensor
    - delay: 1s
    - deep_sleep.enter:

And delete the run_duration from the deep sleep config. This will likely let it run for even less than 30 seconds too as it only stays on for maybe 1 or 2 seconds after api is connected.

VIMVa commented 9 months ago

Will give it a try! Just a question from an eager-to-learn rookie: does the 'on boot' also run on wake after deep sleep then or only at actual boot after forced reset?

ssieb commented 9 months ago

A wake up is the same as a reboot.

VIMVa commented 9 months ago

Thanks for clarifying... but I should have known 🤭. I already have an on_boot to check if a helper switch is on so that the device stays awake and give me opportunity to install new code wirelessly when needed.

VIMVa commented 9 months ago

No luck with this workaround here: already 2 disconnections in as many hours like before. My code for if someone would like to have a check:

esphome:
  name: temp-004
  on_boot:
      - wait_until: api.connected
      - component.update: bme280_temp004 # give this id to the parent bme sensor
      - component.update: wifi_signal_db_temp004 # give this id to the Wi-Fi sensor
      - component.update: batterij_temp004 # give this id to the adc sensor
      - delay: 5s
      - script.execute: consider_deep_sleep_temp004

esp8266:
  board: d1_mini

# Enable logging
logger:

# Enable Home Assistant API
api:
  encryption:
    key: "Ucno7qxcEczHMQFf0Uxxxxxxxx"

ota:
  password: "7f471xxxxxxxxx"

wifi:
  ssid: !secret wifi_ssid
  password: !secret wifi_password
  power_save_mode: none
  manual_ip:
    static_ip: 192.168.1.134
    gateway: 192.168.1.1
    subnet: 255.255.255.0

  # Enable fallback hotspot (captive portal) in case wifi connection fails
  ap:
    ssid: "Temp-004 Fallback Hotspot"
    password: "OxxxxxUx1xxx"

captive_portal:

i2c:
#  sda: 4
#  scl: 5
  scan: False

sensor:
  - platform: bme280
    id: bme280_temp004
    temperature:
      name: "Temperatuur"
      filters:
        - offset: 0.4
    pressure:
      name: "Luchtdruk"
      filters:
        - offset: 2.1
    humidity:
      name: "Luchtvocht"
    address: 0x76
    update_interval: 6min

  - platform: wifi_signal # Reports the WiFi signal strength/RSSI in dB
    name: "WiFi Signal dB"
    id: wifi_signal_db_temp004
    update_interval: 6min
    entity_category: "diagnostic"

  - platform: adc
    id: batterij_temp004
    pin: A0
    name: "Batterij"
    update_interval: 6min  
    unit_of_measurement: "%"
    accuracy_decimals: 0
    icon: mdi:battery-medium
    filters:
      - multiply: 4.5
      - calibrate_polynomial:
         degree: 3
         datapoints:
          - 0.00 -> 0.0
          - 3.30 -> 0.0
          - 3.35 -> 5.0
          - 3.39 -> 10.0
          - 3.44 -> 15.0
          - 3.48 -> 20.0
          - 3.53 -> 25.0
          - 3.57 -> 30.0
          - 3.62 -> 35.0
          - 3.64 -> 40.0
          - 3.69 -> 45.0
          - 3.73 -> 50.0
          - 3.78 -> 55.0
          - 3.82 -> 60.0
          - 3.87 -> 65.0
          - 3.91 -> 70.0
          - 3.96 -> 75.0
          - 4.00 -> 80.0
          - 4.05 -> 85.0
          - 4.09 -> 90.0
          - 4.14 -> 95.0
          - 4.20 -> 100.0
      - lambda: |-
          if (x <= 100) {
            return x;
          } else {
            return 100;
          }

deep_sleep:
  id: deep_sleep_control_temp004
#  run_duration: 20s
  sleep_duration: 15min

# Will only pick up a value if this device is configured in Home Assistant > Integrations
# If the device isn't configured, or Home Assistant is offline, it'll default to false
binary_sensor:
  - platform: homeassistant
    id: prevent_deep_sleep_temp004
    entity_id: input_boolean.prevent_deep_sleep_temp004

script:
  - id: consider_deep_sleep_temp004
    mode: queued
    then:
      - delay: 10s
      - if:
          condition:
           binary_sensor.is_on: prevent_deep_sleep_temp004
          then:
           - logger.log: 'Skipping sleep, per prevent_deep_sleep_temp004'
          else:
           - deep_sleep.enter: deep_sleep_control_temp004
      - script.execute: consider_deep_sleep_temp004
ssieb commented 9 months ago

I don't know what you mean by "disconnections", but if you want to find out what's going on, then you need to watch the serial logs.

VIMVa commented 9 months ago

Exactly what the thread opener described. Devices with deep sleep installed regularly get 'not available' a few moments after going back into deep sleep. It's a known issue and I've read and tried numerous workarounds... that fail to work. Cause and solution may be in HA.

VIMVa commented 9 months ago

Had hoped that today's version 2023.11.0 would have solved this issue... but alas. Only with my 2 D1's with deep sleep active.

Logger: aioesphomeapi.reconnect_logic
Source: runner.py:188
First occurred: 14 november 2023 om 22:26:55 (184 occurrences)
Last logged: 18:35:57
Can't connect to ESPHome API for temp-004 @ 192.168.1.134: Error connecting to ('192.168.1.134', 6053): [Errno 113] Connect call failed ('192.168.1.134', 6053) (SocketAPIError)
Can't connect to ESPHome API for temp-002 @ 192.168.1.132: Timeout while connecting to ('192.168.1.132', 6053) (SocketAPIError)
Can't connect to ESPHome API for temp-004 @ 192.168.1.134: Timeout while connecting to ('192.168.1.134', 6053) (SocketAPIError)
Can't connect to ESPHome API for temp-002 @ 192.168.1.132: Error connecting to ('192.168.1.132', 6053): [Errno 113] Connect call failed ('192.168.1.132', 6053) (SocketAPIError)
VIMVa commented 9 months ago

TWIMC: this is the only workaround that keeps the devices as 'available' during deep sleep for me. Increased the DisconnectRequest to 1000ms. Maybe less will work as well. Device updated at 10h00 with this workaround: Screenshot_2023-11-16-14-28-39-40_c3a231c25ed346e59462e84656a70e50

ssieb commented 7 months ago

Was this issue resolved by that change?