arthurdent75 / SimpleScheduler

An Home Assistant AddOn to schedule entities on/off on weekly base
194 stars 38 forks source link

Unable to connect to MQTT broker! error #86

Closed jdavidr17 closed 1 year ago

jdavidr17 commented 2 years ago

I know this was supposed to be addressed here: https://github.com/arthurdent75/SimpleScheduler/issues/68

however this has happened to me with the current version -- nothing changed with my MQTT server login info (running from HA). Switches are no longer available. Starting / stopping simplescheduler doesn't help.

d

Add-on: Simple Scheduler Simple timer on weekly base

Add-on version: 0.64 You are running the latest version of this add-on. System: Home Assistant OS 9.0 (aarch64 / odroid-n2) Home Assistant Core: 2022.9.7 Home Assistant Supervisor: 2022.09.1

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

[cont-init.d] 00-banner.sh: exited 0. [cont-init.d] 01-log-level.sh: executing... [cont-init.d] 01-log-level.sh: exited 0. [cont-init.d] simplescheduler.sh: executing... [09:45:12] INFO: Starting Scheduler [Mon, 03 Oct 2022 09:45:12 -0400] Starting scheduler... [Mon, 03 Oct 2022 09:45:12 -0400] Home Assistant TimeZone: America/New_York [Mon, 03 Oct 2022 09:45:12 -0400] Addon TimeZone: America/New_York [09:45:12] INFO: Starting MQTT Listener [cont-init.d] simplescheduler.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [Mon, 03 Oct 2022 09:45:12 -0400] Starting MQTT Listner... Error:Connection failed! (Error: 0x00 0x00) [Mon, 03 Oct 2022 09:45:12 -0400] Unable to connecto to MQTT broker! [09:45:12] INFO: Starting web server

arthurdent75 commented 2 years ago

It is not the same scenario as the issue you pointed out. This is an actual connection error. Please check in the addon configuration if the MQTT parameters are correct. Sometimes the MQTT parameters are lost when you update/reinstall the addon.

jdavidr17 commented 2 years ago

This is now happening on two different HA set-ups. Switch entities not appearing. SimpleScheduler not able to connect to MQTT broker. I've reinstalled and reconfigured MQTT and Simplescheduler with hard machine reboots in between. Double checked MQTT configurations. All Tasmota devices and ESPresence are able to find, connect, and interact with the MQTT broker just fine using the same settings. If there are any other logs you think might help to troubleshoot, let me know.

arthurdent75 commented 2 years ago

If there are any other logs you think might help to troubleshoot, let me know.

The only log which can give us one more clue is the MQTT broker log.

BTW which MQTT broker you are using?

jdavidr17 commented 2 years ago

Mosquitto broker Current version: 6.1.3 (Changelog)

Rating

Auth

Signed An Open Source MQTT broker. Visit the Mosquitto broker page for more details


