sfeakes / AqualinkD

Daemon to control Jandy Aqualink RS pool equipment from any home automation hub (Alexa, Homekit & Siri, Home Assistant, smartthings, domoticz etc) or web browser.
Other
172 stars 47 forks source link

SWG settings bounce #95

Open niharmehta opened 5 years ago

niharmehta commented 5 years ago

This is similar to a recently closed issue #85 regarding SWG's bouncing between X% -> 0 -> X%. I have been having this issue since updating to 1.3.6 although I am not convinced this version is definitively the cause.
Symptom is my Aquarite SWG would stop generating every few minutes (low flow light starts). Then recover and quickly go back. Flow rate is NOT the issue as it was independent of speed. Looking at the AqD logs at the time I would see constant messages moving the SWG from 25% ->0 > 25%. I would also see that sometimes the iAqualink was also not coming back online, and when it did, I would see odd Watt/Speed numbers on the screen every so often. Shutting the AqualinkD process, everything would work fine and the SWG and iAqualink would run as expected. Starting the process and problems would start again.

I focused on the RS485 wiring and configuration and made some changes based on recommendations on the recently closed case. (Pump moved to Terminal block 1)

Terminal Block 2 has the pi and the iAqualink connected to it. First to the pi then daisy chains to the iAqualink. The outer wires go straight through to the iAqualink.

Terminal block 1 has both SWG and Pentair Pump connected directly to it. I also had to install a Chlorinator Translator (locked out) so its basically RS -> Translator -> Aquarite | -> Pentair I also completely changed out the wire to 22 gauge solid core security wire from the 24/28 gauge Cat5 i was using.

This did a lot to clean up a majority instances. However, I am still getting instances at seemingly random times where i am seeing messages of the SWG set to 0, then quickly going back to 25%. These times do NOT correlate with any changes in program schedules at those times.

Is it possible that any changes in code during the last couple of releases could be causing some increased errors ? I have started testing with 1.3.3d to see if i can find anything.

On a related note, which I have seen several times in the past releases as well, that sometimes stopping and restarting the AqualinkD process cases the RS to shut the Pump/System off. Not sure if you have seen this. It happened a couple of times today as I was swapping back and forth between 1.3.3d and 1.3.6 a few times.

sfeakes commented 5 years ago

There were some changes around 1.3.4 that make the SWG readings instant. Before it would wait for a few duplicate messages before actually notifying you of any change. Now it’s instant, I had to do this to overcome a bug of when people actually set it the percent to 0. So it could have been you always had the SWG reporting 25-0-25 but AqualinkD was ignoring it, as it only got one message at 0. Ill see if I can think of a way round this in the next release. As for pump turning off when you stop AqualinkD, no, I’ve never seen that before. Are you getting checksum errors in the log?

niharmehta commented 5 years ago

That is possible that this has been happening. I will keep testing with 1.3.3d for a couple of days to see if it changes anything. I do have very infrequent checksum errors. Maybe a couple of times per day. Last time was about 2 hours ago and see this in the logs Sep-30-19 20:19:04 PM Warning:Serial read bad Jandy checksum, ignoring Sep-30-19 20:19:04 PM Warning:Bad receive packet | Jandy | HEX: 0x10|0x02|0x69|0x10|0x02|0x50|0x11|0x19|0x8c|0x10|0x03| Sep-30-19 20:19:59 PM Warning:Serial read bad Jandy checksum, ignoring Sep-30-19 20:19:59 PM Warning:Bad receive packet | Jandy | HEX: 0x10|0x02|0x69|0x10|0x02|0x0a|0x02|0x40|0x14|0x00|0x00|0x00|0x72|0x10|0x03|

I am also tracking the MQTT entries at this time and did not see the SWG values change when the above errors were logged. With the previous problems that I have been seeing the MQTT values do change.

I do see values changed when the system changes modes (transition JVAs between modes) . I have eliminated this as the cause of the other times.

I will investigate if there is an environmental issue causing the error. The box that has the pi and serial adapter also has the iAqualink, and couple of strong static magnets i recently installed to hold a tablet. Possible there is some environmental interaction causing data errors ? The problems seem to manifest with the rest of the system when AqualinkD is running. Maybe a better quality USB converter with optical isolation and good power control or moving the pi and usb converter solves the problem.

