MQTT devices are "glitching," flipping between available and not

1

I removed an esphome device (shouldn’t be related to the problem) and restarted HA, and now my MQTT devices are flip-flopping availability. These are devices that have been working well for years, and all of them are showing this behavior. I’ll attach picture showing the difference in a temperature sensor before and after reboot.

In an attempt to debug, I watched MQTT with mosquitto_sub. I noticed that the homeassistant/status topic was toggling:

mosquitto_sub -t 'homeassistant/status' 
2024-03-27 13:47:10.194 homeassistant/status offline
2024-03-27 13:47:15.621 homeassistant/status online
2024-03-27 13:47:47.981 homeassistant/status offline
2024-03-27 13:47:51.356 homeassistant/status online
2024-03-27 13:48:25.195 homeassistant/status online
2024-03-27 13:48:47.884 homeassistant/status offline
...

What does it mean for this topic to be offline?
Any tips on what I can do to debug further?

Screenshot_2024-03-27_15-21-20
Screenshot_2024-03-27_15-21-20791×526 21.5 KB

1 Like
2

Check your mqtt broker log.

3

I also looked there, but didn’t see anything suspicious. Client connecting and disconnecting, but nothing obviously correlating to HA coming and going.

I have been watching my home assistant logs, and get clear messages about connecting to MQTT. Things are quiet for a while, then I get this flurry of activity. I include the non-MQTT messages for completeness in case they are related.

HA log:

2024-03-27 16:14:13.629 INFO (MainThread) [homeassistant.config_entries] Reloading configuration entries because disabled_by changed in entity registry: 595e016761da4a359654ff65c4aa0d6f
2024-03-27 16:14:15.423 INFO (MainThread) [homeassistant.components.alarm_control_panel] Setting up alarm_control_panel.mqtt
2024-03-27 16:14:15.423 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.mqtt
2024-03-27 16:14:15.423 INFO (MainThread) [homeassistant.components.button] Setting up button.mqtt
2024-03-27 16:14:15.424 INFO (MainThread) [homeassistant.components.camera] Setting up camera.mqtt
2024-03-27 16:14:15.424 INFO (MainThread) [homeassistant.components.climate] Setting up climate.mqtt
2024-03-27 16:14:15.424 INFO (MainThread) [homeassistant.components.device_tracker] Setting up device_tracker.mqtt
2024-03-27 16:14:15.425 INFO (MainThread) [homeassistant.components.event] Setting up event.mqtt
2024-03-27 16:14:15.425 INFO (MainThread) [homeassistant.components.cover] Setting up cover.mqtt
2024-03-27 16:14:15.425 INFO (MainThread) [homeassistant.components.fan] Setting up fan.mqtt
2024-03-27 16:14:15.425 INFO (MainThread) [homeassistant.components.humidifier] Setting up humidifier.mqtt
2024-03-27 16:14:15.426 INFO (MainThread) [homeassistant.components.image] Setting up image.mqtt
2024-03-27 16:14:15.435 INFO (MainThread) [homeassistant.components.lawn_mower] Setting up lawn_mower.mqtt
2024-03-27 16:14:15.435 INFO (MainThread) [homeassistant.components.light] Setting up light.mqtt
2024-03-27 16:14:15.436 INFO (MainThread) [homeassistant.components.lock] Setting up lock.mqtt
2024-03-27 16:14:15.436 INFO (MainThread) [homeassistant.components.number] Setting up number.mqtt
2024-03-27 16:14:15.436 INFO (MainThread) [homeassistant.components.select] Setting up select.mqtt
2024-03-27 16:14:15.436 INFO (MainThread) [homeassistant.components.scene] Setting up scene.mqtt
2024-03-27 16:14:15.437 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.mqtt
2024-03-27 16:14:15.437 INFO (MainThread) [homeassistant.components.siren] Setting up siren.mqtt
2024-03-27 16:14:15.437 INFO (MainThread) [homeassistant.components.switch] Setting up switch.mqtt
2024-03-27 16:14:15.438 INFO (MainThread) [homeassistant.components.text] Setting up text.mqtt
2024-03-27 16:14:15.438 INFO (MainThread) [homeassistant.components.update] Setting up update.mqtt
2024-03-27 16:14:15.438 INFO (MainThread) [homeassistant.components.vacuum] Setting up vacuum.mqtt
2024-03-27 16:14:15.439 INFO (MainThread) [homeassistant.components.water_heater] Setting up water_heater.mqtt
2024-03-27 16:14:15.455 INFO (Thread-658 (_thread_main)) [homeassistant.components.mqtt.client] Connected to MQTT server localhost:1883 (0)
...

