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 require manual restart after update or full system reboot to work properly with bridge connection #3012

Closed
kompre opened this issue Apr 27, 2023 · 24 comments

Comments

@kompre
Copy link

kompre commented Apr 27, 2023

Describe the issue you are experiencing

Hello,

tonight the mosquitto broker auto updated and this morning few devices that relies on it weren't functioning because the signal was not getting trough. This alread happened in the last couple of month or so and I knew that the add on required a manual restart in order to work properly again.

The issue seems to be with the bridge configuration: I have two server on two different machines, where the main server is hosted by HA itself which is bridged to the secondary that actually handles the devices to run. The configuration for such bridge has worked fine for a long time (in share/mosquitto/mosquito.conf):

connection ave-bridge address 192.168.1.10:1883 topic /f8:xx:xx:xx/# out 0 topic /f8:xx:xx:xx/# in 0

When an add on update or full reboot happens the two server don't communicate anymore. I can see that mqtt message are sent on the HA side (listening to all topic in the mqtt device configuration page), but none are received at the secondary server, nor message generated from the secondary are received to the HA side.

A simple restart of the mosquitto broker solve the issue.

I'm able to reproduce the issue by doing a full reboot of HA.

Full reboot and auto update are rare events so I'm not sure when this issue has started, but it happend quite recently, at least a couple of month or so.

(not sure it there is anything useful in the supervisor log I've attached, I've seen no mention of mqtt or mosquitto broker)

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Mosquitto

What is the version of the add-on?

6.2.1

Steps to reproduce the issue

  1. Set up a bridge connection to another mqtt server not hosted by HA
  2. fully reboot the HA system
  3. try send message to other mqtt server (won't work)
  4. manually restart mosquitto broker: now it works again
    ...

System Health information

System Information

version core-2023.4.6
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.10.10
os_name Linux
os_version 6.1.24
arch x86_64
timezone Europe/Rome
config_dir /config
Home Assistant Community Store
GitHub API ok
GitHub Content ok
GitHub Web ok
GitHub API Calls Remaining 5000
Installed Version 1.31.0
Stage running
Available Repositories 1270
Downloaded Repositories 15
Home Assistant Cloud
logged_in false
can_reach_cert_server ok
can_reach_cloud_auth ok
can_reach_cloud ok
Home Assistant Supervisor
host_os Home Assistant OS 10.0
update_channel stable
supervisor_version supervisor-2023.04.1
agent_version 1.5.1
docker_version 23.0.3
disk_total 30.8 GB
disk_used 7.6 GB
healthy true
supported true
board ova
supervisor_api ok
version_api ok
installed_addons Samba share (10.0.1), Check Home Assistant configuration (3.11.0), Mosquitto broker (6.2.1), Duck DNS (1.15.0), Terminal & SSH (9.7.0), Home Assistant Google Drive Backup (0.110.3), Studio Code Server (5.5.7), File editor (5.6.0), Node-RED (14.1.5), Spotify Connect (0.12.3)
Dashboards
dashboards 1
resources 5
views 9
mode storage
Recorder
oldest_recorder_run 18 April 2023 at 14:37
current_recorder_run 27 April 2023 at 07:34
estimated_db_size 303.71 MiB
database_engine sqlite
database_version 3.38.5
Spotify
api_endpoint_reachable ok

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

23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/58a73313/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/01086c0a/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/35865f49/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/2686239e/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/d1992b86/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/d16fdec8/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/36d1c408/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:18 INFO (MainThread) [supervisor.api.middleware.security] /backups/c7386551/info access from cebe7a76_hassio_google_drive_backup
23-04-27 07:36:19 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:36:19 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:36:21 INFO (MainThread) [supervisor.misc.tasks] All core tasks are scheduled
23-04-27 07:36:21 INFO (MainThread) [supervisor.core] Supervisor is up and running
23-04-27 07:36:21 INFO (MainThread) [supervisor.host.info] Updating local host information
23-04-27 07:36:21 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state CoreState.RUNNING
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.DNS_SERVER_IPV6_ERROR/ContextType.DNS_SERVER
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.NO_CURRENT_BACKUP/ContextType.SYSTEM
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.PWNED/ContextType.ADDON
23-04-27 07:36:21 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 07:36:21 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:36:21 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.IPV4_CONNECTION_PROBLEM/ContextType.SYSTEM
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.MULTIPLE_DATA_DISKS/ContextType.SYSTEM
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.FREE_SPACE/ContextType.SYSTEM
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.TRUST/ContextType.SUPERVISOR
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.SECURITY/ContextType.CORE
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.checks.base] Run check for IssueType.DNS_SERVER_FAILED/ContextType.DNS_SERVER
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.check] System checks complete
23-04-27 07:36:21 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state CoreState.RUNNING
23-04-27 07:36:22 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
23-04-27 07:36:22 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state CoreState.RUNNING
23-04-27 07:36:22 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
23-04-27 07:36:22 INFO (MainThread) [supervisor.host.services] Updating service information
23-04-27 07:36:22 INFO (MainThread) [supervisor.host.network] Updating local network information
23-04-27 07:36:22 INFO (MainThread) [supervisor.host.sound] Updating PulseAudio information
23-04-27 07:36:22 INFO (MainThread) [supervisor.host.manager] Host information reload completed
23-04-27 07:36:40 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
23-04-27 07:36:40 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
23-04-27 07:36:40 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
23-04-27 07:40:15 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 07:40:15 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:40:15 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:45:21 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 07:45:21 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:45:21 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:50:27 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 07:50:27 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:50:27 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:52:28 INFO (SyncWorker_4) [supervisor.docker.interface] Stopping addon_core_mosquitto application
23-04-27 07:52:32 INFO (SyncWorker_4) [supervisor.docker.interface] Cleaning addon_core_mosquitto application
23-04-27 07:52:33 INFO (SyncWorker_5) [supervisor.docker.addon] Starting Docker add-on homeassistant/amd64-addon-mosquitto with version 6.2.1
23-04-27 07:52:36 ERROR (MainThread) [supervisor.services.modules.mqtt] There is already a MQTT service in use from core_mosquitto
23-04-27 07:52:43 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'mqtt'
23-04-27 07:52:43 INFO (MainThread) [supervisor.auth] Successful login for 'mqtt'
23-04-27 07:55:33 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 07:55:33 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:55:33 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 07:57:40 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
23-04-27 07:57:41 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_vscode
23-04-27 07:57:41 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
23-04-27 08:00:39 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 08:00:39 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:00:39 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:01:03 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Received message 257:None is not WSMsgType.TEXT
23-04-27 08:01:03 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API connection is closed
23-04-27 08:01:07 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
23-04-27 08:01:08 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_vscode
23-04-27 08:01:08 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
23-04-27 08:01:50 INFO (MainThread) [supervisor.api.middleware.security] /network/info access from core_ssh
23-04-27 08:01:50 INFO (MainThread) [supervisor.api.middleware.security] /network/info access from core_ssh
23-04-27 08:01:50 INFO (MainThread) [supervisor.api.middleware.security] /host/info access from core_ssh
23-04-27 08:01:50 INFO (MainThread) [supervisor.api.middleware.security] /core/info access from core_ssh
23-04-27 08:05:03 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
23-04-27 08:05:45 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 08:05:45 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:05:45 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:10:51 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 08:10:51 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:10:51 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:15:57 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 08:15:57 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:15:57 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:21:03 WARNING (MainThread) [supervisor.addons.options] Option 'interface' does not exist in the schema for Samba share (core_samba)
23-04-27 08:21:03 WARNING (MainThread) [supervisor.addons.options] Option 'dark_mode' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:21:03 WARNING (MainThread) [supervisor.addons.options] Option 'require_ssl' does not exist in the schema for Node-RED (a0d7b954_nodered)
23-04-27 08:22:04 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Received message 257:None is not WSMsgType.TEXT
23-04-27 08:22:04 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API connection is closed
23-04-27 08:22:08 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
23-04-27 08:22:09 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_vscode
23-04-27 08:22:09 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running

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

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
[07:52:34] INFO: Certificates found: SSL is available
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)
[07:52:35] INFO: Starting NGINX for authentication handling...
s6-rc: info: service legacy-services successfully started
[07:52:35] INFO: Starting mosquitto MQTT broker...
1682574755: Loading config file /share/mosquitto/mosquitto.conf
2023-04-27 07:52:35: Warning: Mosquitto should not be run as root/administrator.
[07:52:36] INFO: Successfully send discovery information to Home Assistant.
[07:52:36] INFO: Successfully send service information to the Supervisor.

