Bug Regression: ESPhome deep sleep sensor values get 'unavailable' as soon as api is not connected

[luixal]

The problem

I'm experiencing exactly the same that was described in issue #90923 and solved in PR #90925.

I guess there was a regression of this bug in any version between May (2023.5) and now (2023.8 tested).

The original description is pasted below:

As soon as a ESPhome device disconnects from native api, the value in dashboards switches to 'unavailable', the history graph will get gaps till reconnect. In previous versions the last value was retained and the history graph was a solid line with last value as data points.

The problem gets visible with (battery powered) devices that use deep sleep and just connect a few seconds to transmit values. Just during the short transmission time, the value in dashboard is visible. As soon as device gets into deep sleep, the value switches to 'unavailable'. The history graph gets a dashed or dotted line (depends on update/connection frequency).

Maybe @bdraco can solve this again! :)

What version of Home Assistant Core has the issue?

core-2023.8.0

What was the last working version of Home Assistant Core?

core-2023.5.0

What type of installation are you running?

Home Assistant OS

Integration causing the issue

ESPHome

Link to integration documentation on our website

https://www.home-assistant.io/integrations/esphome/

Diagnostics information

No response

Example YAML snippet

This is the yaml config from the sensor:

esphome:
  name: ph-level-sensor

esp32:
  board: nodemcu-32s

# Enable logging
logger:

# Enable Home Assistant API
api:
  encryption:
    key: !secret.key

ota:
  password: !secret_ota_password

wifi:
  ssid: !secret_wifi_ssid
  password: !secret_wifi_password

  # Enable fallback hotspot (captive portal) in case wifi connection fails
  ap:
    ssid: "Ph-Level-Sensor Fallback Hotspot"
    password: "phsensor1234"

captive_portal:

sensor:

    # Wifi Signal
  - platform: wifi_signal
    name: "Sensor PH- WiFi dbms"
    id: ph_level_wifi_signal_dbm
    update_interval: 300s

  # Wifi Signal
  - platform: template
    unit_of_measurement: "%"
    name: "Sensor PH- WiFi Percentage"
    accuracy_decimals: 0
    update_interval: 300s
    icon: mdi:wifi
    lambda: return (-0.0134 * (id(ph_level_wifi_signal_dbm).state * id(ph_level_wifi_signal_dbm).state ) ) + (-0.2228 * id(ph_level_wifi_signal_dbm).state) + 100.2;

  - platform: ultrasonic
    name: "Sensor PH- Fill Level"
    trigger_pin: GPIO22
    echo_pin: GPIO23
    update_interval: 50s
    unit_of_measurement: "%"
    icon: "mdi:water-percent"
    accuracy_decimals: 0
    filters:
      - lambda: |-
          int value = ((0.31 - x) / 0.31) * 100;
          if (value < 0) return 0;
          if (value > 100) return 100;
          return value;
      - filter_out: nan
      - median:
          window_size: 7
          send_every: 5

deep_sleep:
  run_duration: 120s
  sleep_duration: 15min

Anything in the logs that might be useful for us?

Logs:

2023-08-06 13:18:09.678 WARNING (MainThread) [aioesphomeapi.connection] ph-level-sensor @ 192.168.68.67: Connection error occurred: Ping response not received after 90.0 seconds
2023-08-06 13:18:09.691 INFO (MainThread) [aioesphomeapi.reconnect_logic] Processing unexpected disconnect from ESPHome API for ph-level-sensor @ 192.168.68.67
2023-08-06 13:18:09.691 DEBUG (MainThread) [homeassistant.components.esphome.manager] ph-level-sensor: 192.168.68.67 disconnected (expected=False), running disconnected callbacks
2023-08-06 13:18:09.691 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_wifi_dbms, old_state=<state sensor.sensor_ph_wifi_dbms=-71; state_class=measurement, unit_of_measurement=dBm, device_class=signal_strength, friendly_name=Sensor PH- WiFi dbms @ 2023-08-06T13:14:54.714550+02:00>, new_state=<state sensor.sensor_ph_wifi_dbms=unavailable; state_class=measurement, unit_of_measurement=dBm, device_class=signal_strength, friendly_name=Sensor PH- WiFi dbms @ 2023-08-06T13:18:09.691406+02:00>>
2023-08-06 13:18:09.691 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_wifi_percentage, old_state=<state sensor.sensor_ph_wifi_percentage=50; unit_of_measurement=%, icon=mdi:wifi, friendly_name=Sensor PH- WiFi Percentage @ 2023-08-06T13:14:47.139235+02:00>, new_state=<state sensor.sensor_ph_wifi_percentage=unavailable; unit_of_measurement=%, icon=mdi:wifi, friendly_name=Sensor PH- WiFi Percentage @ 2023-08-06T13:18:09.691624+02:00>>
2023-08-06 13:18:09.691 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_fill_level, old_state=<state sensor.sensor_ph_fill_level=61; state_class=measurement, unit_of_measurement=%, icon=mdi:water-percent, friendly_name=Sensor PH- Fill Level @ 2023-08-06T13:02:18.256907+02:00>, new_state=<state sensor.sensor_ph_fill_level=unavailable; state_class=measurement, unit_of_measurement=%, icon=mdi:water-percent, friendly_name=Sensor PH- Fill Level @ 2023-08-06T13:18:09.691791+02:00>>
2023-08-06 13:18:09.691 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=update.ph_level_sensor_firmware, old_state=<state update.ph_level_sensor_firmware=off; auto_update=False, installed_version=2023.7.1, in_progress=False, latest_version=2023.7.1, release_summary=None, release_url=https://esphome.io/changelog/, skipped_version=None, title=ESPHome, device_class=firmware, entity_picture=https://brands.home-assistant.io/_/esphome/icon.png, friendly_name=Ph-Level-Sensor Firmware, supported_features=1 @ 2023-08-06T12:56:19.647131+02:00>, new_state=<state update.ph_level_sensor_firmware=unavailable; device_class=firmware, entity_picture=https://brands.home-assistant.io/_/esphome/icon.png, friendly_name=Ph-Level-Sensor Firmware, supported_features=1 @ 2023-08-06T13:18:09.691929+02:00>>
2023-08-06 13:18:09.696 INFO (MainThread) [custom_components.meross_cloud.sensor] Refreshing instant metrics for device Lámapara Salón (mss310) power W - Main channel
2023-08-06 13:18:09.725 INFO (MainThread) [custom_components.meross_cloud.sensor] Refreshing instant metrics for device Lámapara Salón (mss310) voltage V - Main channel
[...]
023-08-06 13:18:12.746 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for ph-level-sensor @ 192.168.68.67: Error connecting to ('192.168.68.67', 6053): [Errno 113] Connect call failed ('192.168.68.67', 6053) (SocketAPIError)
2023-08-06 13:18:12.747 INFO (MainThread) [aioesphomeapi.reconnect_logic] Trying to connect to ph-level-sensor @ 192.168.68.67 in the background

