Mqtt light going offline without reason

maxym · November 17, 2021, 6:52pm

Today, I noticed one of my AC powered switches disappear (BTW the one this thread has started with)

look at this:
History shows it turned unavailable yesterdayand remains till now.
But MQTT debug log shows events from today (even a few mins ago)

Since yesterday I have debug enabled for core too. The image above shows grep for entrance word. So no such line in core.debug

Any ideas WTF is going on? It’s not only about I lost entity. But it is not able to recover itself with data still comming from MQTT.
How can I debug this issue more? I suspect even with this evidence, there is no chance to get help from devs.

maxym · November 17, 2021, 8:26pm

found reason of report above. But rootcause is still unknow:

You may see, online topic turned false.
Curious why… I suspect only the device writes there. but why the device would report offline while it’s online all the time?

petro · November 18, 2021, 9:52am

Bug in Shelly

maxym · November 18, 2021, 10:06am

It’s about Shelly Motion (bit different HW). But it might originate from from the same logic implemented in the code base. So yes, it could be.
I already asked for that behavior on Shelly FB. Will see.

I have to check logs for battery powered devices (a few posts above). Going offline is something normal for them. It might be different case from Shelly2.5

Thank you for the feedback

petro · November 18, 2021, 10:40am

Check your discovery configuration and remove the online/offline and see if the issue goes away

maxym · November 18, 2021, 10:42am

I’m not using discovery. Manually configured entities instead.
Yeah… idea of removing availability check came across my mind. Thanks

petro · November 18, 2021, 12:03pm

Manual configuration uses the same code as discovery. The yaml is just passed to the objects instead of the discovery info. So it’s a 1 to 1 comp in that regards

maxym · November 18, 2021, 3:35pm

Yes. I assume that. Thank you.

maxym · November 21, 2021, 2:09pm

So, looks like I’m facing two different issues. Still waiting on asnwer from Shelly about AC powered device.

But I just encountered again issue with battery powered devices. All my battery Shelly H&T turned unavailable recently.
Main differences between them and mentioned above AC powerd devices are:

those devices have no availability topic set
those devices has expiration timeout to 24h

What happened yesterday is, I restarted HA at 12:51, then was reloading manually configured mqtt entities multiple times during a day.

Here is what found in logs:

cat ./home-assistant.log | grep -E "temp-kitchen|kitchen_temperature" | grep -v table

2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-kitchen/sensor/temperature, mid: 5779
2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature (retained): b'22.20'
2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=None, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.100838+01:00>>
2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.100838+01:00>, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.134957+01:00>>
2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-kitchen/sensor/humidity, mid: 5780
2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity (retained): b'54.0'
2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.20'
2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.134957+01:00>, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T02:28:08.155853+01:00>>

2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'52.5'
2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100'
2021-11-21 11:04:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T02:28:08.155853+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T11:04:13.148924+01:00>>
2021-11-21 12:51:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T11:04:13.148924+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:51:16.969906+01:00>>
2021-11-21 12:54:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:51:16.969906+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:54:34.166672+01:00>>
2021-11-21 14:07:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:54:34.166672+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:07:50.729207+01:00>>
2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.45'
2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:07:50.729207+01:00>, new_state=<state sensor.kitchen_temperature=22.45; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:19:19.935248+01:00>>
2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'54.5'
2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100'
2021-11-21 14:21:20 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.45; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:19:19.935248+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:21:20.422972+01:00>>
2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.83'
2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:21:20.422972+01:00>, new_state=<state sensor.kitchen_temperature=22.83; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:25:08.503409+01:00>>
2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'54.0'
2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100'
2021-11-21 14:27:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.83; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:25:08.503409+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:27:31.002663+01:00>>
2021-11-21 14:33:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:27:31.002663+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:33:31.424737+01:00>>
2021-11-21 14:36:52 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:33:31.424737+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:36:52.829243+01:00>>
2021-11-21 14:39:58 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:36:52.829243+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:39:58.600221+01:00>>
2021-11-21 14:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:39:58.600221+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:41:59.945812+01:00>>
2021-11-21 14:49:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:41:59.945812+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:49:01.481926+01:00>>