Additional information

No response

@agners
Copy link
Member

agners commented Apr 27, 2023

tonight the mosquitto broker auto updated and this morning few devices that relies on it weren't functioning because the signal was not getting trough.

You are probably aware, but just to be sure: You can disable auto-update to prevent running into the issue at random.

When an add on update or full reboot happens the two server don't communicate anymore.

...

A simple restart of the mosquitto broker solve the issue.

That is weird. There is no real difference between a manual add-on restart and a restart after update.

@kompre
Copy link
Author

kompre commented Apr 29, 2023

That is weird. There is no real difference between a manual add-on restart and a restart after update.

Could it be related to order of operation? Maybe when the OS boot up something is not yet ready and the mosquitto add on don't initialize properly?

This morning I've updated the OS to the latest available (10.1) and sure, it happened again, mqtt device that are controlled by the secondary server didn't receive any command, nor HA could listen to their message. Restart the mosquitto add on and all is fine.

The HA OS runs on a qemu vm on a Linux machine

Should I look into set up an automation that will restart the add on, say, a minute after a finished boot?

@Makin-Things
Copy link

I am experiencing the same issue. I have a bridge configured and after a HA restart it doesn't work until I manually restart mosquitto.

@ForcedNative
Copy link

Exactly the same pattern here:

A Mosquitto add-on Reboot initiated by an update or running the add-on reboot service results in my bridge connection being lost. The log file shows that the bridge connection is retrieved from the configuration file, but the bridge device no longer pushes messages - used a matt sniffer to confirm.

