addons icon indicating copy to clipboard operation
addons copied to clipboard

Mosquitto broker connections "refused: not authorised" following reboot

Open chumbazoid opened this issue 2 years ago • 10 comments

Describe the issue you are experiencing

MQTT clients are unable to connect to Mosquitto broker following host OS reboot, when broker has been set to start on boot.

HA Core logs:

Logger: homeassistant.components.mqtt.client
Source: components/mqtt/client.py:685
Integration: MQTT (documentation, issues)
First occurred: 1:17:31 PM (5 occurrences)
Last logged: 1:17:47 PM

Disconnected from MQTT server localhost:1883 (5)
 
Logger: homeassistant.components.mqtt.client
Source: components/mqtt/client.py:566
Integration: MQTT (documentation, issues)
First occurred: 1:17:31 PM (5 occurrences)
Last logged: 1:17:47 PM
 
Unable to connect to the MQTT broker: Connection Refused: not authorised.

Issue may be worked around by either of the following, after which MQTT connections are restored:

  1. Manually restarting broker after HA has fully started
  2. Disabling broker start on boot and enabling watchdog

What type of installation are you running?

Home Assistant Supervised

Which operating system are you running on?

Debian

Which add-on are you reporting an issue with?

Mosquitto broker

What is the version of the add-on?

6.1.3

Steps to reproduce the issue

  1. Set Mosquitto broker to start on boot
  2. Reboot OS

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

Upon initial start of HA:

22-09-24 13:16:52 INFO (SyncWorker_2) [supervisor.docker.interface] Attaching to homeassistant/amd64-addon-mosquitto with version 6.1.3
22-09-24 13:16:52 WARNING (MainThread) [supervisor.addons.addon] Watchdog found addon Mosquitto broker is stopped, restarting...
22-09-24 13:16:52 INFO (SyncWorker_4) [supervisor.docker.interface] Cleaning addon_core_mosquitto application
22-09-24 13:16:58 ERROR (MainThread) [supervisor.api.middleware.security] Invalid token for access /addons/self/options/config
22-09-24 13:17:04 ERROR (MainThread) [supervisor.api.middleware.security] Invalid token for access /discovery
22-09-24 13:17:04 ERROR (MainThread) [supervisor.api.middleware.security] Invalid token for access /services/mqtt
22-09-24 13:17:31 ERROR (MainThread) [supervisor.api.middleware.security] Invalid token for access /auth
22-09-24 13:22:54 ERROR (MainThread) [supervisor.api.middleware.security] Invalid token for access /auth

Following manual restart of broker add-on:

22-09-24 13:24:34 INFO (SyncWorker_4) [supervisor.docker.interface] Stopping addon_core_mosquitto application
22-09-24 13:24:38 INFO (SyncWorker_4) [supervisor.docker.interface] Cleaning addon_core_mosquitto application
22-09-24 13:24:40 INFO (SyncWorker_5) [supervisor.docker.addon] Starting Docker add-on homeassistant/amd64-addon-mosquitto with version 6.1.3
22-09-24 13:24:44 INFO (MainThread) [supervisor.services.modules.mqtt] Set core_mosquitto as service provider for mqtt
22-09-24 13:25:39 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for '<MQTT username>'
22-09-24 13:25:40 INFO (MainThread) [supervisor.auth] Successful login for '<MQTT username>'

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

Upon initial auto-start of broker add-on:

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
[13:16:58] ERROR: Unknown HTTP error occured
jq: error (at <stdin>:1): null (null) has no keys
[13:17:00] 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
[13:17:02] INFO: Starting NGINX for authentication handling...
[13:17:03] INFO: Starting mosquitto MQTT broker...
2022-09-24 13:17:03: Warning: Mosquitto should not be run as root/administrator.
parse error: Expected string key before ':' at line 1, column 4
[13:17:04] ERROR: Unknown HTTP error occured
[13:17:04] INFO: Successfully send discovery information to Home Assistant.
[13:17:05] INFO: Successfully send service information to the Supervisor.
2022-09-24 13:17:03: mosquitto version 2.0.11 starting
2022-09-24 13:17:03: Config loaded from /etc/mosquitto/mosquitto.conf.
2022-09-24 13:17:03: Loading plugin: /usr/share/mosquitto/go-auth.so
2022-09-24 13:17:03:  ├── Username/password checking enabled.
2022-09-24 13:17:03:  ├── TLS-PSK checking enabled.
2022-09-24 13:17:03:  └── Extended authentication not enabled.
2022-09-24 13:17:03: Opening ipv4 listen socket on port 1883.
2022-09-24 13:17:03: Opening ipv6 listen socket on port 1883.
2022-09-24 13:17:03: Opening websockets listen socket on port 1884.
2022-09-24 13:17:03: mosquitto version 2.0.11 running
2022-09-24 13:17:03: New connection from 127.0.0.1:46108 on port 1883.
2022-09-24 13:17:03: Client <unknown> closed its connection.
2022-09-24 13:17:31: New connection from 172.30.32.1:53032 on port 1883.
2022-09-24 13:17:31: Client <unknown> disconnected, not authorised.
2022-09-24 13:17:32: New connection from 172.30.32.1:53044 on port 1883.
2022-09-24 13:17:32: Client <unknown> disconnected, not authorised.
2022-09-24 13:17:34: New connection from 172.30.32.1:34972 on port 1883.
2022-09-24 13:17:34: Client <unknown> disconnected, not authorised.
2022-09-24 13:17:38: New connection from 172.30.32.1:34980 on port 1883.
2022-09-24 13:17:38: Client <unknown> disconnected, not authorised.
("New connection / Client <unknown> Disconnected, not authorized" messages continue)

Following manual restart of broker add-on:

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:24:42] 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
[13:24:43] INFO: Starting NGINX for authentication handling...
[13:24:43] INFO: Starting mosquitto MQTT broker...
2022-09-24 13:24:44: Warning: Mosquitto should not be run as root/administrator.
[13:24:44] INFO: Successfully send discovery information to Home Assistant.
[13:24:45] INFO: Successfully send service information to the Supervisor.

Additional information

Experienced since approx. mid-August and core-2022.8.6.

Same issue as #2618, which was reported from an unsupported OS and is apparently therefore not monitored. Opening this new ticket to affirm issue is also experienced on a supported system.

chumbazoid avatar Sep 24 '22 21:09 chumbazoid

I encounter the same issue for several months and have to reinstall MQTT regulary to solve the issue for short time. Mosquitto broker version: 6.1.3 Home Assistant 2022.9.7 Supervisor 2022.09.1 Operating System 9.0 Frontend 20220907.2

Larosen avatar Sep 27 '22 16:09 Larosen

I've never experienced this until yesterday. I think I restarted HA for the latest patch.

A restart of just the broker fixed the issue for me.

Home Assistant 2022.9.7 Supervisor 2022.09.1 Operating System 9.0 Frontend-versie: 20220907.2 - latest

Mosquitto broker Current version: 6.1.3

wouterrutgers avatar Sep 28 '22 18:09 wouterrutgers

Home Assistant 2022.9.7 Supervisor 2022.09.1

Mosquitto broker Current version: 6.1.3

Broker regularly do not start correctly when HA restarts (and do not accept external connections), manually restarting broker fixes the problem temporary.

Aljutor avatar Oct 02 '22 12:10 Aljutor

Home Assistant 2022.9.7 Supervisor 2022.09.1

Mosquitto broker Current version: 6.1.3

Broker regularly do not start correctly when HA restarts (and do not accept external connections), manually restarting broker fixes the problem temporary.

Same System Versions and the same Issue. It started with Mosquitto broker 6.0 or even earlier.

Larosen avatar Oct 02 '22 14:10 Larosen

Mosquito broker 6.1.3 on HA 2022.9.1-7 same problem on restart. I have now disabled watchdog and will leave on start. I am also having problems with the broker randomly refusing connections after a few days from Z2MQTT, which are resolved if I restart the broker.

andyloree avatar Oct 02 '22 22:10 andyloree

Same issue with HassOS on host/hypervisor reboot won't load MQTT Broker properly (access denied from clients) and the addon must be manually restarted after system boots.

mmiller7 avatar Oct 03 '22 15:10 mmiller7

Home Assistant 2022.9.7 Supervisor 2022.09.1 Frontend 20220907.2 - latest

Mosquitto broker Current version: 6.1.3 Zigbee2MQTT Current version: 1.28.0-1

came here from https://github.com/Koenkk/zigbee2mqtt/issues/13001

dimkin-eu avatar Oct 03 '22 17:10 dimkin-eu

I have this issue for a couple of months now on different versions.

ProfessorFlut avatar Oct 04 '22 08:10 ProfessorFlut

:(

2022-10-05 08:21:22: Client disconnected, not authorised. 2022-10-05 08:23:22: New connection from 172.30.32.1:44716 on port 1883. error: received null username or password for unpwd check

Mosquitto broker Current version: 6.1.3

Zigbee2MQTT Current version: 1.28.0-1

4noxx avatar Oct 05 '22 06:10 4noxx

Same issue with HassOS on host/hypervisor reboot won't load MQTT Broker properly (access denied from clients) and the addon must be manually restarted after system boots.

Workaround (disable Watchdog) helps for me at the moment

gnoffer avatar Oct 06 '22 13:10 gnoffer

Same issue on my end.

Mosquito Broker won`t run under watchguard

Installed Version: 6.1.3

Home Assistant 2022.10.0 Supervisor 2022.09.1 Operating System 9.0 Frontend 20221005.0 - latest

tingles2233 avatar Oct 09 '22 15:10 tingles2233

Seems to be working now since latest Core update, enabled both "start on boot" and "watchdog" and no problem after reboot on both my installations: Home Assistant 2022.10.3 Supervisor 2022.10.0 Operating System 9.2 Frontend-version: 20221010.0 - latest

LaPe63 avatar Oct 13 '22 07:10 LaPe63

Thanks for heads up @LaPe63. Appears resolved to me now, as well. Can close issue if others are seeing similar.

chumbazoid avatar Oct 13 '22 19:10 chumbazoid

For what its worth, I recently had this exact problem. Mine most certainly wasnt a network problem, as I could access the tasmota gui, AND it was appearing in the Mosquitto Broker logs:

2023-06-24 15:41:31: New connection from 192.168.0.14:51966 on port 1883. 2023-06-24 15:41:31: Client taz_dishwasher1 disconnected, not authorised.

What fixed it?: Oddly, I manually typed in all the mqtt credentials many times (and rebooted device). Still no joy. What fixed it was copy-pasting the password from a field in HA to the tasmota gui. Worked. Can't explain why or how. I must have (somehow) entered in an erroneous character, OR my MAC is not playing ball...

Anyway, its all good now.

francismiles1 avatar Jun 24 '23 14:06 francismiles1