niharmehta commented 5 years ago

Just now playing with the simulator on 1.3.3d (still testing that version) and when I just browse past the Aquapure menu items in System Setup without making changes, the following shows up in the logs. This is also reflected in the MQTT value changing as well and is repeatable:

Oct-01-19 13:33:12 PM Warning:WS: Send raw command to controller 0x18 Oct-01-19 13:33:13 PM Warning:WS: Send raw command to controller 0x18 Oct-01-19 13:33:13 PM Notice: Setting setpoint of Salt Water Generator to 0 Oct-01-19 13:33:13 PM Notice: Setting setpoint of Salt Water Generator to 0 Oct-01-19 13:33:13 PM Notice: SWG 0s already 0, not changing Oct-01-19 13:33:13 PM Notice: Setting setpoint of Salt Water Generator to 25 Oct-01-19 13:33:13 PM Notice: Setting setpoint of Salt Water Generator to 25 Oct-01-19 13:33:13 PM Notice: SWG 25s already 25, not changing Oct-01-19 13:33:15 PM Warning:WS: Send raw command to controller 0x18 Oct-01-19 13:33:16 PM Notice: Setting setpoint of Salt Water Generator to 0 Oct-01-19 13:33:16 PM Notice: Setting setpoint of Salt Water Generator to 0 Oct-01-19 13:33:16 PM Notice: SWG 0s already 0, not changing Oct-01-19 13:33:16 PM Notice: Setting setpoint of Salt Water Generator to 25 Oct-01-19 13:33:16 PM Notice: Setting setpoint of Salt Water Generator to 25 Oct-01-19 13:33:16 PM Notice: SWG 25s already 25, not changing Oct-01-19 13:33:17 PM Warning:WS: Send raw command to controller 0x18

This may just be a bug in the RS Firmware. Problem does not seem to occur when using the Setup Menus on the iAqualink. Since I do not have an RS Control Panel, I cannot tell if its only to simulator.

hollapm commented 4 years ago

@sfeakes I think the wiring fixed my issue. After I clean the salt cell and turn the system on it bounces from 75->0->75 and then after a number of hours starts to settle. I have disabled the swg_zero_ignore_count in the aqualinkd.conf file so think that there is some residual zero_count in one of the files which is causing it to bounce. Is there a way to verify that the swg_zero_ignore_count is reset to default?

sfeakes commented 4 years ago

swg_zero_ignore_count Is only held in memory, so if it’s been removed from the config file, it’s not being used. You can see if it’s a bug in AqualinkD or actual messages from the SWG by turning on serial logging or RS485 debugging. Then when you see it bounce to zero check the log, you’ll see the message the SWG sent.

niharmehta commented 4 years ago

Still happens with mine. I cleaned up much of the wiring and have about one bounce every couple of hours on top of the expected ones when there is a mode change on my pool . I have not played with the swg_zero_ignore count yet but will try today and capture some more logs.

@sfeakes , do you have any thoughts regarding my above observation that the RS simulator causing the SWG to bounce when browsing past the menus ? Happy to post a video of it happening if that helps.

sfeakes commented 4 years ago

You can ignore the messages your seeing in the simulator, it’s a bug I introduced in the last release when posting logs into web ui . You will see those exact messages in the logs, I just forgot to turn that off when using the simulator. It’s not the cause of the problem. But if you can post the logs that would be helpful.

hollapm commented 4 years ago

aqualinkd.log RS485.log Uploading logs. seems like its still changing SWG %

sfeakes commented 4 years ago

Thanks for the logs, Just a thought, can you try turning pentair packets off in the config, and see if the problem still exists. read_pentair_packets = no

niharmehta commented 4 years ago

I disabled read_pentair_packets earlier this evening and had a couple of instances of the bounces. Do you know if the the SWG settings bounce on a polarity flip? The timing does not align from what i can tell but I don't think that is reported. I will upload some logs in the next day or so.

sfeakes commented 4 years ago

