Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
rmsmirnov opened this issue Aug 17, 2022 · 27 comments
Closed

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

rmsmirnov opened this issue Aug 17, 2022 · 27 comments

Comments

@rmsmirnov
Copy link

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

@sereda-oleg
Copy link

sereda-oleg commented Aug 19, 2022

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.

@sultanoswing
Copy link

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.

@rmsmirnov
Copy link
Author

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 rmsmirnov reopened this Aug 20, 2022
@sultanoswing
Copy link

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

@jpconfessor
Copy link

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

@rmsmirnov
Copy link
Author

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

@sheminasalam
Copy link

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.

@mdegat01
Copy link
Contributor

Ah. So this looks like the same issue as I was tracking over here:
Koenkk/zigbee2mqtt#12801 (comment)

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.

@sultanoswing
Copy link

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.

@sereda-oleg
Copy link

sereda-oleg commented Aug 30, 2022

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

@meyergru
Copy link

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).

@sultanoswing
Copy link

sultanoswing commented Aug 30, 2022 via email

@meyergru
Copy link

meyergru commented Aug 30, 2022

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.

@jpconfessor
Copy link

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.

@sultanoswing
Copy link

sultanoswing commented Aug 31, 2022 via email

@calisro
Copy link

calisro commented Sep 2, 2022

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.

@andreaconfa
Copy link

same problem here. Disabling watchdog fixed that

@GearlooseTechnology
Copy link

GearlooseTechnology commented Sep 11, 2022

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

@chumbazoid
Copy link

@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)

@madAndroid
Copy link

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.

@chumbazoid
Copy link

chumbazoid commented Sep 24, 2022

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

@github-actions
Copy link

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 github-actions bot added the stale label Oct 24, 2022
@calisro
Copy link

calisro commented Oct 24, 2022

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

@github-actions github-actions bot removed the stale label Oct 24, 2022
@github-actions
Copy link

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 github-actions bot added the stale label Nov 24, 2022
@calisro
Copy link

calisro commented Nov 24, 2022

Still an issue

@github-actions github-actions bot removed the stale label Nov 24, 2022
@github-actions
Copy link

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 github-actions bot added the stale label Dec 24, 2022
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Dec 31, 2022
@Alphaemef
Copy link

this occurs for me as well :/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests