core icon indicating copy to clipboard operation
core copied to clipboard

MQTT does not start up properly (sometimes)

Open umrath opened this issue 2 years ago • 22 comments

The problem

When restarting HA (to apply new settings, updates, etc.) I have a fair chance that MQTT is seemingly starting up properly - but missing certain functionalities. Most prominently, button events are not registered, even though they are clearly visible in Zigbee2MQTT.

The usual workaround: Restarting MQTT until it works again. Sometimes it works after restarting once, sometimes it need 2 or more restarts until all events are registered again.

In the logfile I cannot find anything remotely related. The events seem to just "vanish" silently.

What version of Home Assistant Core has the issue?

core-2024.4.3

What was the last working version of Home Assistant Core?

core-2024.1 (maybe)

What type of installation are you running?

Home Assistant OS

Integration causing the issue

MQTT

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

nothing I can remotely pin point to the issue

Additional information

This issue is fairly new. It probably started in Release 2024.3 or so.

umrath avatar Apr 22 '24 10:04 umrath

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

Code owner commands

Code owners of mqtt 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 mqtt Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


mqtt documentation mqtt source (message by IssueLinks)

home-assistant[bot] avatar Apr 25 '24 19:04 home-assistant[bot]

There were some improvements to MQTT startup in 2024.5.0b0

Is there a chance you can try beta?

bdraco avatar Apr 25 '24 19:04 bdraco

This would jeopardize the wife acceptance factor. So, I rather wait for 2024.5 to drop as stable.

umrath avatar Apr 26 '24 21:04 umrath

On my prod setup I have a similar issue since several releases. I tried with 2024.5.0b0 but it's not better.

So, restart HA will result in some entities unavailable (e.g lights, z2m bridge state) and others not (e.g z2m bridge version).

  • Reloading the MQTT (client) integration doesn't help.
  • Restarting the mosquitto broker addon doesn't help.
  • There is no WARNING or ERROR about that in the log.
  • HA sends birth messages (online) on the topic homeassistant/status when it restarts, but no will (offline). Despite it's configured in the mqtt integration configuration.
  • Push offline on homeassistant/status before restart HA doesn't help.
  • Unavailable entity devices MQTT Info tabs are empty. Like if they don't have received the MQTT autodiscovery payload.
  • config are available with mosquitto_sub -h core-mosquitto -v -t "homeassistant/+/+/+/config"

Restart Z2M after HA starts restore missing entities.

seblu avatar Apr 27 '24 21:04 seblu

The sending of will messages was fixed in #116319, a few hours after the previous report. I can confirm they are sent with HA 2024.5.0b2

➜  ~ mosquitto_sub -h core-mosquitto -v -t "homeassistant/status"                 
homeassistant/status online
homeassistant/status offline
homeassistant/status online

Original issue is not fixed. Here is an example with default entities exported by Z2M.

Screenshot_20240429_163301

seblu avatar Apr 29 '24 14:04 seblu

I don't know if this is helpful or not, but a way to "fix" this is to rename the button(s) to something else in Zigbee2MQTT (be sure to select "Update Home Assistant entity ID") and then back again. The action subtype isn't populated in the automation editor before doing this.

Skeletorjus avatar Apr 29 '24 20:04 Skeletorjus

Please note that when all entities are successfully started, restarting the broker does not cause the issue.

I enabled more logging on the moquitto broker and here is outputs focused on a light device soberly named Room3 Light with layer address 0x0017880103367d01. Lights are known to becoming unavailable after HA restart.

MQTT broker logs when HA restart