A simple restart on the add-on page however solves the problem. No difference in log file outputs.

@kompre
Copy link
Author

kompre commented May 16, 2023

I'm on Home Assistant 2023.5.3 and the issue seems to be fixed. I rebooted HA and the bridge mqtt configuration works without reboot.

@Makin-Things
Copy link

This is not fixed. I am on 2023.5.4 and installed the OS update this morning and after that no updates from the configured bridge until I restarted the Mosquitto Broker addin.

@kompre
Copy link
Author

kompre commented May 31, 2023

This is not fixed. I am on 2023.5.4 and installed the OS update this morning and after that no updates from the configured bridge until I restarted the Mosquitto Broker addin.

Yep, you're right, I did the same update this morning and the mosquito bridge needed a manual restart

@Nikey
Copy link

Nikey commented Jun 7, 2023

have the same issue here

@gjdoornink
Copy link

This probably a problem with mosquitto 2.0.15.
See Issue #2634

@kzajac83
Copy link

I created #3072 and toady found that issue is due to timeout, reading eclipse/mosquitto#2634 is the same.

@Makin-Things
Copy link

@agners I am not sure if you are the right person to tag, but Mosquitto needs to be reverted to 2.0.14 until that project fixes this issue.

@xhemp
Copy link

xhemp commented Jul 24, 2023

Have the same, sometimes it doesn't load the conf file.
Edit: Still the same behaviour with 2023.8.1

@tschweitzer
Copy link

I am experiencing the same issue. Since I over night power down my nas where HA runs on, this is an issue for me every morning.

@SchraepferT
Copy link

Same issue here with Mosquitto Broker 6.2.1 and Home Assistant 2023.7.3.
Also, can anyone tell me if it is possible to always automatically load the values of the other broker when restarting the bridge? When restarting the bridge, I sometimes have discrepancies in the current switching states of devices that are only fixed when I press the switch once. The bridge always comes up with the last known values. But the current values are available at the linked broker.

@kompre
Copy link
Author

kompre commented Aug 7, 2023

I have developed a workaround until this issue get fixed: simply create an automation that will restart the add on when it detect that the mqtt bridge is not working.

For the detection of the unavailability of the mqtt bridge, I set up a binary sensor that simply check if has received any update from a mqtt device that usually publish its status multiple times a minute.

Here the automation config (delays are optional):

alias: Restart Mosquitto Broker
description: ""
trigger:
  - platform: homeassistant
    event: start
    enabled: false
  - platform: state
    entity_id:
      - binary_sensor.mqtt_bridge_is_online
    to: "off"
    for:
      hours: 0
      minutes: 1
      seconds: 0
condition: []
action:
  - delay:
      hours: 0
      minutes: 2
      seconds: 0
      milliseconds: 0
  - service: hassio.addon_restart
    data:
      addon: core_mosquitto
mode: single

the binary sensor is a template based on the value of the mqtt entity that publish often: in my case it is a thermostat, that when HA restart has a null value for the current_temperature attribute until it get updated by the mqtt topic.

template:
  - binary_sensor:
      - name: "mqtt bridge is online"
        state: "{{state_attr('climate.termostato_giorno', 'current_temperature') }}"
        delay_off: 00:01:00

@Nikey
Copy link

Nikey commented Aug 25, 2023

Rolled back my mosquitto addon to version 6.1.3 and it's working for weeks now without any problems...
It seems something broke in version 6.2.0

@agners
Copy link
Member

agners commented Sep 1, 2023

With #3187 Mosquitto is now updated to 2.0.17. Since @gjdoornink linked this to an issue in Mosquitto 2.0.15, which is resolved now, I'd expect this to be solved with the Add-on update 6.3.0. Can someone affected by this test and report?

Thanks!

@xhemp
Copy link

xhemp commented Sep 1, 2023

With #3187 Mosquitto is now updated to 2.0.17. Since @gjdoornink linked this to an issue in Mosquitto 2.0.15, which is resolved now, I'd expect this to be solved with the Add-on update 6.3.0. Can someone affected by this test and report?

Thanks!

Sure thing, just tested and it didn't work for me, I had to do a second restart , unfortunately.

@nijel
Copy link

nijel commented Sep 1, 2023

I had to restart after the update as well to make it work.

@swiergot
Copy link

swiergot commented Sep 1, 2023

It will not work right after the upgrade because the new version starts with an incorrect persistence file left by the old version, however after each consecutive restart it will be ok.

@kzajac83
Copy link

kzajac83 commented Sep 1, 2023

Today in my HA appear Mosquito broker update notofication to 6.3.0. I will update, made test and let you know later.

PS. Twice restart HA and for both causes working fine.

@Nikey
Copy link

Nikey commented Sep 14, 2023

I tested version 6.3.1 and it's also not working... Needed to restart the addon after HA restart to get the bridge working again.
Rolled back to version 6.1.3 until it's fixed...

@swiergot
Copy link

It is fixed for me just as I described in my previous comment. Maybe it's a slightly different scenario. What's your bridge configuration?

@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 14, 2023
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Oct 21, 2023
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