In short,
at 2:28 most recent temperature value has been received from mqtt and set in entity
at 11:04 for some reason this sensor has been refreshed with the same values
at 12:51 temperature sensor went unavailable,
at 14:19 temperature is set to valid value because is refreshed from mqtt
at 14:21 it turns unavailable again without reason
at 14:25 temperature is set to valid value because is refreshed from mqtt
at 14:27 it turns unavailable again without reason
Reason of next sensor updates are not known for me but are executed roughly every 3 minutes not changing the state.

Because I make a grep for mqtt topic but for temperature sensor name, there are no log lines shown for humidity and battery sensor of this device. But both are unavailable too.

Here is similar log for other sensor. The behavior and timing are the same:

2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-pcroom/sensor/humidity, mid: 5774
2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.919348+01:00>, new_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.924397+01:00>>
2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity (retained): b'50.0'
2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'24.50'
2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.924397+01:00>, new_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T18:53:15.162819+01:00>>
2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'50.0'
2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100'
2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'23.50'
2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T18:53:15.162819+01:00>, new_state=<state sensor.pcroom_temperature=23.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T03:57:42.206813+01:00>>
2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'49.5'
2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100'
2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'24.50'
2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=23.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T03:57:42.206813+01:00>, new_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:20:29.190627+01:00>>
2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'50.0'
2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100'
2021-11-21 11:41:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:20:29.190627+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:41:07.293522+01:00>>
2021-11-21 12:51:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:41:07.293522+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T12:51:16.779165+01:00>>
2021-11-21 13:47:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T12:51:16.779165+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T13:47:07.439301+01:00>>
2021-11-21 14:07:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T13:47:07.439301+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:07:50.398601+01:00>>
2021-11-21 14:21:20 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:07:50.398601+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:21:20.243528+01:00>>
2021-11-21 14:27:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:21:20.243528+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:27:30.825043+01:00>>
2021-11-21 14:33:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:27:30.825043+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:33:31.245656+01:00>>
2021-11-21 14:35:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:33:31.245656+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:35:34.314269+01:00>>
2021-11-21 14:39:58 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:35:34.314269+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:39:58.214383+01:00>>
2021-11-21 14:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:39:58.214383+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:41:59.662461+01:00>>
2021-11-21 14:49:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:41:59.662461+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:49:01.204123+01:00>>

And here are configuration of the sensor:

######
# KITCHEN SENSORS
# - temperature
# - humidity
# - battery
######
- platform: mqtt
  name: "Kitchen Temperature"
  state_topic: "shellies/temp-kitchen/sensor/temperature"
  json_attributes_topic: "shellies/temp-kitchen/sensor/temperature"
  unit_of_measurement: "°C"
  force_update: true
  device_class: temperature
  expire_after: 86400
- platform: mqtt
  name: "Kitchen Humidity"
  state_topic: "shellies/temp-kitchen/sensor/humidity"
  json_attributes_topic: "shellies/temp-kitchen/sensor/humidity"
  unit_of_measurement: "%"
  payload_available: "true"
  payload_not_available: "false"
  force_update: true
  device_class: humidity
  expire_after: 86400
- platform: mqtt
  name: "Kitchen bttry"
  state_topic: "shellies/temp-kitchen/sensor/battery"
  unit_of_measurement: "%"
  payload_available: "true"
  payload_not_available: "false"
  force_update: true
  device_class: battery
  expire_after: 86400

- platform: template
  sensors:
    kitchen_temp_battery:
      friendly_name: "Kitchen Sensor Battery"
      device_class: battery
      unit_of_measurement: "%"
      value_template: "{{ states('sensor.kitchen_bttry') }}"

(just noticed payload_available/payload_not_available set for 2 of those sensors. but it should make no difference since topic is not defined. Also temperature sensor has no those settings but fails too)

Just thinking if it has something to do with HA restart (see the same time, but one day later, one day = 24h) and possibly with subsequent mqtt entities reloading.

I have other battery powered shelly sensors (DW) but those have no expiration set. And they remain available.

Do you think it’s enough to raise issue on GitHub?

maxym · January 29, 2022, 11:26am

I reported expiration issue to github. Due to no any response, I decided to remove expiration from entities. Tbh not having this feature is less problematic than loosing sensors every few days.

Anyway what is more important I found that after removing expiration lines from entity configs and reloading manually configured mqtt entities, next day I lost those entities again.
It confirms that something is really screwed around this.
Then I restarted HA and since this time no more issues.

Maybe worth to say again that I’m talking about battery powered devices (see config in prev posts) so there is no way they turn unavailable. Also in order to make sure there are no invalid data causing this issue I created test sensors based on the same mqtt topics with use of NR. So I’m pretty sure there is an issue in HA core.

