addons icon indicating copy to clipboard operation
addons copied to clipboard

Mosquitto broker Add-on is not initialized correctly when HA starts

Open rmsmirnov opened this issue 1 year ago • 21 comments

Describe the issue you are experiencing

Hi everyone,

I’ve run into the problem with Mosquitto broker Add-on. When I restart the OS the add-on doesn’t start correctly. It shows the following errors in the log:

[cont-init.d] executing container initialization scripts... [cont-init.d] mosquitto.sh: executing... parse error: Expected string key before ':' at line 1, column 4 [08:21:01] ERROR: Unknown HTTP error occured [08:21:04] INFO: SSL is not enabled

and

[08:21:09] INFO: Starting mosquitto MQTT broker... 1660713669: Warning: Mosquitto should not be run as root/administrator. parse error: Expected string key before ':' at line 1, column 4 [08:21:13] ERROR: Unknown HTTP error occured [08:21:13] INFO: Successfully send discovery information to Home Assistant.

Because Mosquitto broker starts with errors the other add-ons which depends on Mosquitto also start with errors (for example Zigbee2Mqtt).

However if I login to HA web-interface after HA has been fully initialized and manually restart the Mosquitto broker (through Settings->Add-ons menu) then the add-on starts without any error and it begins to operate in normal mode. And then I restart other add-ons (Z2M etc) and they also start working as expected. So to summarize: Mosquitto broker starts normally only from the second attempt.

I was able to reproduce the problem on three devices – one is Raspberry Pi 4 and two are running under Armbian. So it seems that we problem is not device-specific. Also I suspect that the problem began when I’ve upgraded OS from Focal to Jammy through the command do-release-upgrade.

I use HA in Supervised mode and I use only default add-ons settings. Just to be sure I couple times made “Reset to defaults”, unfortunately it didn’t help. Here is the add-on config in my installation:

logins: [] require_certificate: false certfile: fullchain.pem keyfile: privkey.pem customize: active: false folder: mosquitto

I did some debugging with cont-init.d/mosquitto.sh and found that the error occurs when script tries to execute bashio::config command. Next I looked at addons/core/mosquitto/config.yaml and found that 1st line of it contained three defis symbols ‘-‘. It is very close interconnected with the error message “parse error: Expected string key before ‘:’ at line 1, column 4”. I’ve tried to remove this 1st line however it seems that the file addons/core/mosquitto/config.yaml is restored from somewhere (Git?) every time HA starts.

I would like to disable auto-update for file addons/core/mosquitto/config.yaml (or for some upper folder) just to validate my assumption. How to do it?

Thanks in advance.

What type of installation are you running?

Home Assistant Supervised

Which operating system are you running on?

Other (e.g., Raspbian/Raspberry Pi OS/Fedora)

Which add-on are you reporting an issue with?

Mosquitto broker

What is the version of the add-on?

6.1.2

Steps to reproduce the issue

  1. Restart OS
  2. Check the logs of Mosquitto broker for errors.
  3. Restart Mosquitto broker in order to bring it operate normally.

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

No response

Additional information

No response

rmsmirnov avatar Aug 17 '22 07:08 rmsmirnov

Confirm this error. Uninstalling and reinstalling addon doesn't help.

Home Assistant 2022.8.6 Supervisor 2022.08.3 Operating System 8.4 Frontend 20220802.0 - latest

What is the version of the add-on?

6.1.2

Steps to reproduce the issue

Restart OS Check the logs of Mosquitto broker for errors. Restart Mosquitto broker in order to bring it operate normally.

sereda-oleg avatar Aug 19 '22 17:08 sereda-oleg

Also confirm this error. Unfortunately seemed to coincide with moving my supervised virtualbox installation to a new NUC.

What type of installation are you running? Home Assistant Supervised (VirtualBox VM) Home Assistant 2022.8.6 Supervisor 2022.08.3 Operating System 8.4 Frontend 20220802.0 - latest

Which operating system are you running on? Arch linux host, VirtualBox

Which add-on are you reporting an issue with? Mosquitto broker

What is the version of the add-on? 6.1.2