I think I know what might be happening, but I'll need some raw RS485 packets from your system to prove it (and so I can ultimately fix it). I'm updating AqualinkD so I can capture the information, I'll post a new version later today.

sfeakes commented 4 years ago

I've just posted V1.3.7, if you can download that and test it out, would be much appreciated. I don't think I've fixed the SWG bounce, but I'd like to get the raw logs from your system. If you run from the command line with -rsrd option, a file /tmp/RS485.raw will be created, if you could post that I hope I can get to the bottom of the problem. So after running the install script, run with something like the below sudo ./release/aqualinkd -d -c /etc/aqualinkd.conf -v -rsrd Wait for the problem to happen a few times and them post /tmp/RS485.raw, you'll probably have to zip it up as it'll be large.

niharmehta commented 4 years ago

I will upgrade and test now. Should I re-enable Pentair ?

I have attached logs from last night. There was a bounce at ~04:14:31 . AqualinkD.zip

sfeakes commented 4 years ago

Yes, please re-enable Pentair. Good catch, forgot to mention raw log will only work with Pentair enabled.

niharmehta commented 4 years ago

I assume the RS485.log and RS485raw.log are redundant? Right now it is creating both since I did not disable the RS485 logging . Not a big deal, but not sure if you need both or not.

sfeakes commented 4 years ago

The RS485.log is post-processing, the RS485raw.log is pre-procesing. I can re-create the RS485.log if needed, so no need in posting that, it's the RS485raw.log that I need.

My theory is since the Pentair RS485 packets don't follow standard RS protocol, the Pentair pump doesn't understand the Jandy RS485 packets that do follow standard protocol. So the Pentair pump is posting packets in the middle of Jandy packets, (or visa-versa). And that's what's confusing either the the control panel or AqualinkD. If that's the case, I should be able to code around either, I just need the raw / pre-processed packets to see how it all looks.

BTW, if you have any other Pentair devices on the RS485 buss other than the pump, please turn them on, also play with RPM settings, the more Pentair packets that get in the log the better.

niharmehta commented 4 years ago

Caught one bounce at ~12:37:16. Logs attached. Sometimes the system is quiet, other times I will get a few bounces within a couple of hours. I am still logging for now and will post another log when I see more activity. AqualinkD131019-1.zip

hollapm commented 4 years ago

I just updated a few minutes ago. Will take a look out for bounces and post later.

niharmehta commented 4 years ago

Latest logs from last night. ~ Timestamps of bounces not related to expected automation mode changes: ~06:30:23 (during spillover time) ~06:40:29 (during spillover time) ~ 07:21:49

AqualinkD141019-1.zip

hollapm commented 4 years ago

Something that I noticed is that my SWG cell on light keeps bouncing (was doing this with 1.3.6 and again 1.3.7), cell on light is on, then turns off for half a second then back on. When I stopped aqualinkd, it stopped bouncing.

I stopped aqualinkd and it stopped bouncing. I then re-enabled aqualinkd to see if it would start acting up again.

Whats weird is my service 120 light came on after re-enabling aqualinkD (cell was cleaned last week).

I'm going to have it run without aqualinkd running for a few hours then re-enable it to see what happens.

hollapm commented 4 years ago

It still gave an error (121 this time) when I had aqualinkD disabled. I cleaned the cell again and turned on. error message is now gone so going to run and see what happens for a few hours.

sfeakes commented 4 years ago

@niharmehta I've spent a few hours going over your logs, this is what looks to be happening. (Wanted to write this down before I forget)

Control panel sets SWG 25%

Pump Tells control panel it's shutting down in 1 second. Control Panel sets SWG to 0% Control Panel requests Pump to take control. Control Panel sets Pump RPM Pump tell Control Panel is back running Control Panel set's SWG back to 25% So the bounce from 25% to 0% back to 25% is accurate to what's actually happening on the RS485 protocol. The control panel is just NOT notifying iAqualink or RS8 of this SWG change however. So it's just hiding what's going on to the user, which is why you've never seen it before. So, one way to overcome this is to simply use the RS8 messages for the SWG percentage, and not the RS485 packets. The config setting `read_all_devices = no` will stop reading any RS485 packets not designated to be read by an RS8 keypad, there for hiding the bounce from AqualinkD Another way would be to use the `swg_zero_ignore_count = 50` in AqualinkD's config, you're logs show about 25 messages a 0 before going back, so setting that to 50 would probably hide the bounce from you. Preferable, Figure out why your system is doing this with the pump. I'm looking at messages before and after the list I posted, to see if there is anything in their, like Pump bouncing between local & remote control or anything like that. A complete guess is you have a timer set locally on your pump that is overriding the Control Panel settings, and when that timer de-activates and control panel takes over is when you see this bounce.
niharmehta commented 4 years ago

That is really interesting. I wonder if this is a problem limited to Pentair pumps and potentially some sort of FW bug in the pump firmware (or integration with Jandy) that is normally hidden. It seems randomly odd times to have the pump decide to notify the RS it is shutting off. One point I am confused. I would have expected to see in my MQTT and logs monitoring that the RS control panel is sending 0% for 30s. I only see a brief message in the AqualinkD logs, and then an almost immediate bump back to 25%.

In normal operation mode, there does not seem to be any local control of the pump. It shows "Display Not Active". It does not necessarily mean that some older pre-automation programming is still in there that for some reason is ignoring the automation. I just disconnected the pump from the RS and cleared any old schedules from before the Aqualink was installed (set 1-4 to manual). Will report if any change.

I will think about the two options. Not sure I want to give up the read_all_devices . The swg_zero_ignore may be the best option if ultimately this causes issue.
I already have a hold down on my SWG 0% notifications for 5 minutes to handle any bounce or pump start/stops. So this is mostly an issue of unneeded state changes being tracked.

sfeakes commented 4 years ago

My 30 sec statement on the 0% part of the bounce, was an estimate at time by counting the number of messages. You have 228 total messages between the SWG 0 part of the bounce, each message is about 0.1 second apart, so 22.8 seconds. Crap, while typing that, I forgot I shouldn't use 228 messages, I should have used just the SWG messages of 28. So 2.8 seconds as a very rough guess. But that's going by time on how my system works, you're control panel is a lot newer & a different chipset, so maybe faster.

I think the swg_zero_ignore is the better option. I could also change read_all_devices to specific devices, so you could ignore SWG and keep the pump information.

BTW, you didn;t see this in some of the previous versions as I had code to completely ignore any "set SWG to 0" messages. That way you knew the SWG % when the pump was off. But some people want to actually set the SWG to 0, so I have to remove that code. I could also make that a config option, but you'd never be able to actually set the SWG to 0 if you used it.

Give me a few more days and I'll see if I can find the time to go over your other logs and every single pump messages, see if I can find out anything else.

niharmehta commented 4 years ago

Thanks!. Take your time. I have options around it if needed and this for now seems more cosmetic than anything causing problems. My hold downs have quieted down the notifications to almost nothing.
I think having the option to set the SWG to 0 is a useful in cases of adding salt, or shutting it off for the winter.

sfeakes commented 4 years ago

Something very interesting, right in the middle of the 0 bounce.

    0x10|0x02|0x00|0x01|0x3f|0x00|0x52|0x10|0x03|
*1) 0x10|0x02|0x50|0x11|0x00|0x73|0x10|0x03|
    0x10|0x02|0x00|0x16|0x25|0x00|0x00|0x00|0x4d|0x10|0x03|  
    0x10|0x02|0x80|0x00|0x92|0x10|0x03|
    0x10|0x02|0x0a|0x02|0x00|0x14|0x00|0x00|0x00|0x32|0x10|0x03|
*2) 0x10|0x02|0x0a|0x03|0x00|0x20|0x20|0x41|0x71|0x75|0x61|0x50|0x75|0x72|0x65|0x20|0x32|0x35|0x25|0x20|0x20|0x6f|0x10|0x03|
    0x10|0x02|0x60|0x00|0x72|0x10|0x03|
    0x10|0x02|0x33|0x30|0x75|0x10|0x03|0x00|0x00|
    0x10|0x02|0x00|0x01|0x00|0x00|0x13|0x10|0x03|
    0x10|0x02|0xa3|0x53|0x08|0x10|0x03|0x00|0x00|
    0x10|0x02|0x00|0x01|0x3f|0x00|0x52|0x10|0x03|
*3) 0x10|0x02|0x50|0x11|0x00|0x73|0x10|0x03|
    0x10|0x02|0x00|0x16|0x25|0x00|0x00|0x00|0x4d|0x10|0x03|

Message #1 and #3 are Control panel telling the SWG to set the % to zero, message #2 is Control Panel sending AqualinkD an ascii message that states 'AquaPure 25% '. So not only is the control panel not telling RS8 keypad of the bounce, it's actively 'hiding it' from the RS8 keypad. Makes me think the control panel actually knows it's bouncing to 0 for a reason, and not a reset pump it didn't actually know about. Means there is some logic as to why it's doing this, just need to figure out why now. Also explains you not seeing the 0 for the full duration ~2.8 seconds, as AqualinkD would do the following. < All readings to this point 25> Read the RS485 packet and record SWG to 0 Read the RS485 packet and record SWG to 0 -- repeat above -- Read the RS8 message and record SWG to 25 Read the RS485 packet and record SWG to 0 Read the RS485 packet and record SWG to 0 -- repeat above -- Read the RS485 packet and record SWG to 25 < All readings to this point 25>

So one bounce to 0, would actually show 2 in MQTT.

niharmehta commented 4 years ago

Wait.. so the CP tells SWG to go to 0% then back up without any external commands telling it so, but then directly tells the RS8 "Nothing new here.. setting is at 25% just like you wanted".
Very odd, so either it is reacting to some other external signal that you have not seen yet or there is a specific reason in the AqualinkRS (either planned or unplanned) doing this and then catching it and resetting.