BTW, can you help somehow with pushing this git issue forward? 3 weeks without any reaction. Not sure if it’s expected in case of such a crucial component like mqtt.

github.com/home-assistant/core

MQTT timeout misbehave after reloading mqtt entities

opened 01:56PM - 06 Jan 22 UTC

michalk-k

integration: mqtt

### The problem This issue is harder to describe preciselly or debug. But it …might be not so hard to find the issue in the code. In short: * There are battery powered devices (Shelly H&T) * All are configured manually in yaml as MQTT entities (see below for example) * Entities have `expire_after` set to 86400 (24h) Now, if I restart HA, it nothing wrong happens. Or in another words, everything works as expected indefinitely. Once I use reload mqtt entities using HA feature `YAML configuration reloading: MANUALLY CONFIGURED MQTT DEVICED` I can expect one or more devices will turn unavailable during incoming 24-48h. It happens even to devices configured to explicitely refresh their state even without change of sensing values (for example every 6 hours) So devices report thay are alive evey 6 hours, but HA turns them unavailable despite that. And for 99% it's related to reloading mqtt entities. What is even worse, when device is unavailable, it's not turned available by next temperature reporting. Following things are able to recover: 1. HA restart 2. Reload MQTT devices (with risk any other sensors will go offline in next day 3. wait for some time (probably for device announce performed periodicaly by it self) Obviously, setting up devices to not use `expire_after` feature solves the issue. But it also proves that there is something wrong with expiration evaluation. Examples below show 3 entities created from single Shelly device. From my observations, if one sensor turns unavailable, all other do the same. But it might be because the same expiration time. Not sure when exactly I experienced this issue for the first ime. But for sure I started be aware about it in year 2021. If my memory serves well, the feature of reloading mqtt entities has been implemented around begining of 2021. Here is extracted log from core and mqtt components set to debug logging. Below you can find short description. Dates are from Nov'21 - I took it from forum post. Today I found time to report it since the issue hit me again... after I reloaded entities yesterday. ``` cat ./home-assistant.log | grep -E "temp-kitchen|kitchen_temperature" | grep -v table ``` ``` 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-kitchen/sensor/temperature, mid: 5779 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature (retained): b'22.20' 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=None, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.100838+01:00>> 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.100838+01:00>, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.134957+01:00>> 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-kitchen/sensor/humidity, mid: 5780 2021-11-20 16:30:16 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity (retained): b'54.0' 2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.20' 2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-20T16:30:16.134957+01:00>, new_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T02:28:08.155853+01:00>> 2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'52.5' 2021-11-21 02:28:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100' 2021-11-21 11:04:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.20; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T02:28:08.155853+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T11:04:13.148924+01:00>> 2021-11-21 12:51:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T11:04:13.148924+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:51:16.969906+01:00>> 2021-11-21 12:54:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:51:16.969906+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:54:34.166672+01:00>> 2021-11-21 14:07:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T12:54:34.166672+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:07:50.729207+01:00>> 2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.45' 2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:07:50.729207+01:00>, new_state=<state sensor.kitchen_temperature=22.45; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:19:19.935248+01:00>> 2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'54.5' 2021-11-21 14:19:19 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100' 2021-11-21 14:21:20 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.45; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:19:19.935248+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:21:20.422972+01:00>> 2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/temperature: b'22.83' 2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:21:20.422972+01:00>, new_state=<state sensor.kitchen_temperature=22.83; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:25:08.503409+01:00>> 2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/humidity: b'54.0' 2021-11-21 14:25:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-kitchen/sensor/battery: b'100' 2021-11-21 14:27:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=22.83; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:25:08.503409+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:27:31.002663+01:00>> 2021-11-21 14:33:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:27:31.002663+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:33:31.424737+01:00>> 2021-11-21 14:36:52 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:33:31.424737+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:36:52.829243+01:00>> 2021-11-21 14:39:58 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:36:52.829243+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:39:58.600221+01:00>> 2021-11-21 14:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:39:58.600221+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:41:59.945812+01:00>> 2021-11-21 14:49:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.kitchen_temperature, old_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:41:59.945812+01:00>, new_state=<state sensor.kitchen_temperature=unavailable; unit_of_measurement=°C, friendly_name=Kitchen Temperature, device_class=temperature @ 2021-11-21T14:49:01.481926+01:00>> ``` Description to above: at 2:28 most recent temperature value has been received from mqtt and set in entity at 11:04 for some reason this sensor has been refreshed with the same values at 12:51 temperature sensor went unavailable, at 14:19 temperature is set to valid value because is refreshed from mqtt at 14:21 it turns unavailable again without reason at 14:25 temperature is set to valid value because is refreshed from mqtt at 14:27 it turns unavailable again without reason Reason of next sensor updates are not known for me but are executed roughly every 3 minutes not changing the state. Here is similar log for other sensor. The behavior and timing are the same: ``` 2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.components.mqtt] Subscribing to shellies/temp-pcroom/sensor/humidity, mid: 5774 2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.919348+01:00>, new_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.924397+01:00>> 2021-11-20 16:30:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity (retained): b'50.0' 2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'24.50' 2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=25.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T16:30:15.924397+01:00>, new_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T18:53:15.162819+01:00>> 2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'50.0' 2021-11-20 18:53:15 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100' 2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'23.50' 2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-20T18:53:15.162819+01:00>, new_state=<state sensor.pcroom_temperature=23.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T03:57:42.206813+01:00>> 2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'49.5' 2021-11-21 03:57:42 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100' 2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/temperature: b'24.50' 2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=23.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T03:57:42.206813+01:00>, new_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:20:29.190627+01:00>> 2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/humidity: b'50.0' 2021-11-21 11:20:29 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on shellies/temp-pcroom/sensor/battery: b'100' 2021-11-21 11:41:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=24.50; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:20:29.190627+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:41:07.293522+01:00>> 2021-11-21 12:51:16 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T11:41:07.293522+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T12:51:16.779165+01:00>> 2021-11-21 13:47:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T12:51:16.779165+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T13:47:07.439301+01:00>> 2021-11-21 14:07:50 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T13:47:07.439301+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:07:50.398601+01:00>> 2021-11-21 14:21:20 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:07:50.398601+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:21:20.243528+01:00>> 2021-11-21 14:27:30 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:21:20.243528+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:27:30.825043+01:00>> 2021-11-21 14:33:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:27:30.825043+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:33:31.245656+01:00>> 2021-11-21 14:35:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:33:31.245656+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:35:34.314269+01:00>> 2021-11-21 14:39:58 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:35:34.314269+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:39:58.214383+01:00>> 2021-11-21 14:41:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:39:58.214383+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:41:59.662461+01:00>> 2021-11-21 14:49:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.pcroom_temperature, old_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:41:59.662461+01:00>, new_state=<state sensor.pcroom_temperature=unavailable; unit_of_measurement=°C, friendly_name=PCroom Temperature, device_class=temperature @ 2021-11-21T14:49:01.204123+01:00>> ``` ### What version of Home Assistant Core has the issue? core-2021.12.7 ### What was the last working version of Home Assistant Core? _No response_ ### What type of installation are you running? Home Assistant OS ### Integration causing the issue sensor.mqtt, binary_sensor.mqtt etc ### Link to integration documentation on our website https://www.home-assistant.io/integrations/sensor.mqtt/ ### Example YAML snippet ```yaml ###### # KITCHEN SENSORS # - temperature # - humidity # - battery ###### - platform: mqtt name: "Kitchen Temperature" state_topic: "shellies/temp-kitchen/sensor/temperature" json_attributes_topic: "shellies/temp-kitchen/sensor/temperature" unit_of_measurement: "°C" force_update: true device_class: temperature expire_after: 86400 - platform: mqtt name: "Kitchen Humidity" state_topic: "shellies/temp-kitchen/sensor/humidity" json_attributes_topic: "shellies/temp-kitchen/sensor/humidity" unit_of_measurement: "%" payload_available: "true" payload_not_available: "false" force_update: true device_class: humidity expire_after: 86400 - platform: mqtt name: "Kitchen bttry" state_topic: "shellies/temp-kitchen/sensor/battery" unit_of_measurement: "%" payload_available: "true" payload_not_available: "false" force_update: true device_class: battery expire_after: 86400 ``` ### Anything in the logs that might be useful for us? _No response_ ### Additional information _No response_

