MQTT issue - won't start, shows no red flags

Sekh · June 10, 2024, 10:39am

Hello all,

I tried to switch a few days ago from ZHA to Zigbee2MQTT. I had it working but went backward to ZHA because the process took me so long that I just didn’t have the time to reset all devices on that evening.

Now I tried again and am running into a strange behaviour with the MQTT Broker (Mosquitto Broker). It appears it cannot start but I don’t see any abvious issue in the logs. I’ve uninstalled and re-installed both MQTT and Zigbee2MQTT several times to no avail.

I’ve restarted my home assistant at 12:25
Here is MQTT log

cont-init: info: /etc/cont-init.d/nginx.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun mosquitto (no readiness notification)
services-up: info: copying legacy longrun nginx (no readiness notification)
[11:35:11] INFO: Starting NGINX for authentication handling...
s6-rc: info: service legacy-services successfully started
[11:35:11] INFO: Starting mosquitto MQTT broker...
2024-06-10 11:35:11: Warning: Mosquitto should not be run as root/administrator.
2024-06-10 11:35:11: mosquitto version 2.0.18 starting
2024-06-10 11:35:11: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-06-10 11:35:11: Loading plugin: /usr/share/mosquitto/go-auth.so
2024-06-10 11:35:11:  ├── Username/password checking enabled.
2024-06-10 11:35:11:  ├── TLS-PSK checking enabled.
2024-06-10 11:35:11:  └── Extended authentication not enabled.
2024-06-10 11:35:11: Opening ipv4 listen socket on port 1883.
2024-06-10 11:35:11: Opening ipv6 listen socket on port 1883.
2024-06-10 11:35:11: Opening websockets listen socket on port 1884.
2024-06-10 11:35:11: mosquitto version 2.0.18 running
2024-06-10 11:35:11: New connection from 127.0.0.1:51518 on port 1883.
2024-06-10 11:35:11: Client <unknown> disconnected due to protocol error.
[11:35:12] INFO: Successfully send discovery information to Home Assistant.
[11:35:12] INFO: Successfully send service information to the Supervisor.
2024-06-10 11:35:16: New connection from 172.30.32.1:34939 on port 1883.
2024-06-10 11:35:16: Client 2ZPZv5nLrtP5vWiZGDxbXp disconnected, not authorised.
2024-06-10 11:39:09: New connection from 172.30.32.1:43571 on port 1883.
2024-06-10 11:39:09: New client connected from 172.30.32.1:43571 as 4kcFjVGaCxVPwBOO24Sfcd (p2, c1, k60, u'mqtt').
2024-06-10 11:39:10: Client 4kcFjVGaCxVPwBOO24Sfcd disconnected.
2024-06-10 11:39:10: New connection from 172.30.32.1:40185 on port 1883.
2024-06-10 11:39:10: New client connected from 172.30.32.1:40185 as 4qNjnq2Hxs0lf6IFJzPOkx (p2, c1, k60, u'mqtt').
2024-06-10 11:39:10: New connection from 172.30.32.1:42127 on port 1883.
2024-06-10 11:39:10: New client connected from 172.30.32.1:42127 as 2sGUs5CBALtrjLDGHFw0Kl (p2, c1, k60, u'mqtt').
s6-rc: info: service legacy-services: stopping
[09:40:05] INFO: Service restart after closing
2024-06-10 11:40:05: mosquitto version 2.0.18 terminating
time="2024-06-10T11:40:05+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T11:40:05+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/acl\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T11:40:05+02:00" level=error msg="Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
2024-06-10 11:40:05: Saving in-memory database to /data//mosquitto.db.
[09:40:05] INFO: Service restart after closing
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/mosquitto.sh
[11:47:29] INFO: SSL is not enabled
cont-init: info: /etc/cont-init.d/mosquitto.sh exited 0
cont-init: info: running /etc/cont-init.d/nginx.sh
cont-init: info: /etc/cont-init.d/nginx.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun mosquitto (no readiness notification)
services-up: info: copying legacy longrun nginx (no readiness notification)
[11:47:29] INFO: Starting NGINX for authentication handling...
s6-rc: info: service legacy-services successfully started
[11:47:29] INFO: Starting mosquitto MQTT broker...
2024-06-10 11:47:29: Warning: Mosquitto should not be run as root/administrator.
2024-06-10 11:47:29: mosquitto version 2.0.18 starting
2024-06-10 11:47:29: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-06-10 11:47:29: Loading plugin: /usr/share/mosquitto/go-auth.so
2024-06-10 11:47:29:  ├── Username/password checking enabled.
2024-06-10 11:47:29:  ├── TLS-PSK checking enabled.
2024-06-10 11:47:29:  └── Extended authentication not enabled.
2024-06-10 11:47:29: Opening ipv4 listen socket on port 1883.
2024-06-10 11:47:29: Opening ipv6 listen socket on port 1883.
2024-06-10 11:47:29: Opening websockets listen socket on port 1884.
2024-06-10 11:47:29: mosquitto version 2.0.18 running
2024-06-10 11:47:29: New connection from 127.0.0.1:46576 on port 1883.
2024-06-10 11:47:29: Client <unknown> disconnected due to protocol error.
[11:47:30] INFO: Successfully send discovery information to Home Assistant.
[11:47:30] INFO: Successfully send service information to the Supervisor.
2024-06-10 12:17:30: Saving in-memory database to /data//mosquitto.db.
2024-06-10 12:18:35: New connection from 172.30.33.4:47138 on port 1883.
2024-06-10 12:18:35: New client connected from 172.30.33.4:47138 as mqttjs_23eafec6 (p2, c1, k60, u'mqtt').
2024-06-10 12:19:47: New connection from 172.30.32.1:33429 on port 1883.
2024-06-10 12:19:47: New client connected from 172.30.32.1:33429 as 1Bz3iuI4FOw8q9PKy6XgMV (p2, c1, k60, u'homeassistant').
2024-06-10 12:19:47: Client 1Bz3iuI4FOw8q9PKy6XgMV disconnected.
2024-06-10 12:19:47: New connection from 172.30.32.1:59361 on port 1883.
2024-06-10 12:19:47: New client connected from 172.30.32.1:59361 as 0VVywc9XkemNLSsGHC9DNA (p2, c1, k60, u'homeassistant').
2024-06-10 12:21:15: New connection from 172.30.32.1:60329 on port 1883.
2024-06-10 12:21:15: Client 3IUbOc2DqkXKuyYKfvDjFI disconnected, not authorised.
2024-06-10 12:21:53: New connection from 172.30.32.1:43809 on port 1883.
2024-06-10 12:21:53: New client connected from 172.30.32.1:43809 as 5RR6kUO1toWo1avpIAZVUZ (p2, c1, k60, u'mqtt').
2024-06-10 12:21:53: Client 5RR6kUO1toWo1avpIAZVUZ disconnected.
2024-06-10 12:22:02: New connection from 172.30.32.1:42399 on port 1883.
2024-06-10 12:22:02: New client connected from 172.30.32.1:42399 as 4BuA5QxrqenQzy2l8WpowG (p2, c1, k60, u'mqtt').
2024-06-10 12:23:35: Client 0VVywc9XkemNLSsGHC9DNA has exceeded timeout, disconnecting.
2024-06-10 12:25:53: Client 4BuA5QxrqenQzy2l8WpowG closed its connection.
2024-06-10 12:26:01: New connection from 172.30.32.1:39117 on port 1883.
2024-06-10 12:26:01: New client connected from 172.30.32.1:39117 as 65Lr9hwI3vU7wl9ty6dAlX (p2, c1, k60, u'mqtt').
2024-06-10 12:30:13: Client mqttjs_23eafec6 disconnected.
2024-06-10 12:30:20: New connection from 172.30.33.4:43298 on port 1883.
2024-06-10 12:30:20: New client connected from 172.30.33.4:43298 as mqttjs_95a8c186 (p2, c1, k60, u'mqtt').