The MQTT broker logs show this at the same time:

1711577655: New connection from 127.0.0.1:35011 on port 1883.
1711577655: New client connected from 127.0.0.1:35011 as 64D7wEiALr2ihz46da8JTb (p2, c1, k60, u'myusername').
1711577656: Client 4fz0cJSqroqdgeeBpcb6Ab closed its connection.
1711577656: Client 28R1er2Za5g4jEzpzOINGm closed its connection.

Is there anything there that could indicate why HA reconnected to MQTT?

(edit: removed red herring errors by disabling automations causing them. The dump above still happens – timing it shows it’s every 30 second)

4

New information: That first entry in the log didn’t used to show up in my logs. What causes this and how do I find the problem entity?

INFO (MainThread) [homeassistant.config_entries] Reloading configuration entries because disabled_by changed in entity registry: 595e016761da4a359654ff65c4aa0d6f

A quick look in my core.entity_registry file in .storage shows lots of devices with that value as the config_entry_id. Is that normal to reuse config_entry_id between entities?

Edit: Found it clearly labeled in core.config_entries:

       "entry_id": "595e016761da4a359654ff65c4aa0d6f",
        "version": 1,
        "domain": "mqtt",
        "title": "configuration.yaml",

That also seems to own homeassistant/status topic. Why is this reload happening?

5

I’m not really sure.

Check your LWT settings: https://www.home-assistant.io/integrations/mqtt/#birth-and-last-will-messages

6

LWT are default. I disabled MQTT automatic discovery and the problem went away. I tried upgrading to latest HA release and it’s got the same behavior.

I would like to be able to turn auto discovery back on. Any tips would be appreciated.

7

Two things you could try:

  1. Enable debug logging for mqtt to see if that reveals any further info.

  2. Connect to your broker with MQTT Explorer and watch the /homeassistant discovery topics to see if any of them are updating constantly (the topic will highlight when a message is received).

8

Thanks for the debug tips. Watching /homeassistant didn’t reveal anything, just the offline/online messages from my first post.

Verbose broker is very verbose…

When the event happens, it looks like HA unsubscribes from everything, and then subscribes again.

1711662960: Received UNSUBSCRIBE from 2WKPKGtqjjjFmPMcfSJ4jA
1711662960: 	valetudo/rockrobo/GoToLocationCapability/presets
1711662960: 2WKPKGtqjjjFmPMcfSJ4jA valetudo/rockrobo/GoToLocationCapability/presets
1711662960: 	ovms/user/car/metric/v/c/time
1711662960: 2WKPKGtqjjjFmPMcfSJ4jA ovms/user/car/metric/v/c/time
1711662960: 	homecam/back/motion/detection
... [repeats, presumably for each device]
1711662960: Sending UNSUBACK to 2WKPKGtqjjjFmPMcfSJ4jA
1711662961: New connection from 127.0.0.1:47633 on port 1883.
1711662961: New client connected from 127.0.0.1:47633 as 4nia84f7fEf8hOqHifPgcq (p2, c1, k60, u'mymqttname').
1711662961: Will message specified (7 bytes) (r0, q0).
1711662961: 	homeassistant/status
1711662961: Sending CONNACK to 4nia84f7fEf8hOqHifPgcq (0, 0)
1711662962: Received SUBSCRIBE from 4nia84f7fEf8hOqHifPgcq
1711662962: 	ovms/user/car/metric/s/v2/connected (QoS 0)
1711662962: 4nia84f7fEf8hOqHifPgcq 0 ovms/user/car/metric/s/v2/connected
1711662962: 	ovms/user/car/metric/s/v3/connected (QoS 0)
... [repeats subscribing everything]
1711662962: Sending SUBACK to 4nia84f7fEf8hOqHifPgcq
1711662962: Sending PUBLISH to 4nia84f7fEf8hOqHifPgcq (d0, q0, r1, m0, 'ovms/user/car/metric/s/v2/connected', ... (3 bytes))
... [repeats publishing everything]

I don’t see anything terribly informative there, other than confirmation that HA is actively dropping and renewing things.

Any ideas what causes the Reloading configuration entries because disabled_by changed in entity that starts this whole thing off?