petro · January 29, 2022, 11:36am

Issues like this could take months to identify before a fix can be applied. The fact that you can’t identify it yourself and you have the issue shows that anyone else without the issue is going to have even more difficulty identifying the problem. Best advice I can give is to be patient and keep the issue alive by responding in it.

maxym · January 29, 2022, 11:43am

Yeah, I’d like to respond and help but nobody asking questions. Im afraid that after month or two bots will start closing this issue due to no development activity (which is extremely discouraging for reporters and imo doesn’t help anything, but this is subject for another discussion)

I think I narrowed the issue down to the feature of manual reloading entities. There should be no big problem to find what has been forgotten (fixing might be more complex depending on various things, though)

petro · January 29, 2022, 11:44am

if you respond, the issue doesn’t get closed

petro · January 29, 2022, 11:44am

the bot does not distinguish between members and non-members. It only cares about active conversations

petro · January 29, 2022, 11:48am

here’s the code: as an FYI reloading reinits the entity. Both onboarding and reloading follow the same code. It could be related but I doubt it seeing as the config will be the same.

init

github.com

home-assistant/core/blob/049fc8a945a2956d0a056855b297a73ce8a1f4c6/homeassistant/components/mqtt/sensor.py#L150

    
      
              async_add_entities([MqttSensor(hass, config, config_entry, discovery_data)])
          
          

          