ZHA is disabled at the moment.

I guess the best option is to wipe MQTT and Zigbee2MQTT entirely but it seems uninstalling them doesn’t delete everything since the MQTT logs are still there after the re-install (perhaps the reason why re-installing them didn’t work).

I don’t know what to do to make it work…
Do you have any idea?

Sekh · June 10, 2024, 11:19am

I realize the MQTT logs isn’t showing up in chronological order !!

See below the full log for
MQTT

s6-rc: info: service legacy-services successfully started
[11:47:29] INFO: Starting mosquitto MQTT broker...
2024-06-10 11:47:29: Warning: Mosquitto should not be run as root/administrator.
2024-06-10 11:47:29: mosquitto version 2.0.18 starting
2024-06-10 11:47:29: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-06-10 11:47:29: Loading plugin: /usr/share/mosquitto/go-auth.so
2024-06-10 11:47:29:  ├── Username/password checking enabled.
2024-06-10 11:47:29:  ├── TLS-PSK checking enabled.
2024-06-10 11:47:29:  └── Extended authentication not enabled.
2024-06-10 11:47:29: Opening ipv4 listen socket on port 1883.
2024-06-10 11:47:29: Opening ipv6 listen socket on port 1883.
2024-06-10 11:47:29: Opening websockets listen socket on port 1884.
2024-06-10 11:47:29: mosquitto version 2.0.18 running
2024-06-10 11:47:29: New connection from 127.0.0.1:46576 on port 1883.
2024-06-10 11:47:29: Client <unknown> disconnected due to protocol error.
[11:47:30] INFO: Successfully send discovery information to Home Assistant.
[11:47:30] INFO: Successfully send service information to the Supervisor.
2024-06-10 12:17:30: Saving in-memory database to /data//mosquitto.db.
2024-06-10 12:18:35: New connection from 172.30.33.4:47138 on port 1883.
2024-06-10 12:18:35: New client connected from 172.30.33.4:47138 as mqttjs_23eafec6 (p2, c1, k60, u'mqtt').
2024-06-10 12:19:47: New connection from 172.30.32.1:33429 on port 1883.
2024-06-10 12:19:47: New client connected from 172.30.32.1:33429 as 1Bz3iuI4FOw8q9PKy6XgMV (p2, c1, k60, u'homeassistant').
2024-06-10 12:19:47: Client 1Bz3iuI4FOw8q9PKy6XgMV disconnected.
2024-06-10 12:19:47: New connection from 172.30.32.1:59361 on port 1883.
2024-06-10 12:19:47: New client connected from 172.30.32.1:59361 as 0VVywc9XkemNLSsGHC9DNA (p2, c1, k60, u'homeassistant').
2024-06-10 12:21:15: New connection from 172.30.32.1:60329 on port 1883.
2024-06-10 12:21:15: Client 3IUbOc2DqkXKuyYKfvDjFI disconnected, not authorised.
2024-06-10 12:21:53: New connection from 172.30.32.1:43809 on port 1883.
2024-06-10 12:21:53: New client connected from 172.30.32.1:43809 as 5RR6kUO1toWo1avpIAZVUZ (p2, c1, k60, u'mqtt').
2024-06-10 12:21:53: Client 5RR6kUO1toWo1avpIAZVUZ disconnected.
2024-06-10 12:22:02: New connection from 172.30.32.1:42399 on port 1883.
2024-06-10 12:22:02: New client connected from 172.30.32.1:42399 as 4BuA5QxrqenQzy2l8WpowG (p2, c1, k60, u'mqtt').
2024-06-10 12:23:35: Client 0VVywc9XkemNLSsGHC9DNA has exceeded timeout, disconnecting.
2024-06-10 12:25:53: Client 4BuA5QxrqenQzy2l8WpowG closed its connection.
2024-06-10 12:26:01: New connection from 172.30.32.1:39117 on port 1883.
2024-06-10 12:26:01: New client connected from 172.30.32.1:39117 as 65Lr9hwI3vU7wl9ty6dAlX (p2, c1, k60, u'mqtt').
2024-06-10 12:30:13: Client mqttjs_23eafec6 disconnected.
2024-06-10 12:30:20: New connection from 172.30.33.4:43298 on port 1883.
2024-06-10 12:30:20: New client connected from 172.30.33.4:43298 as mqttjs_95a8c186 (p2, c1, k60, u'mqtt').
s6-rc: info: service legacy-services: stopping
[10:41:35] INFO: Service restart after closing
2024-06-10 12:41:35: mosquitto version 2.0.18 terminating
time="2024-06-10T12:41:35+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T12:41:35+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/acl\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T12:41:35+02:00" level=error msg="Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T12:41:35+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T12:41:35+02:00" level=error msg="POST error: Post \"http://127.0.0.1:80/acl\": dial tcp 127.0.0.1:80: connect: connection refused"
time="2024-06-10T12:41:35+02:00" level=error msg="Post \"http://127.0.0.1:80/superuser\": dial tcp 127.0.0.1:80: connect: connection refused"
2024-06-10 12:41:35: Saving in-memory database to /data//mosquitto.db.
[10:41:35] INFO: Service restart after closing
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/mosquitto.sh
[13:08:29] INFO: SSL is not enabled
cont-init: info: /etc/cont-init.d/mosquitto.sh exited 0
cont-init: info: running /etc/cont-init.d/nginx.sh
cont-init: info: /etc/cont-init.d/nginx.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun mosquitto (no readiness notification)
services-up: info: copying legacy longrun nginx (no readiness notification)
[13:08:29] INFO: Starting NGINX for authentication handling...
s6-rc: info: service legacy-services successfully started
[13:08:30] INFO: Starting mosquitto MQTT broker...
2024-06-10 13:08:30: Warning: Mosquitto should not be run as root/administrator.
2024-06-10 13:08:30: mosquitto version 2.0.18 starting
2024-06-10 13:08:30: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-06-10 13:08:30: Loading plugin: /usr/share/mosquitto/go-auth.so
2024-06-10 13:08:30:  ├── Username/password checking enabled.
2024-06-10 13:08:30:  ├── TLS-PSK checking enabled.
2024-06-10 13:08:30:  └── Extended authentication not enabled.
2024-06-10 13:08:30: Opening ipv4 listen socket on port 1883.
2024-06-10 13:08:30: Opening ipv6 listen socket on port 1883.
2024-06-10 13:08:30: Opening websockets listen socket on port 1884.
2024-06-10 13:08:30: mosquitto version 2.0.18 running
2024-06-10 13:08:30: New connection from 127.0.0.1:39726 on port 1883.
2024-06-10 13:08:30: Client <unknown> disconnected due to protocol error.
[13:08:30] INFO: Successfully send discovery information to Home Assistant.
[13:08:30] INFO: Successfully send service information to the Supervisor.
2024-06-10 13:09:15: New connection from 172.30.32.1:42997 on port 1883.
2024-06-10 13:09:15: New client connected from 172.30.32.1:42997 as 4LlZ3uNpa21M14pnrQJ3q9 (p2, c1, k60, u'homeassistant').
2024-06-10 13:09:15: Client 4LlZ3uNpa21M14pnrQJ3q9 disconnected.
2024-06-10 13:09:15: New connection from 172.30.32.1:38515 on port 1883.
2024-06-10 13:09:15: New client connected from 172.30.32.1:38515 as 6HwKZdG9tJiDNwNnTFGExV (p2, c1, k60, u'homeassistant').
2024-06-10 13:12:23: New connection from 172.30.33.4:56112 on port 1883.
2024-06-10 13:12:23: New client connected from 172.30.33.4:56112 as mqttjs_51cdfd25 (p2, c1, k60, u'mqtt').
2024-06-10 13:14:20: New connection from 172.30.32.1:54785 on port 1883.
2024-06-10 13:14:20: New client connected from 172.30.32.1:54785 as 2x6YiXG3Ww0qLGhyO506wd (p2, c1, k60, u'mqtt').
2024-06-10 13:14:20: Client 2x6YiXG3Ww0qLGhyO506wd disconnected.
2024-06-10 13:14:23: New connection from 172.30.32.1:43037 on port 1883.
2024-06-10 13:14:23: New client connected from 172.30.32.1:43037 as 2CrBSt8A1zwijdERA6CmYD (p2, c1, k60, u'mqtt').