Steps to reproduce the issue Restart OS Check the logs of Mosquitto broker for errors (same as those posted above for me) Restart Mosquitto broker in order to bring it operate normally.

sultanoswing avatar Aug 20 '22 11:08 sultanoswing

It seems that I’ve found a workaround. I toggled off "Start on boot" for Mosquitto broker add-on and kept "Watchdog" as toggled on for it. Also I implemented the same settings for all my installed add-ons which depends on Mosquitto broker (like Z2M etc). After OS reboot all errors in Mosquitto log have gone. I understand that this is a workaround and not a permanent solution))

I suppose that if "Start on boot" is toggled on then Mosquitto starts too early when HA has not been fully started. The problem is with bashio, Mosquitto can’t read any values from config..

rmsmirnov avatar Aug 20 '22 13:08 rmsmirnov

Workaround of disabling Mosquitto broker's 'Start on boot' worked for me too, thanks.

sultanoswing avatar Aug 20 '22 22:08 sultanoswing

Same problem here as well.. had to restart manually.. I hope this gets fixed soon..

jpconfessor avatar Aug 26 '22 03:08 jpconfessor

There a lot of users who was faced with this issue. Here is another example of workaround (automation) which I've seen in T-chats (indents need to be corrected):

alias: Add-ons start description: "" trigger: - platform: homeassistant event: start condition: [] action: - service: hassio.addon_restart data: addon: core_mosquitto - delay: hours: 0 minutes: 1 seconds: 0 milliseconds: 0 - service: hassio.addon_restart data: addon: 45df7312_zigbee2mqtt mode: single

rmsmirnov avatar Aug 26 '22 07:08 rmsmirnov

There a lot of users who was faced with this issue. Here is another example of workaround (automation) which I've seen in T-chats (indents need to be corrected):

alias: Add-ons start description: "" trigger: - platform: homeassistant event: start condition: [] action: - service: hassio.addon_restart data: addon: core_mosquitto - delay: hours: 0 minutes: 1 seconds: 0 milliseconds: 0 - service: hassio.addon_restart data: addon: 45df7312_zigbee2mqtt mode: single

The problem with this is that even if you restart HA after a configuration change this will be exxecuted. In my case the problem occurs only when the system is rebooted and not when just restarting HA. So I use a nodered flow that executes the same when nodered is started.

sheminasalam avatar Aug 29 '22 08:08 sheminasalam

Ah. So this looks like the same issue as I was tracking over here: https://github.com/Koenkk/zigbee2mqtt/issues/12801#issuecomment-1221641205

If so it should be fixed by 2022.08.5 of Supervisor. Let me know if you still see this issue after Supervisor is updated.

mdegat01 avatar Aug 29 '22 22:08 mdegat01

Yep - looks to have been resolved (at least for me) by 2022.08.5

MQTT add on now starts without error on host reboot, with both "Start on boot" and "Watchdog" selected.

sultanoswing avatar Aug 30 '22 00:08 sultanoswing

Home Assistant 2022.8.7 Supervisor 2022.08.5 Operating System 8.5 Frontend 20220802.0 - latest