class MqttSensor(MqttEntity, SensorEntity):
              """Representation of a sensor that can be updated using MQTT."""
          
          
    _entity_id_format = ENTITY_ID_FORMAT
              _attr_last_reset = None
              _attributes_extra_blocked = MQTT_SENSOR_ATTRIBUTES_BLOCKED
          
          
    def __init__(self, hass, config, config_entry, discovery_data):
                  """Initialize the sensor."""
                  self._state = None
                  self._expiration_trigger = None
          
          
        expire_after = config.get(CONF_EXPIRE_AFTER)
                  if expire_after is not None and expire_after > 0:
                      self._expired = True
                  else:
                      self._expired = None

updating the state

github.com

home-assistant/core/blob/049fc8a945a2956d0a056855b297a73ce8a1f4c6/homeassistant/components/mqtt/sensor.py#L181

    
      
                  self._config.get(CONF_VALUE_TEMPLATE), entity=self
              ).async_render_with_possible_json_value
              self._last_reset_template = MqttValueTemplate(
                  self._config.get(CONF_LAST_RESET_VALUE_TEMPLATE), entity=self
              ).async_render_with_possible_json_value
          
          
async def _subscribe_topics(self):
              """(Re)Subscribe to topics."""
              topics = {}
          
          
    def _update_state(msg):
                  # auto-expire enabled?
                  expire_after = self._config.get(CONF_EXPIRE_AFTER)
                  if expire_after is not None and expire_after > 0:
                      # When expire_after is set, and we receive a message, assume device is not expired since it has to be to receive the message
                      self._expired = False
          
          
            # Reset old trigger
                      if self._expiration_trigger:
                          self._expiration_trigger()
                          self._expiration_trigger = None

the availability

github.com

home-assistant/core/blob/049fc8a945a2956d0a056855b297a73ce8a1f4c6/homeassistant/components/mqtt/sensor.py#L305

    
      
          def device_class(self) -> str | None:
              """Return the device class of the sensor."""
              return self._config.get(CONF_DEVICE_CLASS)
          
          
@property
          def state_class(self) -> str | None:
              """Return the state class of the sensor."""
              return self._config.get(CONF_STATE_CLASS)
          
          
@property
          def available(self) -> bool:
              """Return true if the device is available and value has not expired."""
              expire_after = self._config.get(CONF_EXPIRE_AFTER)
              # mypy doesn't know about fget: https://github.com/python/mypy/issues/6185
              return MqttAvailability.available.fget(self) and (  # type: ignore[attr-defined]
                  expire_after is None or not self._expired
              )

To me, if this were a bug it would be in the availability, and I would start looking at the fget because the availability is based on the expiration and if it exists in that database. The reload may clear that accidentally or something

github.com

home-assistant/core/blob/049fc8a945a2956d0a056855b297a73ce8a1f4c6/homeassistant/components/mqtt/sensor.py#L309

    
      
          @property
          def state_class(self) -> str | None:
              """Return the state class of the sensor."""
              return self._config.get(CONF_STATE_CLASS)
          
          