and for Zigbee2MQTT

[2024-06-10 12:49:23] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:24] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:25] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:26] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:27] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:28] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:29] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:30] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:31] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:49:35] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:36] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:37] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:38] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:39] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:41] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:49:44] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:45] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:46] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:47] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:48] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:51] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:49:53] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:54] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:55] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:56] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:49:57] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:01] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:01] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:02] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:04] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:05] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:06] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:07] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:08] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:09] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:10] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:11] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:11] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:15] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:16] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:17] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:18] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:19] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:21] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:24] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:25] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:26] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:27] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:28] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:30] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:31] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:31] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:32] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:33] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:34] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:39] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:40] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:41] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:41] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:42] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:43] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:48] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:49] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:50] error: 	z2m:mqtt: MQTT error: getaddrinfo ENOTFOUND core-mosquitto
[2024-06-10 12:50:51] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:51] error: 	z2m:mqtt: Not connected to MQTT server!
[2024-06-10 12:50:51] error: 	z2m:mqtt: Cannot send message: topic: 'zigbee2mqtt/bridge/state', payload: '{"state":"offline"}
[2024-06-10 12:50:51] info: 	z2m:mqtt: Disconnecting from MQTT server
[2024-06-10 12:50:51] info: 	z2m: Stopping zigbee-herdsman...
[2024-06-10 12:50:58] info: 	zh:controller: Wrote coordinator backup to '/config/zigbee2mqtt/coordinator_backup.json'
[2024-06-10 12:50:58] info: 	zh:zstack:znp: closing
[2024-06-10 12:50:58] info: 	zh:zstack:znp: Port closed
[2024-06-10 12:50:58] info: 	z2m: Stopped zigbee-herdsman
[2024-06-10 12:50:58] info: 	z2m: Stopped Zigbee2MQTT
[13:12:20] INFO: Preparing to start...
[13:12:21] INFO: Socat not enabled
[13:12:21] INFO: Starting Zigbee2MQTT...
[2024-06-10 13:12:23] info: 	z2m: Logging to console, file (filename: log.log)
[2024-06-10 13:12:23] info: 	z2m: Starting Zigbee2MQTT version 1.38.0 (commit #unknown)
[2024-06-10 13:12:23] info: 	z2m: Starting zigbee-herdsman (0.49.2)
[2024-06-10 13:12:23] info: 	zh:zstack:znp: Opening SerialPort with {"path":"/dev/ttyUSB0","baudRate":115200,"rtscts":false,"autoOpen":false}
[2024-06-10 13:12:23] info: 	zh:zstack:znp: Serialport opened
[2024-06-10 13:12:23] info: 	z2m: zigbee-herdsman started (resumed)
[2024-06-10 13:12:23] info: 	z2m: Coordinator firmware version: '{"meta":{"maintrel":1,"majorrel":2,"minorrel":7,"product":1,"revision":20210708,"transportrev":2},"type":"zStack3x0"}'
[2024-06-10 13:12:23] info: 	z2m: Currently 0 devices are joined:
[2024-06-10 13:12:23] info: 	z2m: Zigbee: disabling joining new devices.
[2024-06-10 13:12:23] info: 	z2m:mqtt: Connecting to MQTT server at mqtt://core-mosquitto:1883
[2024-06-10 13:12:23] info: 	z2m:mqtt: Connected to MQTT server
[2024-06-10 13:12:23] info: 	z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
[2024-06-10 13:12:23] info: 	z2m: Started frontend on port 8099
[2024-06-10 13:12:23] info: 	z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
[2024-06-10 13:12:23] info: 	z2m: Zigbee2MQTT started!
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/binary_sensor/1221051039810110150109113116116_0x00124b002a2e5e50/connection_state/config', payload '{"device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"device_class":"connectivity","entity_category":"diagnostic","name":"Connection state","object_id":"zigbee2mqtt_bridge_connection_state","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"payload_off":"offline","payload_on":"online","state_topic":"zigbee2mqtt/bridge/state","unique_id":"bridge_0x00124b002a2e5e50_connection_state_zigbee2mqtt","value_template":"{{ value_json.state }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/binary_sensor/1221051039810110150109113116116_0x00124b002a2e5e50/restart_required/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"device_class":"problem","enabled_by_default":false,"entity_category":"diagnostic","name":"Restart required","object_id":"zigbee2mqtt_bridge_restart_required","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"payload_off":false,"payload_on":true,"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_restart_required_zigbee2mqtt","value_template":"{{ value_json.restart_required }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/button/1221051039810110150109113116116_0x00124b002a2e5e50/restart/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_topic":"zigbee2mqtt/bridge/request/restart","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"device_class":"restart","name":"Restart","object_id":"zigbee2mqtt_bridge_restart","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"payload_press":"","unique_id":"bridge_0x00124b002a2e5e50_restart_zigbee2mqtt"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/select/1221051039810110150109113116116_0x00124b002a2e5e50/log_level/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_template":"{\"options\": {\"advanced\": {\"log_level\": \"{{ value }}\" } } }","command_topic":"zigbee2mqtt/bridge/request/options","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"entity_category":"config","name":"Log level","object_id":"zigbee2mqtt_bridge_log_level","options":["error","warning","info","debug"],"origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_log_level_zigbee2mqtt","value_template":"{{ value_json.log_level | lower }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/sensor/1221051039810110150109113116116_0x00124b002a2e5e50/version/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"entity_category":"diagnostic","icon":"mdi:zigbee","name":"Version","object_id":"zigbee2mqtt_bridge_version","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_version_zigbee2mqtt","value_template":"{{ value_json.version }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/sensor/1221051039810110150109113116116_0x00124b002a2e5e50/coordinator_version/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"enabled_by_default":false,"entity_category":"diagnostic","icon":"mdi:chip","name":"Coordinator version","object_id":"zigbee2mqtt_bridge_coordinator_version","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_coordinator_version_zigbee2mqtt","value_template":"{{ value_json.coordinator.meta.revision }}"}'
[2024-06-10 13:12:28] info: 	undefined: MQTT publish: topic 'homeassistant/sensor/1221051039810110150109113116116_0x00124b002a2e5e50/network_map/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"enabled_by_default":false,"entity_category":"diagnostic","json_attributes_template":"{{ value_json.data.value | tojson }}","json_attributes_topic":"zigbee2mqtt/bridge/response/networkmap","name":"Network map","object_id":"zigbee2mqtt_bridge_network_map","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/response/networkmap","unique_id":"bridge_0x00124b002a2e5e50_network_map_zigbee2mqtt","value_template":"{{ now().strftime('%Y-%m-%d %H:%M:%S') }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/sensor/1221051039810110150109113116116_0x00124b002a2e5e50/permit_join_timeout/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"device_class":"duration","entity_category":"diagnostic","name":"Permit join timeout","object_id":"zigbee2mqtt_bridge_permit_join_timeout","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_permit_join_timeout_zigbee2mqtt","unit_of_measurement":"s","value_template":"{{ iif(value_json.permit_join_timeout is defined, value_json.permit_join_timeout, None) }}"}'
[2024-06-10 13:12:28] info: 	z2m:mqtt: MQTT publish: topic 'homeassistant/switch/1221051039810110150109113116116_0x00124b002a2e5e50/permit_join/config', payload '{"availability":[{"topic":"zigbee2mqtt/bridge/state","value_template":"{{ value_json.state }}"}],"availability_mode":"all","command_topic":"zigbee2mqtt/bridge/request/permit_join","device":{"hw_version":"zStack3x0 20210708","identifiers":["zigbee2mqtt_bridge_0x00124b002a2e5e50"],"manufacturer":"Zigbee2MQTT","model":"Bridge","name":"Zigbee2MQTT Bridge","sw_version":"1.38.0"},"icon":"mdi:human-greeting-proximity","name":"Permit join","object_id":"zigbee2mqtt_bridge_permit_join","origin":{"name":"Zigbee2MQTT","sw":"1.38.0","url":"https://www.zigbee2mqtt.io"},"payload_off":"false","payload_on":"true","state_topic":"zigbee2mqtt/bridge/info","unique_id":"bridge_0x00124b002a2e5e50_permit_join_zigbee2mqtt","value_template":"{{ value_json.permit_join | lower }}"}'

It makes no sense to me and it’s driving me crazy

petro · June 10, 2024, 11:28am

I’m not sure what’s not making sense? Z2m is connecting just fine.

and

That’s z2m.

Also, they are in chronological order, not sure where you’re getting the idea that they aren’t.

I only see 1 or 2 disconnections in your logs, most likely due to you restarting z2m (there’s only 1 z2m disconnection). The other disconnections are random non-z2m devices.

So what’s the actual problem here? Your broker is starting, z2m is starting.

Sekh · June 10, 2024, 11:43am

Thanks for your answer.

I have an event at [10:41:35] between [13:08:29] and [11:47:30]

It looks like it, but they aren’t.
When I’m going to Zigbee2MQTT in the sidebar, I get this message

When I’m checking both add-ons, they’re grey

And when I’m opening them, they appear in red (stopped)

Of course, trying to launch them manually doesn’t change anything.

Thanks again for your help!

petro · June 10, 2024, 11:47am

No you don’t… you must be reading the log incorrectly.

These are log lines:

Any line that doesn’t start with a timestamp formatted exactly like that, is a part of the previous log. In your case this is 1 log entry:

Sekh:

2024-06-10 12:30:20: New client connected from 172.30.33.4:43298 as mqttjs_95a8c186 (p2, c1, k60, u'mqtt').
s6-rc: info: service legacy-services: stopping
[10:41:35] INFO: Service restart after closing

What does the addon itself show, refresh the page when looking at the addon.

Sekh · June 10, 2024, 12:07pm

You’re right, my bad.

I’m not sure to understand what you’re looking for.
Do you mean in the info tab?

When I’m launching the Mosquitto broker or the Zigbee2MQTT addon, I get a animation on the launch/start button, but it’s not going any further. When I refresh the page, it remains stopped and I have the option to either start or uninstall it.

That’s what’s frustrating, I get no error message at all. It just shows up as stopped…

petro · June 10, 2024, 12:08pm

Start up the MQTT broker, then go to the MQTT broker logs and watch them. Then before starting again, refresh the log page if the addon still hasn’t started. That will contain your errors.

Sekh · June 10, 2024, 12:14pm

I saw that the logs aren’t updated each time I try to start Mosquitto broker…

I tried several times within the last 5 minutes and only got that addionnal line.

2024-06-10 14:08:31: Saving in-memory database to /data//mosquitto.db.

petro · June 10, 2024, 12:20pm

when you restart the addon, you’ll get a new fresh log with new timestamps. A completely new fresh log. Are you refreshing the page?

Sekh · June 10, 2024, 12:27pm

Just to be clear, it’s never showing green meaning I never get to see the restart button. I hit the start button, it doesn’t do much and when I refresh the page, it’s still showing up as stopped. I only get the option to start or uninstall.

NB: log don’t even reset after uninstalling/reinstalling Mosquitto broker.

petro · June 10, 2024, 12:29pm

Correct, but you can look at the logs after you do this and it will show you a full startup sequence that it attempted to do.

You are looking at the ADDON logs, not HA logs.

Sekh · June 10, 2024, 1:01pm

I think I’m doing just that
Here’s a video

petro · June 10, 2024, 1:04pm

Are you refreshing the page? the log should be completely new. That log is not. This tells me the supervisor is not starting the addon when you click start. Post the supervisor logs.

Sekh · June 10, 2024, 1:10pm

Here you go

2024-06-10 13:05:22.405 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
2024-06-10 13:05:22.453 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
2024-06-10 13:05:22.454 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
2024-06-10 13:05:22.456 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-06-10 13:05:22.464 INFO (MainThread) [supervisor.resolution.checks.base] Run check for disabled_data_disk/system
2024-06-10 13:05:22.464 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-06-10 13:05:22.464 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-06-10 13:05:22.530 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-06-10 13:05:22.531 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-06-10 13:05:22.531 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2024-06-10 13:05:44.301 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/zigbee2mqtt/hassio-zigbee2mqtt repository
2024-06-10 13:05:44.303 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/FunkeyFlo/ps5-mqtt repository
2024-06-10 13:05:44.306 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/esphome/home-assistant-addon repository
2024-06-10 13:05:44.308 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/home-assistant/addons repository
2024-06-10 13:05:44.311 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/hassio-addons/repository repository
2024-06-10 13:05:45.450 INFO (MainThread) [supervisor.store] Loading add-ons from store: 82 all - 0 new - 0 remove
2024-06-10 13:05:45.450 INFO (MainThread) [supervisor.store] Loading add-ons from store: 82 all - 0 new - 0 remove
2024-06-10 13:08:28.863 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on homeassistant/amd64-addon-mosquitto with version 6.4.1
2024-06-10 13:08:30.500 INFO (MainThread) [supervisor.discovery] Sending discovery to Home Assistant mqtt from core_mosquitto
2024-06-10 13:08:30.523 INFO (MainThread) [supervisor.discovery] Discovery c5280a737a5b4eabb18f000be20e1f6d message send
2024-06-10 13:08:30.768 INFO (MainThread) [supervisor.services.modules.mqtt] Set core_mosquitto as service provider for mqtt
2024-06-10 13:10:22.814 INFO (MainThread) [supervisor.addons.addon] No 45df7312_zigbee2mqtt addon Docker image zigbee2mqtt/zigbee2mqtt-amd64 found
2024-06-10 13:10:22.815 INFO (MainThread) [supervisor.docker.interface] Downloading docker image zigbee2mqtt/zigbee2mqtt-amd64 with tag 1.38.0-1.
2024-06-10 13:10:28.644 INFO (MainThread) [supervisor.addons.addon] Creating Home Assistant add-on data folder /data/addons/data/45df7312_zigbee2mqtt
2024-06-10 13:10:28.645 INFO (MainThread) [supervisor.docker.interface] Downloading docker image zigbee2mqtt/zigbee2mqtt-amd64 with tag 1.38.0-1.
2024-06-10 13:10:28.865 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 13:10:29.560 INFO (MainThread) [supervisor.addons.manager] Add-on '45df7312_zigbee2mqtt' successfully installed
2024-06-10 13:11:42.586 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-06-10 13:11:51.699 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 13:12:18.145 INFO (MainThread) [supervisor.ingress] Update Ingress as panel for 45df7312_zigbee2mqtt
2024-06-10 13:12:20.961 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on zigbee2mqtt/zigbee2mqtt-amd64 with version 1.38.0-1
2024-06-10 13:12:23.586 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'mqtt'
2024-06-10 13:12:23.851 INFO (MainThread) [supervisor.auth] Successful login for 'mqtt'
2024-06-10 13:13:25.390 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 13:13:51.701 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 13:14:20.962 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Zigbee2MQTT to start, took more than 120 seconds
2024-06-10 13:14:43.958 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 13:14:56.760 WARNING (MainThread) [supervisor.addons.addon] 45df7312_zigbee2mqtt is already running!
2024-06-10 13:15:02.986 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 13:15:25.392 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 13:16:43.961 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 13:16:56.762 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Zigbee2MQTT to start, took more than 120 seconds
2024-06-10 13:17:02.988 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 13:38:50.288 INFO (MainThread) [supervisor.host.info] Updating local host information
2024-06-10 13:38:50.606 INFO (MainThread) [supervisor.host.services] Updating service information
2024-06-10 13:38:50.610 INFO (MainThread) [supervisor.host.network] Updating local network information
2024-06-10 13:38:50.679 INFO (MainThread) [supervisor.host.sound] Updating PulseAudio information
2024-06-10 13:38:50.682 INFO (MainThread) [supervisor.host.manager] Host information reload completed
2024-06-10 13:41:42.711 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-06-10 14:05:10.457 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 14:05:18.350 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
2024-06-10 14:05:22.536 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
2024-06-10 14:05:22.537 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
2024-06-10 14:05:22.537 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
2024-06-10 14:05:22.537 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
2024-06-10 14:05:22.538 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-06-10 14:05:22.538 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
2024-06-10 14:05:22.538 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
2024-06-10 14:05:22.539 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-06-10 14:05:22.539 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
2024-06-10 14:05:22.540 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
2024-06-10 14:05:22.540 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-06-10 14:05:22.547 INFO (MainThread) [supervisor.resolution.checks.base] Run check for disabled_data_disk/system
2024-06-10 14:05:22.547 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-06-10 14:05:22.548 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-06-10 14:05:22.603 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-06-10 14:05:22.604 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-06-10 14:05:22.604 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2024-06-10 14:06:28.966 WARNING (MainThread) [supervisor.addons.addon] 45df7312_zigbee2mqtt is already running!
2024-06-10 14:07:10.460 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 14:08:28.969 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Zigbee2MQTT to start, took more than 120 seconds
2024-06-10 14:11:24.248 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 14:11:42.841 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-06-10 14:13:24.250 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 14:27:39.104 WARNING (MainThread) [supervisor.addons.addon] 45df7312_zigbee2mqtt is already running!
2024-06-10 14:29:39.106 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Zigbee2MQTT to start, took more than 120 seconds
2024-06-10 14:41:42.969 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-06-10 14:53:32.368 WARNING (MainThread) [supervisor.addons.addon] core_mosquitto is already running!
2024-06-10 14:55:32.371 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Mosquitto broker to start, took more than 120 seconds
2024-06-10 15:05:22.612 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
2024-06-10 15:05:22.612 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
2024-06-10 15:05:22.612 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
2024-06-10 15:05:22.659 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
2024-06-10 15:05:22.660 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-06-10 15:05:22.660 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
2024-06-10 15:05:22.660 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
2024-06-10 15:05:22.660 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-06-10 15:05:22.661 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
2024-06-10 15:05:22.661 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
2024-06-10 15:05:22.662 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-06-10 15:05:22.665 INFO (MainThread) [supervisor.resolution.checks.base] Run check for disabled_data_disk/system
2024-06-10 15:05:22.665 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-06-10 15:05:22.665 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-06-10 15:05:22.718 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-06-10 15:05:22.718 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-06-10 15:05:22.718 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete

Sekh · June 10, 2024, 1:13pm

It says “core_mosquitto is already running!” each time I try to start it
But is shows it “stopped” when I check the addon.
It looks like it times out each time, despite detecting that it’s already running…

petro · June 10, 2024, 1:33pm

Yes, but have you refreshed the page? This is a browser, it may be showing you false data from browser cache. I know I keep saying refresh the page, I’m saying it because it’s important that you do that. Sometimes the UI is out of sync with what’s really happening.

Sekh · June 10, 2024, 1:50pm

Yes I did. I retried multiple times, it’s always the same behaviour.

I hit the start button on the Mosquitto Broker add-on, nothing happens
Refresh page, nothing else happens
Go to add-on logs, nothing new there
Go to Supervisor, shows “core_mosquitto is already running!” + timeout after 120 seconds

petro · June 10, 2024, 2:02pm

Then try rebooting your system.

Sekh · June 10, 2024, 2:06pm

Done as well, several times
Same behaviour

petro · June 10, 2024, 2:11pm

I’m not sure what to tell you.