2024-04-30 11:44:01: Client hass closed its connection.
2024-04-30 11:44:07: New connection from 172.30.32.1:59111 on port 1883.
2024-04-30 11:44:07: New client connected from 172.30.32.1:59111 as hass (p5, c1, k30, u'homeassistant').
2024-04-30 11:44:07: Will message specified (7 bytes) (r1, q0).
2024-04-30 11:44:07: 	homeassistant/status
2024-04-30 11:44:07: Sending CONNACK to hass (0, 0)
2024-04-30 11:44:10: Received SUBSCRIBE from hass
2024-04-30 11:44:10: 	homeassistant/+/+/config (QoS 0)
2024-04-30 11:44:10: hass 0 homeassistant/+/+/config
2024-04-30 11:44:10: 	homeassistant/+/+/+/config (QoS 0)
2024-04-30 11:44:10: hass 0 homeassistant/+/+/+/config
2024-04-30 11:44:10: 	drop_connect/discovery/# (QoS 0)
2024-04-30 11:44:10: hass 0 drop_connect/discovery/#
2024-04-30 11:44:10: 	dsmr/# (QoS 0)
2024-04-30 11:44:10: hass 0 dsmr/#
2024-04-30 11:44:10: 	fully/deviceInfo/+ (QoS 0)
2024-04-30 11:44:10: hass 0 fully/deviceInfo/+
2024-04-30 11:44:10: 	tasmota/discovery/# (QoS 0)
2024-04-30 11:44:10: hass 0 tasmota/discovery/#
2024-04-30 11:44:10: Sending SUBACK to hass
...
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/power_on_behavior/config', ... (847 bytes))
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/linkquality/config', ... (871 bytes))
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/last_seen/config', ... (833 bytes))
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/update_state/config', ... (825 bytes))
...
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/binary_sensor/0x0017880103367d01/update_available/config', ... (882 bytes))
...
2024-04-30 11:44:10: Outgoing messages are being dropped for client hass.
...
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/update/0x0017880103367d01/update/config', ... (1283 bytes))
...
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/select/0x0017880103367d01/effect/config', ... (845 bytes))
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/select/0x0017880103367d01/power_on_behavior/config', ... (949 bytes))
...
2024-04-30 11:44:10: Sending PUBLISH to hass (d0, q0, r1, m0, 'homeassistant/light/0x0017880103367d01/light/config', ... (985 bytes))
...
2024-04-30 11:44:13: Received SUBSCRIBE from hass
...
2024-04-30 11:44:13: Sending SUBACK to hass
...
2024-04-30 11:44:17: Received SUBSCRIBE from hass
...
2024-04-30 11:44:17: Sending SUBACK to hass
...
2024-04-30 11:44:49: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 11:44:49: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 11:44:49: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 11:44:49: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))

Note:

  • HA client doesn't subscribe to the topic zigbee2mqtt/Room3 Light published in homeassistant/light/0x0017880103367d01/light/config at 2024-04-30 11:44:10.
  • There is a line Outgoing messages are being dropped for client hass.

MQTT auto-discovery payload of the light requested from external client

mosquitto_sub -h core-mosquitto -v -t "homeassistant/+/0x0017880103367d01/light/config"       
homeassistant/light/0x0017880103367d01/light/config {"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"},{"topic":"zigbee2mqtt/Room3 Light/availability","value_template":"{{ value_json.state }}"}],"availability_mode":"all","brightness":true,"brightness_scale":254,"color_mode":true,"command_topic":"zigbee2mqtt/Room3 Light/set","device":{"identifiers":["zigbee2mqtt_0x0017880103367d01"],"manufacturer":"Philips","model":"Hue Fair (4034031P7)","name":"Room3 Light","suggested_area":"Room3","sw_version":"1.108.5","via_device":"zigbee2mqtt_bridge_0x00124b0025e1e6ec"},"effect":true,"effect_list":["blink","breathe","okay","channel_change","candle","finish_effect","stop_effect","stop_hue_effect"],"max_mireds":500,"min_mireds":150,"name":null,"object_id":"room3_light","origin":{"name":"Zigbee2MQTT","sw":"1.36.1","url":"https://www.zigbee2mqtt.io"},"schema":"json","state_topic":"zigbee2mqtt/Room3 Light","supported_color_modes":["color_temp"],"unique_id":"0x0017880103367d01_light_zigbee2mqtt"}