@property
          def available(self) -> bool:
              """Return true if the device is available and value has not expired."""
              expire_after = self._config.get(CONF_EXPIRE_AFTER)
              # mypy doesn't know about fget: https://github.com/python/mypy/issues/6185
              return MqttAvailability.available.fget(self) and (  # type: ignore[attr-defined]
                  expire_after is None or not self._expired
              )

maxym · February 18, 2022, 5:05pm

Hello. Seems the bug has been identified and the fix prepared.
But I’m not sure what next. Seems it didn’t get into any release yet. Label says it should be released withing 2022.2.x releases. (8 patches has been released since then)
Unfortunately more than 2 weeks there is no movement (while issue has been closed by a bot). I cannot find any information in github confirming it has been merged to official release branch.
Can you help describing current situation?

github.com/home-assistant/core

Fix MQTT expire_after effects after reloading

home-assistant:dev ← jbouwh:fix-mqtt-expire_after

opened 08:35AM - 01 Feb 22 UTC

jbouwh

+289 -18

## Proposed change  When the MQTT sensor or binary_sensor platform are used with the `expire_after` option, a timer used to auto expire the sensor value. When reloading the MQTT integration these sensors are not clean up and influence the availability the new loaded entity. The PR cleans up the old `sensor` and `binary_sensor` timers at reload. After reloading the sensor's state will be restored. A new timer will be started. When a new update is received the timer will be in sync again. This PR also fixed an error where entities that use `RestoreEntity` were tried to remove twice. ## Type of change  - [ ] Dependency upgrade - [x] Bugfix (non-breaking change which fixes an issue) - [ ] New integration (thank you!) - [ ] New feature (which adds functionality to an existing integration) - [ ] Breaking change (fix/feature causing existing functionality to break) - [ ] Code quality improvements to existing code or addition of tests ## Additional information  - This PR fixes or closes issue: fixes #63546 - This PR is related to issue: - Link to documentation pull request: ## Checklist  - [x] The code change is tested and works locally. - [x] Local tests pass. **Your PR cannot be merged unless tests pass** - [x] There is no commented out code in this PR. - [x] I have followed the [development checklist][dev-checklist] - [x] The code has been formatted using Black (`black --fast homeassistant tests`) - [x] Tests have been added to verify that the new code works. If user exposed functionality or configuration variables are added/changed: - [ ] Documentation added/updated for [www.home-assistant.io][docs-repository] If the code communicates with devices, web services, or third-party tools: - [ ] The [manifest file][manifest-docs] has all fields filled out correctly. Updated and included derived files by running: `python3 -m script.hassfest`. - [ ] New or updated dependencies have been added to `requirements_all.txt`. Updated by running `python3 -m script.gen_requirements_all`. - [ ] For the updated dependencies - a link to the changelog, or at minimum a diff between library versions is added to the PR description. - [ ] Untested files have been added to `.coveragerc`. The integration reached or maintains the following [Integration Quality Scale][quality-scale]:  - [ ] No score or internal - [ ] 🥈 Silver - [ ] 🥇 Gold - [ ] 🏆 Platinum  To help with the load of incoming pull requests: - [ ] I have reviewed two other [open pull requests][prs] in this repository. [prs]: https://github.com/home-assistant/core/pulls?q=is%3Aopen+is%3Apr+-author%3A%40me+-draft%3Atrue+-label%3Awaiting-for-upstream+sort%3Acreated-desc+review%3Anone+-status%3Afailure  [dev-checklist]: https://developers.home-assistant.io/docs/en/development_checklist.html [manifest-docs]: https://developers.home-assistant.io/docs/en/creating_integration_manifest.html [quality-scale]: https://developers.home-assistant.io/docs/en/next/integration_quality_scale_index.html [docs-repository]: https://github.com/home-assistant/home-assistant.io

petro · February 18, 2022, 5:10pm

it’s merged, so it’s probably going into 2022.3

maxym · February 18, 2022, 5:19pm

Yeah I saw merged to dev. But since emontnemery labeled it as 2022.2 milestone I though It will get to Feb.
Anyway thank you for instant answer.

petro · February 18, 2022, 5:22pm

I don’t know the process to 100%, but I’m fairly sure frenck just chooses the safest PR fixes for the xxxx.x.1+ fixes and all the volatile stuff goes into xxxx.x.0 & dev builds.

maxym · March 4, 2022, 3:28pm

Could you please assist me finding confirmation if this fix either landed in 2022.3 or not?
It seems it’s not mentioned in changelog as well as I cannot see any references in GitHub