MQTT addon starts with error on host reboot, with both "Start on boot" and "Watchdog" selected. :(

i`m use automation as a solution

sereda-oleg avatar Aug 30 '22 11:08 sereda-oleg

I have the latest Home Assistant OS (8.5) with full updates in (including MQTT broker 6.1.3) and the system does not come up correctly. I do not know if MQTT Broker is the culprit, as restarting it does not even help: I have to restart Home Assistant via developer tools after I have restarted MQTT broker.

If I do not do it in this order, MQTT runs, but my dashboard shows none of the MQTT-based entities. I suspect that there are problems with the credentials that cannot be read in early stages (I use HA users as advised in the documentation).

meyergru avatar Aug 30 '22 21:08 meyergru

Perhaps try, as suggested above, to disable "Start on boot" and enable "Watchdog". This workaround was working for me previously.

On Wed, 31 Aug 2022 at 09:02, Dr. Uwe Meyer-Gruhl @.***> wrote:

I have the latest Home Assistant OS (8.5) with full updates in (including MQTT broker 6.1.3) and the system does not come up correctly. I do not know if MQTT Broker is the culprit, as restarting it does not even help: I have to restart Home Assistant via developer tools after I have restarted MQTT broker.

If I do not do it in this order, MQTT runs, but my dashboard shows none of the MQTT-based entities. I suspect that there are problems with the credentials that cannot be read in early stages (I use HA users as advised in the documentation).

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/addons/issues/2618#issuecomment-1232164111, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFIZN4UL3JAPEX6YF24CBKDV3ZZE5ANCNFSM56YOFYLQ . You are receiving this because you commented.Message ID: @.***>

sultanoswing avatar Aug 30 '22 21:08 sultanoswing

No, that would not work. As I said: I need to restart MQTT in order to have the user credentials and THEN restart HA in order for it to get access to the broker.

I have found a simple workaround, though: I defined the users in MQTT, thus they are available without full availability of the base component. That has the advantage that no extraneous users are created which could be misused to access the web UI (because you can guess something like DVES_USER:DVES_PASS.

What is advised in the documentation cannot work at all, because there seems to be a circular dependency or at least one that is not met per default.

meyergru avatar Aug 30 '22 21:08 meyergru

Happened again today.. and I am in the most recent version

Home Assistant 2022.8.7
Supervisor 2022.08.5
Operating System 8.5
Frontend 20220802.0 - latest

Logs:

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
parse error: Expected string key before ':' at line 1, column 4
[15:47:29] ERROR: Unknown HTTP error occured
jq: error (at <stdin>:1): null (null) has no keys
[15:47:30] 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)
s6-rc: info: service legacy-services successfully started
[15:47:31] INFO: Starting NGINX for authentication handling...
[15:47:31] INFO: Starting mosquitto MQTT broker...
2022-08-31 15:47:31: Warning: Mosquitto should not be run as root/administrator.
parse error: Expected string key before ':' at line 1, column 4
[15:47:33] ERROR: Unknown HTTP error occured
[15:47:33] INFO: Successfully send discovery information to Home Assistant.
[15:47:33] INFO: Successfully send service information to the Supervisor.
2022-08-31 15:47:31: mosquitto version 2.0.11 starting
2022-08-31 15:47:31: Config loaded from /etc/mosquitto/mosquitto.conf.
2022-08-31 15:47:31: Loading plugin: /usr/share/mosquitto/go-auth.so
2022-08-31 15:47:31:  ├── Username/password checking enabled.
2022-08-31 15:47:31:  ├── TLS-PSK checking enabled.
2022-08-31 15:47:31:  └── Extended authentication not enabled.
2022-08-31 15:47:31: Opening ipv4 listen socket on port 1883.
2022-08-31 15:47:31: Opening ipv6 listen socket on port 1883.
2022-08-31 15:47:31: Opening websockets listen socket on port 1884.
2022-08-31 15:47:31: mosquitto version 2.0.11 running
2022-08-31 15:47:32: New connection from 127.0.0.1:49068 on port 1883.
2022-08-31 15:47:32: Client <unknown> closed its connection.
2022-08-31 15:47:40: New connection from 172.30.33.1:41072 on port 1883.
2022-08-31 15:47:40: New client connected from 172.30.33.1:41072 as mqttjs_6e7c1b1c (p2, c1, k60, u'addons').
2022-08-31 15:47:43: New connection from 192.168.4.4:54182 on port 1883.
2022-08-31 15:47:43: Client <unknown> disconnected, not authorised.

jpconfessor avatar Aug 31 '22 20:08 jpconfessor

Yeah, me too.

Reverted back to disabling "Start on boot'" as a workaround.

On Thu, Sep 1, 2022, 08:01 JP Confessor @.***> wrote:

Happened again today.. and I am in the most recent version

Home Assistant 2022.8.7

Supervisor 2022.08.5

Operating System 8.5

Frontend 20220802.0 - latest

Logs:

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

parse error: Expected string key before ':' at line 1, column 4

[15:47:29] ERROR: Unknown HTTP error occured

jq: error (at :1): null (null) has no keys

[15:47:30] 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)

s6-rc: info: service legacy-services successfully started

[15:47:31] INFO: Starting NGINX for authentication handling...

[15:47:31] INFO: Starting mosquitto MQTT broker...

2022-08-31 15:47:31: Warning: Mosquitto should not be run as root/administrator.

parse error: Expected string key before ':' at line 1, column 4

[15:47:33] ERROR: Unknown HTTP error occured

[15:47:33] INFO: Successfully send discovery information to Home Assistant.

[15:47:33] INFO: Successfully send service information to the Supervisor.

2022-08-31 15:47:31: mosquitto version 2.0.11 starting

2022-08-31 15:47:31: Config loaded from /etc/mosquitto/mosquitto.conf.

2022-08-31 15:47:31: Loading plugin: /usr/share/mosquitto/go-auth.so

2022-08-31 15:47:31: ├── Username/password checking enabled.

2022-08-31 15:47:31: ├── TLS-PSK checking enabled.

2022-08-31 15:47:31: └── Extended authentication not enabled.

2022-08-31 15:47:31: Opening ipv4 listen socket on port 1883.

2022-08-31 15:47:31: Opening ipv6 listen socket on port 1883.

2022-08-31 15:47:31: Opening websockets listen socket on port 1884.

2022-08-31 15:47:31: mosquitto version 2.0.11 running

2022-08-31 15:47:32: New connection from 127.0.0.1:49068 on port 1883.

2022-08-31 15:47:32: Client closed its connection.

2022-08-31 15:47:40: New connection from 172.30.33.1:41072 on port 1883.

2022-08-31 15:47:40: New client connected from 172.30.33.1:41072 as mqttjs_6e7c1b1c (p2, c1, k60, u'addons').

2022-08-31 15:47:43: New connection from 192.168.4.4:54182 on port 1883.

2022-08-31 15:47:43: Client disconnected, not authorised.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/addons/issues/2618#issuecomment-1233364600, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFIZN4ROWPDE6NU32VWV6FLV3622TANCNFSM56YOFYLQ . You are receiving this because you commented.Message ID: @.***>

sultanoswing avatar Aug 31 '22 20:08 sultanoswing

Leaving start on boot and disabling watchdog works. Watchdog is the issue. It was also an issue with other addons like mariadb, ring alarm, etc.

calisro avatar Sep 02 '22 20:09 calisro

same problem here. Disabling watchdog fixed that

andreaconfa avatar Sep 04 '22 09:09 andreaconfa

Same issue here. Shouldn't be too hard to fix this.

Home Assistant 2022.8.7 Supervisor 2022.08.6 Operating System 8.4 Frontend-versie: 20220802.0 - latest

GearlooseTechnology avatar Sep 11 '22 14:09 GearlooseTechnology

@mdegat01 can you please clarify why this is labeled "unsupported" ?

Experiencing this issue on a supported Supervised installation since core-2022.8.6.

Can anyone be assigned to take a closer look ? MQTT is quite a central component to many HA installations. Thanks.

System Information
version | core-2022.9.2
installation_type | Home Assistant Supervised

Home Assistant Supervisor
host_os | Debian GNU/Linux 11 (bullseye)
update_channel | stable
supervisor_version | supervisor-2022.08.6
healthy | true
supported | true
supervisor_api | ok
version_api | ok
installed_addons | AdGuard Home (4.7.3), Tailscale (0.7.0), Terminal & SSH (9.6.1), ESPHome (2022.8.3), Mosquitto broker (6.1.3), TasmoAdmin (0.20.0)

chumbazoid avatar Sep 13 '22 19:09 chumbazoid

I can also confirm that disabling the "watchdog" switch allows the broker to work properly on boot .. if that's enabled, I get a failure of the broker whenever HA is rebooted - I'm running Home Assistant Blue.

madAndroid avatar Sep 19 '22 05:09 madAndroid

As this ticket originates from an unsupported OS and is therefore apparently not monitored, opened #2680 for same issue but from a supported installation.

chumbazoid avatar Sep 24 '22 21:09 chumbazoid

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Oct 24 '22 22:10 github-actions[bot]

still occurs. Not sure why this was never looked at considering its a pretty large issue.

calisro avatar Oct 24 '22 22:10 calisro