I think I still have those hourly (at almost exactly 60m) BAD packets show up in the logs (currently at close to 17 minutes pas the hour. No idea what is causing it or where it is from. I wonder if this is something specific to iAqualink or the Pentair. I may pull the iAquallink off the bus to see if that changes anything.

sfeakes commented 4 years ago

Yup, that’s what’s happening. As for the bad packets, I just read yours manually so didn’t do any checksum checks, I’ll run your raw logs through my parser to check, but if it’s just Pentair checksum errors and not Jandy, that could be my code. If it’s every hour, maybe the CP is putting the pump into local run mode for 1 hour, then when it needs to reset / pass another run for 1 command that’s what’s showing up. I’ll spend some more time going over everything when I get the chance, but I haven’t figured all the Pentair data out just yet, there are still a lot of unknowns on that pump protocol to me, and no more information on the net.

niharmehta commented 4 years ago

Another set of logs.

This is really interesting. For the 2nd day in a row, I was alerted that the Aquapure Pool setting in iAqualink was set to 0% for more than 5 minutes. I thought the day before I may have accidentally set it manually while testing, but absolutely sure I did not this time as my monitoring showed that the switch occurred while I was nowhere near my computer at 06:31:20 this morning. I also see several hourly bounces of the SWG enabled going to 0 and back to 2.

At ~6:31:15 there is a couple of bounces and a flurry of programming messages following Oct-15-19 06:31:15 AM Debug: Ignoring SWG set to 0 due to packet packet count 0 <= 0 from control panel to SWG 0x00 0x73.

Looking at the logs, there is a bunch of entries of what looks like bounces as well as where it looks like an RS menu is being walked through and then at ~6:31:20 it drops to 0 again and stays there. The iAqualink shows the Aquapure Pool setting is at 0.

For a couple of minutes after, I see the messages as something is scanning the menus (not sure what 'something' is) : Oct-15-19 06:32:25 AM Debug: Find item in Menu: loop 25 of 25 looking for 'SET AQUAPURE' received message 'Jandy AquaLinkRS'

The other issue is there seems to be a ' enabled' bounce now every hour at about 15 minutes past the hour. I noticed this via the aqualinkd/SWG/enabled in MQTT 2:14:50 3:15:09 4:15:06 5:15:11 (as well as several others between 5:07 - 5:32) 6:15:12 7:15:12 8:15:08 9:14:43

What is interesting is that I think the actual SWG setting was still 0 at 7:15, 8:15, and 9:14. Just the enabled setting was bouncing.

AqualinkD-151019-1.zip

niharmehta commented 4 years ago

Well.. this is odd. After posting the last update, I restarted aqualinkD and 5 minutes later received a notice that my SWG was set to 0 for more than 5 minutes . (This time SPA since that mode was running).
Oct-15-19 10:29:46 AM Notice: Listening to Aqualink RS8 on serial port: /dev/ttyUSB0 Oct-15-19 10:29:46 AM Info: MQTT: Subscribing mqtt with id of: aqualinkd_b827eb7d Oct-15-19 10:29:46 AM Info: MQTT: Connection acknowledged Oct-15-19 10:29:46 AM Info: MQTT: Subscribing to 'aqualinkd/#' Oct-15-19 10:29:46 AM Info: MQTT: Subscription(s) acknowledged Oct-15-19 10:29:46 AM Info: MQTT: Published id=1: aqualinkd/Alive 1 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/Alive 1 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/Freeze_Protect 0 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/Freeze_Protect/setpoint 36.00 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/Freeze_Protect/enabled 1 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/Battery 1 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG 2 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG/fullstatus 0 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG/enabled 2 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG/PPM 3700 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG/Percent 0 Oct-15-19 10:29:46 AM Debug: MQTT: topic aqualinkd/SWG/Percent/set 0 Oct-15-19 10:29:46 AM Notice: Setting setpoint of Salt Water Generator to 0 Oct-15-19 10:29:46 AM Debug: MQTT: Ignore aqualinkd/SWG/Percent_f -17.78

I have attached logs again. For some reason, the RS485raw was not in the /tmp directory this time. The only automation I have setting the percentage is a slider bar in home assistant. Nobody is using it, but I will disable it to see if it changes anything.

AqualinkD151019-2.zip

niharmehta commented 4 years ago

I have pulled the iAqualink off the bus to see if that changes anything.

Can you clarify the SWG MQTT codes in the Wiki:

aqualinkd/SWG                       (0 off, 2 on and generating salt.) 
aqualinkd/SWG/enabled               (0 off, 2 on but not generating salt - SWG reported no-flow or equiv.)
qualinkd/SWG/fullstatus            (0 on, 1 no flow, 2 low salt, 4 high salt, 8 clean cell, 9 turning off, 16 high current, 32 low volts, 64 low temp, 128 check PCB, 255 off)

Specifically, I ams seeing SWG=2 (on and generating salt) but SWG/Enabled=2 (On but not generating salt ). My system always shows enabled=2 except for very, very short bounces which seem related to what we are troubleshooting. Not sure how SWG and SWG enabled can both be 2 and there is no no-flow condition. Maybe something that the Aquarite does not report through AL-5 or the Chlorinator Translator ?

sfeakes commented 4 years ago

Sorry, bad documentation, hope below clears it up.

aqualinkd/SWG/enabled               (0 off, 2 on but *might not* be generating salt - SWG reported no-flow or equiv.)
aqualinkd/SWG                      (0 off, 2 on and *IS* generating salt)

The enabled topic is really designed for HomeKit / thermostat integration in home automation hubs.

SWG/enabled (0,2) is supposed to mimic pool / spa heaters. IE, they can be enabled but not actually heating. IE water is up to temp, they will turn off, then turn back on when water get's back to temp. SWG maps to a thermostat in most home automation hubs very neatly, and most home automation hubs have both on/off and enabled/disabled, so /enabled topic was simply added to help in that integration. It can be ignored if not needed.

RS485raw.log will only be created if AqualinkD is started with a -rsrd command line parameter, there is no configuration option for this.

On the error. Do you have the Spa SWG default to 0? You can configure SWG % for both pool and spa mode, just checking you actually have it set AND you system can generate salt in spa mode.

niharmehta commented 4 years ago

Thanks for the explanation. That helps.
Hopefully the notes and log files I posted above will be helpful.

Regarding your question, yes it is set to 25% for both Pool and Spa. I actually don't have a Spa, but actually two pool sections that share 1 pump. (Upper and Lower sections) and the Spillover to circ between them . Just using SPA naming as that is what is built in to Jandy. It does generate in both modes normally .

sfeakes commented 4 years ago

Going over your logs, something told AqualinkD to set the SWG to 0 over a MQTT message.
AqualinkD received the set SWG to 0 as soon as it started up.

Oct-15-19 10:29:46 AM Debug:  MQTT: topic aqualinkd/SWG/Percent/set 0
Oct-15-19 10:29:46 AM Notice: Setting setpoint of Salt Water Generator to 0

<snip all the starting up crap, then AqualinkD preceded to action the request >

Oct-15-19 10:30:12 AM Notice: Setting setpoint of Salt Water Generator to 0
Oct-15-19 10:30:12 AM Debug:  programming SWG percent to 0

So that's why your SWG is at 0, something posted a message of 0 to the topic aqualinkd/SWG/Percent/set

niharmehta commented 4 years ago

I think I noticed that when I saw the startup logs. A couple of hours ago, I did disable the slider control in home assistant in case it is taking a cached value and putting a 'set' in there when it first connects. This may be the issue of the startup going to 0 sometimes at start. However, the other days in the morning, it did not occur during any restart of AqualinkD or the system.

sfeakes commented 4 years ago

You'll have to go through the MQTT logs on your server to see who posted that message. AqualinkD doesn't post to any topic that ends in /set, so it's definitely not a message AqualinkD posted and received back and acted on in some form or error. Some config on another system that posts to that topic is the cause of your problem. OR, you have retain option set on MQTT messages that get posted to /set from a system. In which case the MQTT server would have posted that to AqualinkD. In any case, it's a problem with the config of home assistant if that's the only other MQTT client you have.

niharmehta commented 4 years ago

Agreed regarding the set. The set is only happening from home assistant with the slider bar which is now removed. The MQTT set was indeed retained which has been cleared now.

I will keep an eye on the system with everything cleared out. I did get a bounce about 3 minutes ago, but will see if it continues with any set automations disabled.

niharmehta commented 4 years ago

Fixing the retained flag has fixed most of the bounces. (I have disabled any set automations for now just in case). . However had a couple of hits this morning. I do not have serial logs for these, however I have re-enabled raw serial logging and will post updates when it happens again.

sfeakes commented 4 years ago

I don't think the bounces are due to the MQTT issue you had. I think you were just dealing with two completely different problems what were both effecting the SWG going to 0.

niharmehta commented 4 years ago

I agree. It was confusing the issue. Self inflicted unfortunately. Thanks for catching that.

I have attached latest logs. There seems to be a pattern to the times. Symptom I am catching is the /SWG goes to 0 as well as SWG/enabled as well .

System started at ~14:48:52 ( I dont think I see a bounce until the 1st one below) 1st bounce at ~ 17:33:40 (Almost exactly 1:45) 2nd Bounce: ~ 17:36:24 (not sure about this one) 3rd Bounce(s): ~17:58:01 + 17:58:12 (3:10 after system start, 25 min after 1st) 4th Bounce(s): ~ 18:57:59 + 18:58:43 (1hr since previous bounce) 5th Bounce(s): ~ 19:58:17 + 19:58:50 (1hr since last) I have my system set to 25%. In theory, this version of the Aquarite has 3hr cycles. I think this means that it will run for 25% of a 3hr window. (45 minutes on, 135 minutes off). I also think polarity reversals happen at this schedule, or at just 3hr intervals.. I am not sure yet. The boundaries do not line up, but I am curious and will change my settings tonight to see if it changes anything I wonder if the CP could be sending some sort of diagnostic request or something.

May be worth dropping a note to the Chrlorinator Translator person. I bet he has this protocol down and may know what is happening.

AqualinkD161019-1.zip

niharmehta commented 4 years ago

In the spirit of never having too many log files to pour over. I changed my settings to 50% a few hours ago. There was no change in the cycles. I have attached updated log files . Couple things to point out Just upgraded to 1.3.8 . Let me know if more logs with that version will help.

Status Bounces: 20:58:35 SWG and SWG/enabled drops to 0 momentarily. 21:58:43 Repeat of above Pool enter enters spillover from 2200 - 2300 . No bounce reported. 23:58:29 - SWG and SWG/enabled drops to 0 momentarily

SWG Percentage bounce: 23:05:04 % dropped from 50 to 0, then bounced right back up. 00:08:07 Repeat of above.

AqualinkD171019-1.zip

scroundy commented 4 years ago

I get bounces multiple times a minute. I have my SWG set to 50%. It beeps and says 0% then back to 50%. Attached are my logs (or at least a version of them). This only happens when I am running aqualink. Please let me know if there are different logs you would need or other information. Thanks. aqualinkd.zip

niharmehta commented 4 years ago

You are running a pretty old version of AqualinkD. 1.3.3d fixed bugs with SWG as did 1.3.5 which had it owns bounce fixes introduced in 1.33. You may want to go to 1.3.7 or 1.3.8

scroundy commented 4 years ago

Not sure why that comes up. Line 835 shows I'm on 1.3.7.

niharmehta commented 4 years ago

Odd. Line 1 shows you are 1.3.3 . Maybe upgraded since then. I only looked at that top line. Logs may have appended.. Any chance you are running two instances ?

sfeakes commented 4 years ago

@scroundy As niharmehta said, that's a strange log. You have v1.3.3 running then that exists and v1.3.7 starts. I would normally assume that you just upgraded, but the configuration used for the two versions is very different. It also looks like 1.3.3 connected to the control panel, but 1.3.7 never did truly conect. it looks like there is a bigger problem than SWG from the logs, but there is not really enough to go on yet.

Can you give a few more details please. like is this your fist time installing / has this just started / did things work before / anything you did recently etc etc

scroundy commented 4 years ago

To be sure I've re-flashed my raspberry pi and installed 1.3.8a. So far no bouncing between settings. I'll keep my eye on it.

On Fri, Oct 18, 2019 at 6:42 AM sfeakes notifications@github.com wrote:

@scroundy https://github.com/scroundy As niharmehta said, that's a strange log. You have v1.3.3 running then that exists and v1.3.7 starts. I would normally assume that you just upgraded, but the configuration used for the two versions is very different. It also looks like 1.3.3 connected to the control panel, but 1.3.7 never did truly conect. it looks like there is a bigger problem than SWG from the logs, but there is not really enough to go on yet.

Can you give a few more details please. like is this your fist time installing / has this just started / did things work before / anything you did recently etc etc

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/sfeakes/AqualinkD/issues/95?email_source=notifications&email_token=ALJ3WQGBFO3IDVKCDBOLI7TQPG4MJA5CNFSM4I4C3CJ2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEBUQK7I#issuecomment-543753597, or unsubscribe https://github.com/notifications/unsubscribe-auth/ALJ3WQBGR3EXDXAJQWYR34TQPG4MJANCNFSM4I4C3CJQ .

scroundy commented 4 years ago

Lots of bouncing today. Every few seconds. To be clear it goes from Cell On at 50% to turning the cell off and showing 0%. This is happening at my aquapure panel and it beeps with each change. This only happens when aqualinkd is running. Here is my log file. aqualinkd.log

hollapm commented 4 years ago

I've updated to 1.3.9 and have stopped AqualinkD from running. I may allow it to run but when it is I am getting error 121 on the SWG. When I turn off AquaLinkD the error goes away. Under older codes I would also get errors more frequently (120 and 121) which also went away when I turned off, but since it was bouncing from 0 ->75 -> 0 I thought that may be causing the error. I'm wondering whats the best thing for me to do. Run AqualinkD with the error code or hold off with AuqalinkD?

sfeakes commented 4 years ago

@hollapm The problem you describe, does sound like wiring problem. It's happened to a few others, where running AqualinkD (or any RS485 device at that specific point) will introduce noise somehow onto the bus and effect connection between control panel and unit. Do you have the manual for your SWG to see what the error codes mean? You should probably look at those coes, AqualinkD doesn;t send any information to the SWG directly, it only monitors information sent between the control panel and SWG. If you set read_all_devices = no in aqualinkd config, then it won't even read the SWG information that's sent between the control panel and SWG and will simply use the status information that the control panel sends a keypad