MQTT broker log:

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 [22:53:14] 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) s6-rc: info: service legacy-services successfully started [22:53:14] INFO: Starting NGINX for authentication handling... [22:53:14] INFO: Starting mosquitto MQTT broker... 2022-10-05 22:53:14: Warning: Mosquitto should not be run as root/administrator. [22:53:15] INFO: Successfully send discovery information to Home Assistant. [22:53:15] INFO: Successfully send service information to the Supervisor. 2022-10-05 22:53:14: mosquitto version 2.0.11 starting 2022-10-05 22:53:14: Config loaded from /etc/mosquitto/mosquitto.conf. 2022-10-05 22:53:14: Loading plugin: /usr/share/mosquitto/go-auth.so 2022-10-05 22:53:14: ├── Username/password checking enabled. 2022-10-05 22:53:14: ├── TLS-PSK checking enabled. 2022-10-05 22:53:14: └── Extended authentication not enabled. 2022-10-05 22:53:14: Opening ipv4 listen socket on port 1883. 2022-10-05 22:53:14: Opening ipv6 listen socket on port 1883. 2022-10-05 22:53:14: Opening websockets listen socket on port 1884. 2022-10-05 22:53:14: Opening ipv4 listen socket on port 8883. 2022-10-05 22:53:14: Opening ipv6 listen socket on port 8883. 2022-10-05 22:53:14: Opening websockets listen socket on port 8884. 2022-10-05 22:53:14: mosquitto version 2.0.11 running 2022-10-05 22:53:15: New connection from 127.0.0.1:60880 on port 1883. 2022-10-05 22:53:15: Client closed its connection. 2022-10-05 22:53:16: New connection from 192.168.5.60:57941 on port 1883. 2022-10-05 22:53:16: New client connected from 192.168.5.60:57941 as espresense-home (p2, c1, k15, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.31:58527 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.31:58527 as DVES_4A68CF (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.186:53353 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.186:53353 as DVES_681C41 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.32:58566 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.32:58566 as DVES_A9F949 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.158:54454 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.158:54454 as DVES_68249D (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.244:62546 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.244:62546 as DVES_6811E4 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.243:51721 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.243:51721 as DVES_4A5970 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.139:61684 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.139:61684 as DVES_4A37C9 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.179:61298 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.179:61298 as DVES_682CAA (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.102:65264 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.102:65264 as DVES_63E792 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.242:49843 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.242:49843 as DVES_4DC8EF (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:18: New connection from 192.168.5.66:58398 on port 1883. 2022-10-05 22:53:18: New client connected from 192.168.5.66:58398 as DVES_858E03 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:19: New connection from 192.168.5.137:58099 on port 1883. 2022-10-05 22:53:19: New client connected from 192.168.5.137:58099 as DVES_A4957B (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:19: New connection from 192.168.5.47:56328 on port 1883. 2022-10-05 22:53:19: New client connected from 192.168.5.47:56328 as DVES_4DCAA9 (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:19: New connection from 192.168.5.221:51285 on port 1883. 2022-10-05 22:53:19: New client connected from 192.168.5.221:51285 as DVES_4A96DE (p2, c1, k30, u'theadventureloft'). 2022-10-05 22:53:22: New connection from 172.30.32.2:44654 on port 1883. 2022-10-05 22:53:22: Client closed its connection. 2022-10-05 22:53:22: New connection from 172.30.32.1:48771 on port 1883.

arthurdent75 commented 2 years ago

I've done some test and it seems that only Mosquitto inside the HA addon has this issue. Using an external MQTT broker everything works fine. I made some search and I found this: https://github.com/home-assistant/addons/blob/master/mosquitto/CHANGELOG.md#610

I need to run more test, and maybe try to change the php MQTT library...

arthurdent75 commented 2 years ago

I was not able to reproduce the issue. Can you please post here a screenshot of your MQTT settings in the addon configuration (with the password blurred, of course)?

jdavidr17 commented 2 years ago

Screen Shot 2022-10-10 at 3 12 22 PM

jdavidr17 commented 2 years ago

Screen Shot 2022-10-10 at 3 14 15 PM

jdavidr17 commented 2 years ago

Screen Shot 2022-10-10 at 3 15 53 PM

jdavidr17 commented 2 years ago

Screen Shot 2022-10-10 at 3 18 02 PM

arthurdent75 commented 2 years ago

🤔 Does the password contain any special character? With the previous version of my addon it worked fine?

jdavidr17 commented 2 years ago

"Does the password contain any special character?" -- no With the previous version of my addon it worked fine?" -- yes

jdavidr17 commented 2 years ago

Maybe this will help... it's the log with Debug "on":

Screen Shot 2022-10-12 at 3 14 37 AM

jdavidr17 commented 2 years ago

this is the same, from my second instance of HA located 2000 miles away:

Screen Shot 2022-10-12 at 3 41 57 AM

arthurdent75 commented 2 years ago

this is the same, from my second instance of HA located 2000 miles away:

This is a completely different error. In this instance MQTT succesfuly connect, because the lines with errors are executed after the connection to the MQTT broker. You can confirm that by looking in the Mosquitto log.

What is happening here is that the addon is unable to load the json files that contains the saved schedulers or there is a malformed json in the folder 🤔 You could try to remove all the json from the folder and try to add it one at the time until the error appear. BTW, if the problem persist, you should open another issue, because it is different from this one.

coolspot18 commented 1 year ago

I'm having the same issue - even with no schedules, Simple Scheduler won't connect to MQTT:

[16:48:16] INFO: Starting MQTT Listener [cont-init.d] simplescheduler.sh: exited 0. [cont-init.d] done. [services.d] starting services [Sat, 12 Nov 2022 16:48:16 -0500] Starting MQTT Listner... PHP Notice: Uninitialized string offset: 0 in /var/www/html/phpMQTT.php on line 244 Notice: Uninitialized string offset: 0 in /var/www/html/phpMQTT.php on line 244 PHP Notice: Uninitialized string offset: 0 in /var/www/html/phpMQTT.php on line 250 Notice: Uninitialized string offset: 0 in /var/www/html/phpMQTT.php on line 250 PHP Notice: Uninitialized string offset: 3 in /var/www/html/phpMQTT.php on line 251 Notice: Uninitialized string offset: 3 in /var/www/html/phpMQTT.php on line 251 Error:Connection failed! (Error: 0x00 0x00) [Sat, 12 Nov 2022 16:48:16 -0500] Unable to connecto to MQTT broker! [16:48:16] INFO: Starting web server [services.d] done.

arthurdent75 commented 1 year ago

Sadly the MQTT PHP library doesn't work well. I'm currently rewriting the whole addon from scratch in python. Just be patient for a while.

arthurdent75 commented 1 year ago

Solved in the new release. Currently under testing. It will be out soon.

arthurdent75 commented 1 year ago

Solved in 2.0