Additional information

No response

[home-assistant[bot]]

Hey there @ottowinter, @jesserockz, @bdraco, mind taking a look at this issue as it has been labeled with an integration (esphome) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `esphome` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign esphome` Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

---

esphome documentation esphome source _{^{(message by IssueLinks)}}

[bdraco]

Please enable debug logging and post a log for when the device goes to sleep. Thanks

[luixal]

Hi,

This is the only log I find related to the sensor (sensor.sensor_ph_fill_level):

2023-08-04 22:20:51.706 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_wifi_dbms, old_state=None, new_state=<state sensor.sensor_ph_wifi_dbms=unavailable; state_class=measurement, unit_of_measurement=dBm, device_class=signal_strength, friendly_name=Sensor PH- WiFi dbms @ 2023-08-04T22:20:51.706358+02:00>>
2023-08-04 22:20:51.706 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_wifi_percentage, old_state=None, new_state=<state sensor.sensor_ph_wifi_percentage=unavailable; unit_of_measurement=%, icon=mdi:wifi, friendly_name=Sensor PH- WiFi Percentage @ 2023-08-04T22:20:51.706922+02:00>>
2023-08-04 22:20:51.707 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.sensor_ph_fill_level, old_state=None, new_state=<state sensor.sensor_ph_fill_level=unavailable; state_class=measurement, unit_of_measurement=%, icon=mdi:water-percent, friendly_name=Sensor PH- Fill Level @ 2023-08-04T22:20:51.707391+02:00>>
2023-08-04 22:20:51.710 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=esphome>
[...]
2023-08-04 22:20:54.877 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for ph-level-sensor @ 192.168.68.67: Error connecting to ('192.168.68.67', 6053): [Errno 113] Connect call failed ('192.168.68.67', 6053) (SocketAPIError)
2023-08-04 22:20:54.933 INFO (MainThread) [aioesphomeapi.reconnect_logic] Trying to connect to ph-level-sensor @ 192.168.68.67 in the background

Not sure if this what you're looking for.

Thanks!

[bdraco]

You'll get a few log line for aioesphomeapi when the device goes to sleep. I need those and the ones for homeassistant.components.esphome

[bdraco]

Make sure both loggers are set to debug level

[bdraco]

Also it would be helpful if you posted the esphome yaml for the device

[luixal]

Hi @bdraco I updated the first post with the logs I got and the yaml config file.

[bdraco]

This looks like it's working as expected on the Home Assistant side and the problem is with the device or esphome code

Processing unexpected disconnect from ESPHome API for ph-level-sensor @ 192.168.68.67

The device is supposed to send a disconnect request before it goes into deep sleep. Instead it just stops responding which is why it's being marked as unavailable

You'll probably need to attach a serial console to see why it's failing to tell Home Assistant that its going to sleep with a disconnect request

[bdraco]

Please continue at https://github.com/esphome/issues/issues since it's going to need to be fixed on the device firmware

[luixal]

It was my bad, I mixed things up:

• I have a sensor using deep sleep. This seems to be working fine, keeping the value wile sleeping.
• I have a similar sensor not using beed sleep, but running only at certain hours (shares electrical power with another device so it just goes off, doesn't go into sleeping state) and this was the one shown as unavailable.

Sorry for wasting your time, everything seems to be working as supposed.

Thanks!

TIP: hope HA uses state for state itself and another field like value or last_value for the value, as they're clearly different things :(

[bdraco]

Thanks for following up