MQTT broker logs when Z2M restart

2024-04-30 12:00:30: Received DISCONNECT from z2m
2024-04-30 12:00:30: Client z2m disconnected.
2024-04-30 12:00:42: New connection from 172.30.33.3:51256 on port 1883.
2024-04-30 12:00:42: New client connected from 172.30.33.3:51256 as z2m (p5, c1, k30, u'addons').
2024-04-30 12:00:42: Will message specified (19 bytes) (r1, q1).
2024-04-30 12:00:42: 	zigbee2mqtt/bridge/state
2024-04-30 12:00:42: Sending CONNACK to z2m (0, 0)
2024-04-30 12:00:42: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/bridge/state', ... (18 bytes))
2024-04-30 12:00:42: Sending PUBLISH to hass (d0, q0, r0, m0, 'zigbee2mqtt/bridge/state', ... (18 bytes))
2024-04-30 12:00:42: Received SUBSCRIBE from z2m
2024-04-30 12:00:42: 	zigbee2mqtt/# (QoS 0)
2024-04-30 12:00:42: z2m 0 zigbee2mqtt/#
...
2024-04-30 12:00:42: Sending PUBLISH to z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:00:42: Sending PUBLISH to z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light/availability', ... (18 bytes))
...
2024-04-30 12:00:43: Received PUBLISH from z2m (d0, q1, r1, m7217, 'zigbee2mqtt/Room3 Light/availability', ... (18 bytes))
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light/availability', ... (18 bytes))
...
2024-04-30 12:00:43: Received SUBSCRIBE from z2m
2024-04-30 12:00:43: 	homeassistant/status (QoS 0)
2024-04-30 12:00:43: z2m 0 homeassistant/status
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/status', ... (6 bytes))
2024-04-30 12:00:43: Received SUBSCRIBE from z2m
2024-04-30 12:00:43: 	homeassistant/# (QoS 0)
2024-04-30 12:00:43: z2m 0 homeassistant/#
...
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/power_on_behavior/config', ... (847 bytes))
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/linkquality/config', ... (871 bytes))
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/last_seen/config', ... (833 bytes))
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/sensor/0x0017880103367d01/update_state/config', ... (825 bytes))
...
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/binary_sensor/0x0017880103367d01/update_available/config', ... (882 bytes))
...
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/select/0x0017880103367d01/effect/config', ... (845 bytes))
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/select/0x0017880103367d01/power_on_behavior/config', ... (949 bytes))
...
2024-04-30 12:00:43: Sending PUBLISH to z2m (d0, q0, r1, m0, 'homeassistant/light/0x0017880103367d01/light/config', ... (985 bytes))
...
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7898, 'homeassistant/light/0x0017880103367d01/light/config', ... (985 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/light/0x0017880103367d01/light/config', ... (985 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/light/0x0017880103367d01/light/config', ... (985 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7898, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7899, 'homeassistant/sensor/0x0017880103367d01/power_on_behavior/config', ... (847 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/power_on_behavior/config', ... (847 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/power_on_behavior/config', ... (847 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7899, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7900, 'homeassistant/select/0x0017880103367d01/power_on_behavior/config', ... (949 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/select/0x0017880103367d01/power_on_behavior/config', ... (949 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/select/0x0017880103367d01/power_on_behavior/config', ... (949 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7900, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7901, 'homeassistant/select/0x0017880103367d01/effect/config', ... (845 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/select/0x0017880103367d01/effect/config', ... (845 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/select/0x0017880103367d01/effect/config', ... (845 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7901, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7902, 'homeassistant/sensor/0x0017880103367d01/linkquality/config', ... (871 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/linkquality/config', ... (871 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/linkquality/config', ... (871 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7902, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7903, 'homeassistant/sensor/0x0017880103367d01/last_seen/config', ... (833 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/last_seen/config', ... (833 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/last_seen/config', ... (833 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7903, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7904, 'homeassistant/sensor/0x0017880103367d01/update_state/config', ... (825 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/update_state/config', ... (825 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/sensor/0x0017880103367d01/update_state/config', ... (825 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7904, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7905, 'homeassistant/binary_sensor/0x0017880103367d01/update_available/config', ... (882 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/binary_sensor/0x0017880103367d01/update_available/config', ... (882 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/binary_sensor/0x0017880103367d01/update_available/config', ... (882 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7905, rc0)
2024-04-30 12:00:44: Received PUBLISH from z2m (d0, q1, r1, m7906, 'homeassistant/update/0x0017880103367d01/update/config', ... (1283 bytes))
2024-04-30 12:00:44: Sending PUBLISH to hass (d0, q0, r0, m0, 'homeassistant/update/0x0017880103367d01/update/config', ... (1283 bytes))
2024-04-30 12:00:44: Sending PUBLISH to z2m (d0, q0, r0, m0, 'homeassistant/update/0x0017880103367d01/update/config', ... (1283 bytes))
2024-04-30 12:00:44: Sending PUBACK to z2m (m7906, rc0)
...
2024-04-30 12:00:45: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:00:45: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
...
2024-04-30 12:00:46: Received SUBSCRIBE from hass
...
2024-04-30 12:00:46: 	zigbee2mqtt/Room3 Light/availability (QoS 0)
2024-04-30 12:00:46: hass 0 zigbee2mqtt/Room3 Light/availability
2024-04-30 12:00:46: 	zigbee2mqtt/Room3 Light (QoS 0)
2024-04-30 12:00:46: hass 0 zigbee2mqtt/Room3 Light
...
2024-04-30 12:00:46: Sending PUBLISH to hass (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light/availability', ... (18 bytes))
2024-04-30 12:00:46: Sending PUBLISH to hass (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
...
2024-04-30 12:00:47: Received SUBSCRIBE from hass
...
2024-04-30 12:01:13: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:01:13: Sending PUBLISH to hass (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:01:13: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
...
2024-04-30 12:01:15: Received PUBLISH from z2m (d0, q0, r1, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:01:15: Sending PUBLISH to hass (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))
2024-04-30 12:01:15: Sending PUBLISH to z2m (d0, q0, r0, m0, 'zigbee2mqtt/Room3 Light', ... (638 bytes))

In this case,

  • HA client subscribe to Room3 state topic (zigbee2mqtt/Room3 Light) after Z2M re-published mqtt autoconfig payload at config homeassistant/light/0x0017880103367d01/light/config.
  • HA client issue 2 batches of subscribe requests at 12:00:46 and 12:00:47`.

In both cases, payload of homeassistant/light/0x0017880103367d01/light/config is 985 bytes long. For some reason, when HA restarts, either it does not parse correctly the payload correctly or it fails to subscribe to the state topic.

seblu avatar Apr 30 '24 11:04 seblu

There was a change in 2024.5.b0 causing MQTT not to publish a will. That is offline to topic homeassistant/status. This could cause that Z2M is not triggered to publish configs and states. It was fixed with 2024.5.0b2. May be you can check if that solves the issue?

jbouwh avatar Apr 30 '24 13:04 jbouwh

There was a change in 2024.5.b0 causing MQTT not to publish a will. That is offline to topic homeassistant/status. This could cause that Z2M is not triggered to publish configs and states. It was fixed with 2024.5.0b2. May be you can check if that solves the issue?

I tested. It's mentioned here https://github.com/home-assistant/core/issues/115958#issuecomment-2082916942

seblu avatar Apr 30 '24 14:04 seblu

So what is it that is not working. After MQTT starts, it should replay any retained messages. That should bring up the entities in HA. When the birth message is published, the that should trigger Z2M to start publishing stuff. If that is not happening, then it could also be an issue with Z2M.

jbouwh avatar Apr 30 '24 15:04 jbouwh

Well, looks like my previous comments are not clear enough.

So what is it that is not working.

  1. HA starts, Z2M starts : OK. All devices and entities are discovered via MQTT.
  2. Z2M starts, HA starts : KO. Some devices and entities are unavailable.

After MQTT starts, it should replay any retained ages. That should bring up the entities in HA.

MQTT broker logs show that MQTT discovery topics previously published by Z2M are sent to HA MQTT client. For some reason, HA does not parse them and does not subscribe to state topics.

When the birth message is published, the that should trigger Z2M to start publishing stuff. If that is not happening, then it could also be an issue with Z2M.p

MQTT Discovery topics are retained, so they are published as soon as a new client subscribe. Why is Z2M has to publish stuff after birth messages?

seblu avatar Apr 30 '24 21:04 seblu

That does sound like the exact problem we just fixed in https://github.com/home-assistant/core/pull/116471

bdraco avatar Apr 30 '24 21:04 bdraco

This is what I think happened. Z2M is triggered by the birth message online to homeassistant/status. This message should be sent after the Home Assistant MQTT integration is connected AND has subscribed, so that it already has processed all retained config messages.

The birth message changes the availability and triggers Z2M to send status updates for all devices. If the birth message is sent to soon, and subscription has not been completed yet, status updated will be missed until subscription has been completed.

So what should happen is:

  1. HA MQTT is connecting to the broker
  2. HA MQTT is processing set up of all YAML config setups
  3. HA MQTT is subscribing for discovery updates, this triggers setup of all items that are set up through discovery.
  4. HA MQTT sends a birth message so availability for all devices toggle to online and Z2M starts sending status updates.

jbouwh avatar May 01 '24 06:05 jbouwh

I just give a try to 2024.5.0b6 which ship #116471 but some devices are still unavailable.

Regarding point 4., I don't think Z2M wait for HA to be online to send status update. Z2M sends them when they occurs and the last version is delivered by the broker when HA subscribe.

From my previous mosquito logs studies, I know that the broker is sending MQTT discovery topics when a client connects, so I should start looking into the HA mqtt debug logs to see if something may hint you.

seblu avatar May 01 '24 16:05 seblu

The configs are fine if they are retained, but devices become unavailable if they miss a status update. The online birth message is to be used for Z2M to no know HA is available. From that point entities should be updated and ZHA should start publishing the actual states.

jbouwh avatar May 01 '24 16:05 jbouwh

It feels like 2024.5 made it worse. I'm currently struggling to get it running for half an hour now.

umrath avatar May 02 '24 18:05 umrath

You have to wait till 2025.5.1

jbouwh avatar May 02 '24 18:05 jbouwh

cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d mqtt -p 116550

If you are adventurous and want to test as a custom component

bdraco avatar May 02 '24 18:05 bdraco

After 45 I got it to work, I think. Next time it fails, I will test it.

umrath avatar May 02 '24 18:05 umrath

Just went from 2024.04.4 to 2024.5.1, but now I can't get button automations to work regardless of how many restarts. Using Zigbee2MQTT 1.37.0-1.

Automations with button action just show "Unknown trigger". Seems to also be reported in https://github.com/home-assistant/core/issues/114660

andrejpavlovic avatar May 03 '24 18:05 andrejpavlovic

That's what I had yesterday. After 45 minutes of restarting mqtt and z2m randomly, it worked again. Real pain in the rear.

umrath avatar May 03 '24 19:05 umrath

2025.5.1 does not solve the problem - but reverts back to the originally reported state That means, I can solve the issue by restarting MQTT. (At least that's the way it was yesterday evening.)

Update: After another restart this morning I could replicate the original behaviour:

  1. After a restart, certain funcationalities were missing.
  2. A restart of MQTT fixes the issue.

Until a solution is available, I am tempted to solve this by triggering an automation about 5 minutes after restarting HA and if certain entities are not available by restarting MQTT.

(update2, translated to english. Sorry!)

umrath avatar May 06 '24 03:05 umrath

@umrath clear, thanks!

jbouwh avatar May 06 '24 05:05 jbouwh

@umrath I am going to tweak some of the startup parameters, may be you could try to see if that has any effect?

Could you try to set INITIAL_SUBSCRIBE_COOLDOWN = 3.0, may be you can play a bit with the param.

In homeassistant/components/mqtt/client.py L86 ?

This should wait longer (3 sec instead of 1sec) for new subscribe commands before publishing the birth message.

In my logs on dev I can see a 3 sec delay between the last processed component and publishing the online birth message. Not sure why this did not work during start up. May be you can check the MQTT logs

jbouwh avatar May 06 '24 07:05 jbouwh

@umrath How to restart MQTT to fix the issue after HA restart? I tried to reload and to disable/ enable MQTT without any success. Currently running on 2024.4.4, downgraded from 2024.5.1 - faced the issue first time not directly after the upgrades, it appeared after VM restart due to maintenance of the host system.

Marianp90 avatar May 06 '24 12:05 Marianp90

@umrath I am going to tweak some of the startup parameters, may be you could try to see if that has any effect?

Could you try to set INITIAL_SUBSCRIBE_COOLDOWN = 3.0, may be you can play a bit with the param.

In homeassistant/components/mqtt/client.py L86 ?

This should wait longer (3 sec instead of 1sec) for new subscribe commands before publishing the birth message.

In my logs on dev I can see a 3 sec delay between the last processed component and publishing the online birth message. Not sure why this did not work during start up. May be you can check the MQTT logs

I will check this later. Sounds interesting.

umrath avatar May 06 '24 13:05 umrath

@umrath How to restart MQTT to fix the issue after HA restart? I tried to reload and to disable/ enable MQTT without any success. Currently running on 2024.4.4, downgraded from 2024.5.1 - faced the issue first time not directly after the upgrades, it appeared after VM restart due to maintenance of the host system.

I reload the integration. In 2024.5.1 this fixed the problem reliably twice in a row (did not work in 2024.5).

umrath avatar May 06 '24 13:05 umrath

@umrath How to restart MQTT to fix the issue after HA restart? I tried to reload and to disable/ enable MQTT without any success. Currently running on 2024.4.4, downgraded from 2024.5.1 - faced the issue first time not directly after the upgrades, it appeared after VM restart due to maintenance of the host system.

I reload the integration. In 2024.5.1 this fixed the problem reliably twice in a row (did not work in 2024.5).

Ok, thanks. So simply go to settings -> integrations -> MQTT -> first and single item in the list -> click three dots -> reload, right? Seems not working for my OpenDTU integration - shows for a few seconds old data and then changes back to "unavailable" - even for 2024.5.1

Marianp90 avatar May 06 '24 15:05 Marianp90

I might have a related issue; Since upgrading to 2024.5, I need to restart MQTT-integration after restarting HA, otherwise all lock-entities are unavailable. But only lock. However, all my lock entities origin from Zigbee2MQTT. I have hundreds of other entities from Zigbee2MQTT (lights, sensors..) and they all seem to work fine even without restarting the integration - except locks. after reloading MQTT all is good.

For me, it is easy to reproduce, I just restart HA, then my locks are gone again.

BoneheadFraggle avatar May 06 '24 15:05 BoneheadFraggle

I have been having issues with my Roborock S5 not reconnecting to HA and all of my Zigbee buttons being non-responsive after a restart. I actually had the same problem in the subsequent reboot after upgrading to 2024.5.2 but I just restarted again and everything worked.

nomonkeynodeal avatar May 07 '24 03:05 nomonkeynodeal