MQTT issue

[mhmatttu]

I've recently noticed some strange behavior that I believe I have narrowed down to MQTT.

Each time I stop and then restart aqualinkD service, all pool circuits turn on (spa mode, heater, lights, waterfall, blower, etc). This does not happen if I have mosquitto mqtt service disabled.

I do have some integrations (i.e node-red, homebridge-aqualinkd plugin), but disabling these don't seem to change the behavior.

Any ideas on how to troubleshoot this? I have probably messed something up :)

Thanks.

[sfeakes]

Seen this a before, and it was another service re-posting messages. What else have you on MQTT? Remember that AqualinkD posts messages with retain flag, this means when someone subscribes to the topic, the MQTT server resends the last set of messages.

[mhmatttu]

sorry for the delay...unexpected travel this week :).

in my effort to troubleshoot, i have disabled all connections to my MQTT broker except the below:

• aqualinkd
• homebridge-aqualinkd plugin
• mqtt explorer

below is a screenshot of mqtt explorer showing only these 3 connections active.

when i stop aqualinkd service and restart, all circuits turn on. screenshot below

**disabling homebridge does not change the behavior. above screenshot with all circuits on was with homebridge service stopped.

[rstrouse]

That leaves Aqualinkd changing these values. If the homebridge-aqualinkd is disabled and simply restarting Aqualinkd emits 1s to the Aux_?? topic then it has to be Aqualinkd doing this. In fact, given how this is structured, njsPC does not write to that leaf it only reads from it. It will write to the Aux_??/set value which Aqualinkd subscribes to then sets the circuit accordingly. The expectation then is that other clients will read the Aux_?? leaf to set their internal values.

Out of curiosity if you open up the Aux_?? leaves what are the set values?

[mhmatttu]

Here is the full expanded view prior to stopping aqualinkd service

Below is after restarting aqualinkd service.

interesting as you noted, set values remain as "0", but all circuits are on.

[sfeakes]

Are the circuits physically on, or just showing on in MQTT?
The set topics are what clients should use to request AqualinkD to do something.
Can you post you mosquito config?
If the circuits are physically on then I don’t think the problem is MQTT, if they aren’t physically on then you should look at the MQTT history of a specific topic between stopping and starting AqualinkD. (Set mosquito into verbose mode)
If you put AqualinkD in debug mode, you will see every MQTT message it reads and posts.

[mhmatttu]

The circuits are physically on as well. If MQTT isn't the issue, are there any other logs that would be helpful?

Thanks

[sfeakes]

If you don’t see /set flick to 1 then 0 then I doubt it’s MQTT. Set aqualinkd to debug, it will tell you what & why it’s turned something on.

[mhmatttu]

I am not seeing /set flick to 1 then 0 in MQTT explorer. Attached is my log in debug mode. unfortunately i'm unable to make heads or tails of it.

aqualinkd.log

I appreciate the help!

[sfeakes]

You have something re-posting MQTT messages to AqualinkD as soon as it starts, and before AqualinkD has even connected to the control panel.

Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: topic aqualinkd/Pool_Heater/setpoint/set 31.67
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Pool_Heater/setpoint/set': value 31.67
---
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Pool_Heater/set': value 0.00
Jul-10-22 17:00:48 PM Info:    NetService:MQTT: received 'OFF' for 'Pool_Heater', turning 'OFF'
---
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: topic aqualinkd/Spa_Heater/setpoint/set 37.78
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Spa_Heater/setpoint/set': value 37.78
---
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Spa_Heater/set': value 0.00
Jul-10-22 17:00:48 PM Info:    NetService:MQTT: received 'OFF' for 'Spa_Heater', turning 'OFF'
---
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Filter_Pump/set': value 0.00
Jul-10-22 17:00:48 PM Info:    NetService:MQTT: received 'OFF' for 'Filter_Pump', turning 'OFF'
---
Jul-10-22 17:00:48 PM Debug:   NetService:MQTT: URI Request 'Spa_Mode/set': value 0.00
Jul-10-22 17:00:48 PM Info:    NetService:MQTT: received 'OFF' for 'Spa_Mode', turning 'OFF'

AqualinkD is queuing up these messages and then posts them once it connects to the control panel.

Jul-10-22 17:00:57 PM Notice:  AqualinkD: Starting communication with Control Panel
Jul-10-22 17:00:58 PM Debug:   AqualinkD: Actioning delayed request

This is your problem. I think you have some form of re-post history on your MQTT server.

[sfeakes]

Just thinking about this. What ever you are using to post message for AqualinkD to receive ie the xyz/set topic(s), you probably have the retain and/or QOS flags set when posting that message. That means the broker will ALWAYS resent the last message every time someone subscribes to the topic. Since AqualinkD is subscribing as it just starts, the broker is resending that message. If you are, you need to turn that off as you don’t want last state on the /set topic.

[mhmatttu]

Thank you. I appreciate this additional information. I will do some more digging to see what may be posting the messages. I thought I had everything disabled at this point.

[sfeakes]

@mhmatttu I'm sure you have disabled everything. My guess is its the MQTT broker/server that posting the message. ie. application post a messages to topic aqualinkd/xyz/set with retain and/or QOS flags then is turned off. The MQTT broker will post that same message to everyone the subscribes to aqualinkd/xyz/set for eternity (or unless a different message is posted to that topic).
Restart MQTT server might reset that, but you may also have to clear cache etc.

[mhmatttu]

Thanks again for all your help. I deleted the mosquitto.db file and changed the persistence setting to false in mosquitto.conf.

That seems to have resolved the issue. All interfaces are back to running and no issues for now.

Thanks!

[sfeakes]

Just be careful when you start using your automations again that they don’t set the retain flag against the /set topics.