AqualinkD icon indicating copy to clipboard operation
AqualinkD copied to clipboard

AqualinkD turning VSP pump on/off repeatedly

Open smurry opened this issue 4 years ago • 37 comments

Hi, @sfeakes ,

Before describing my issue, I want to thank you for what has to have been an incredible amount of time spent on this project. And congrats on an awesome project.

I'm having some trouble with my installation and I'm not sure if you might have some insight. I have a Jandy RS-8 panel with a PDA (only), and a Jandy ePump (VSP). Over the weekend, I tried a first-time install of AqualinkD. I had never tried it before, so what I am describing is not a change from some previously-working condition.

Also, for the description below, the behavior I noticed was essentially the same in the version I deployed a few days ago (1.x) and the newest version I installed today (2.0).

As far as I can tell, whenever aqualinkD "wakes up" (e.g. when you open the web page to control the pool) aqualinkD shuts down my variable speed pump. To be clear, it does not turn off the relay to the pump on the panel, but it apparently sends some serial command to the pump that shuts it off. After some random period of time (some number of seconds, usually) it turns back on again, then off again, and so on...

One clue that may help is that whenever the pump cycles, a message on the web interface flashes "Aquapure off." As I understand it, this is related to the aquapure SWG, but I don't have a salt water pool. Also, in MQTT there are a lot of messages back and forth about the aquapure system.

This is a total guess on my part, but one possibility is that it is confusing my VSP for an aquapure system, and sending commands to what it thinks is the aquapure is actually going to my VSP and causing the on/off cycling. This is, as I said, a total guess.

When I try logging serial data, though, I don't see anything that appears to be odd, other than some "unknown" packets being sent to 0x78 (which I believe is my VSP):

Jandy To 0x78 of type Unknown | HEX: 0x10|0x02|0x78|0x44|0x00|0x80|0x25|0x73|0x10|0x03|

Jandy To 0x78 of type Unknown | HEX: 0x10|0x02|0x78|0x41|0xcb|0x10|0x03|

Here is an excerpt from the log file that covers one of these pump power-cycle events:

aqualinkd.log

and here is my configuration file:

aqualinkd.txt

As a final piece of information, if I wake up my PDA, everything returns to normal. If I shut down the aqualinkd service on the Rpi, everything works normally. It appears that aqualinkD is sending some messages out that cause this behaviour, but I can't track it down in the logs.

Very sorry for asking such a long an rambling question, but I hope you may have some insight.

smurry avatar Jun 02 '20 03:06 smurry

This is odd behavior, but I think you may have multiple things going on. First you should turn off SWG and Extended packet detection in AqualinkD config. Use the following To do that. read_all_devices = no read_pentair_packets = no force_SWG = no extended_device_id_programming = no

With those AqualinkD will not even try to read (let alone write) any information to anything other than the control panel using PDA protocol.

But, what I think is happening, is you have an issue on your RS485 wiring where when AqualinkD is running (or anything reading/writing) to the usb2rs485 adapter it’s blocking the pump rs485 messages. I’ve seen something very similar to this before, but I’ll need some time to dig it up. You should probably check your wiring. Maybe also use the raw reading of the USB port command listed in the wiki, see if that also messes with the pump. (With AqualinkD not running obviously).

One other thing, if your PDA you may well be best using a version prior to V2.0 for the moment. But one thing I’d like to know, can you change the VSP rpm from the PDA? If so, I’ll have to See if I can code that into V2 of AqualinkD.

sfeakes avatar Jun 02 '20 04:06 sfeakes

Fantastic suggestions.  I'll try them tomorrow and report back.  Thanks for tge quick reply.--StefanOn Jun 1, 2020 23:15, sfeakes [email protected] wrote:

This is odd behavior, but I think you may have multiple things going on. First you should turn off SWG and Extended packet detection in AqualinkD config. Use the following To do that.

read_all_devices = no

read_pentair_packets = no

force_SWG = no

extended_device_id_programming = no

With those AqualinkD will not even try to read (let alone write) any information to anything other than the control panel using PDA protocol.

But, what I think is happening, is you have an issue on your RS485 wiring where when AqualinkD is running (or anything reading/writing) to the usb2rs485 adapter it’s blocking the pump rs485 messages. I’ve seen something very similar to this before, but I’ll need some time to dig it up. You should probably check your wiring. Maybe also use the raw reading of the USB port command listed in the wiki, see if that also messes with the pump. (With AqualinkD not running obviously).

One other thing, if your PDA you may well be best using a version prior to V2.0 for the moment. But one thing I’d like to know, can you change the VSP rpm from the PDA? If so, I’ll have to See if I can code that into V2 of AqualinkD.

—You are receiving this because you authored the thread.Reply to this email directly, view it on GitHub, or unsubscribe.

smurry avatar Jun 02 '20 04:06 smurry

OK, I did a bit more troubleshooting today. The changes to the config file you recommended above didn't seem to make a difference. Today I tailed to log file and tried to capture what was happening immediately before the pump cycled from "on" to "off". Basically this occurred when AqualinkD woke up and entered programming mode.

Here is one section of the log that I captured:

Jun-02-20 17:44:48 PM Debug: PDA Menu Line 0 = Jun-02-20 17:44:48 PM Debug: PDA Menu Line 1 = AIR POOL Jun-02-20 17:44:48 PM Debug: PDA Menu Line 2 = Jun-02-20 17:44:48 PM Debug: PDA Menu Line 3 = Jun-02-20 17:44:48 PM Debug: PDA Menu Line 4 = POOL MODE ON Jun-02-20 17:44:48 PM Debug: PDA Menu Line 5 = POOL HEATER OFF Jun-02-20 17:44:48 PM Debug: PDA Menu Line 6 = SPA MODE OFF Jun-02-20 17:44:48 PM Debug: PDA Menu Line 7 = SPA HEATER OFF Jun-02-20 17:44:48 PM Debug: PDA Menu Line 8 = MENU Jun-02-20 17:44:48 PM Debug: PDA Menu Line 9 = EQUIPMENT ON/OFF Jun-02-20 17:44:48 PM Debug: PDA Menu highlighted line = 4 = POOL MODE ON Jun-02-20 17:44:48 PM Info: PDA Menu '2' Selectedline 'POOL MODE ON', Last line received 'AIR POOL' Jun-02-20 17:44:48 PM Debug: Kicking PDA thread 14,0x1fcf9e0 Jun-02-20 17:44:48 PM Debug: waitForPDAMessageHighlight last = 0x04 : index 4 : (3 of 10) Jun-02-20 17:44:48 PM Debug: RS Waiting to send cmd '0x06' (programming)

If I understand this correctly, the first part of the log is the RS panel sending the screen contents for the PDA to Aqualink (which it thinks is a PDA). I am curious about the next part, though, specifically this:

DA Menu '2' Selectedline 'POOL MODE ON', Last line received 'AIR POOL'

Does this simulate "selecting" (i.e. highlighing and pressing "select" on the PDA) the item "POOL MODE ON"? If so, on my PDA if you select POOL MODE ON it will toggle to POOL MODE OFF. Could this be causing the behavior?

Just a thought about this, not knowing exactly what this item in the log means. Thanks for any insight you might have.

Also, per your suggestion, I will be looking at my wiring. I have already replaced the wires once, so I tend to think that the wiring is not the problem, but I will try again to tighten the connections and maybe replace the wires again to see if this resolves the issue.

smurry avatar Jun 02 '20 19:06 smurry

The “select line” is the message the control panel sent Aqualinkd. It simply telling the display to highlight that line. Aqualink is not sending any commands.

When I said wiring, I was taking about the RS485 protocol. It’s very finicky, to correctly terminated and T’d vs Chain links. So just checking the wire might not be it, check how it’s wired against all other devices.

sfeakes avatar Jun 03 '20 01:06 sfeakes

Thanks for the clarification on the select line.

I have ordered a Jandy-branded RS-485 “expansion module” that I think might eliminate any potential wiring issues. It should be here in a couple of days. When I receive it, I’ll report back if it improves things.

Thanks again for the quick reply.

--Stefan

From: sfeakes [email protected] Sent: Tuesday, June 2, 2020 8:59 PM To: sfeakes/AqualinkD [email protected] Cc: smurry [email protected]; Author [email protected] Subject: Re: [sfeakes/AqualinkD] AqualinkD turning VSP pump on/off repeatedly (#106)

The “select line” is the message the control panel sent Aqualinkd. It simply telling the display to highlight that line. Aqualink is not sending any commands.

When I said wiring, I was taking about the RS485 protocol. It’s very finicky, to correctly terminated and T’d vs Chain links. So just checking the wire might not be it, check how it’s wired against all other devices.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/sfeakes/AqualinkD/issues/106#issuecomment-637907581 , or unsubscribe https://github.com/notifications/unsubscribe-auth/AAIGODLG7I5LAGFP4MJTPITRUWU5TANCNFSM4NQLGDLQ . https://github.com/notifications/beacon/AAIGODMSAJQON22YUZU3KDDRUWU5TA5CNFSM4NQLGDL2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEYC3E7I.gif

smurry avatar Jun 03 '20 02:06 smurry

That should eliminate any issues, I’ve read about them and I think one other person is using one. All the pool equipment is very non specific as to what’s terminated and what isn’t, so kinda trial end error on specific versions of equipment as to how you can wire it

On Jun 2, 2020, at 9:55 PM, smurry [email protected] wrote:

 Thanks for the clarification on the select line.

I have ordered a Jandy-branded RS-485 “expansion module” that I think might eliminate any potential wiring issues. It should be here in a couple of days. When I receive it, I’ll report back if it improves things.

Thanks again for the quick reply.

--Stefan

From: sfeakes [email protected] Sent: Tuesday, June 2, 2020 8:59 PM To: sfeakes/AqualinkD [email protected] Cc: smurry [email protected]; Author [email protected] Subject: Re: [sfeakes/AqualinkD] AqualinkD turning VSP pump on/off repeatedly (#106)

The “select line” is the message the control panel sent Aqualinkd. It simply telling the display to highlight that line. Aqualink is not sending any commands.

When I said wiring, I was taking about the RS485 protocol. It’s very finicky, to correctly terminated and T’d vs Chain links. So just checking the wire might not be it, check how it’s wired against all other devices.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/sfeakes/AqualinkD/issues/106#issuecomment-637907581 , or unsubscribe https://github.com/notifications/unsubscribe-auth/AAIGODLG7I5LAGFP4MJTPITRUWU5TANCNFSM4NQLGDLQ . https://github.com/notifications/beacon/AAIGODMSAJQON22YUZU3KDDRUWU5TA5CNFSM4NQLGDL2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEYC3E7I.gif

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

sfeakes avatar Jun 03 '20 03:06 sfeakes

I've been going down the path of trying to figure out where the BAD and UNKOWN packets were coming from. I installed a Jandy RS485 expansion board and ran shielded data cable to the house. No changes other than making thinks neater. I also tried an RPI 4 to see if processing/memory helped. Tried a poweedr USB hub, still had errors. Finally last week I ordered a DSD TECH SH-U11 USB to RS485 RS422 Converter with FTDI FT232 off Amazon to replace the converter linked to in the WIKI. All the extraneous errors disappeared. I'm now down to a couple bad packets that always happen on the quarter hour (referenced in another issue) that I'm trying to track down:

Jun 17 16:15:20 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0x0c|0x10|0x02|0x50|0x11|0x41|0xb4|0x10|0x03| Jun 17 16:15:20 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring

The only reason I care about those quarter hour errors is that they for some reason they shutoff my SWG. Right now I have a crontab that stops and starts aqualinkd at 20 past the hour so the SWG starts up again.

rgregrowe avatar Jun 17 '20 21:06 rgregrowe

This part of that message 0x10|0x02|0x50|0x11|0x41|0xb4|0x10|0x03| is the control panel telling the SWG to set to 65% (is 65% what your SWG is set to) ? 0x50 is SWG. 0x11 is set % command, 0x41 is 65%. Rest is checksum and header / tail.

But it's the preceding 0x10|0x02|0x0c that's bad. That looks like something it trying to send a message to a second control panel. 0x0c is not something I have decoded yet.

going back over your config, you should comment out these two lines extended_device_id=0x40 and extended_device_id_programming = yes, since PDA panel doesn't support either. (but that's not your problem)

Can you please describe every device you have wired up to the RS485 bus and how / where it's wired?
Also send the output of serial_logger run in debug mode started just before the problem occurs, something like. sudo ./release/serial_logger /dev/ttyUSB0 -rsrd -d -p 5000000000 Post the file /tmp/RS485raw.log and also the command output just the part that lists the JandyID's.

That will help me look at what's going on on your system. When running that, if the problem doesn't happen, then fire up aqualinkd, wait until 1 or 2 mins before the problem usually happens, go to the debug page and enable serial debugging, wait for the problem to occur, turn off serial debugging, download the file and post that. http://aqualinkd.ip:port/debug.html will get you to the debug page.

sfeakes avatar Jun 17 '20 21:06 sfeakes

I'll add an update on my problem. Not much to post really, at this point. I did properly wire my RS485 with the official Jandy expansion board. No change, the pump still shuts off over and over when connected to the RS-485 converter and Raspberry Pi.

Then, I ordered a different RS-485 converter. Same problem. Pump still shuts off repeatedly.

Here's what I know, though. First off, AqualinkD is communicating. I am able turn on/off the relays for the pump, lights, heater, etc. So, for example, I can command AqualinkD to turn on/off the lights. I hear the relay click and the lights of course go on and off. This is repeatable.

Since I have a VSP, two things seem to have to happen to get the pump running. One, the pump relay has to be turned on. This sends power to the pump. Then, some command(s) over RS-485 to tell the pump to turn on and at what speed (and maybe other things as well...not sure).

The pump relay is working correctly and repeatably with AqualinkD. That is, if I turn the pump "off" in AqualinkD, the pump relay clicks off. It appears that the on/off cycling of the pump is related to the RS-485 bus. It would seems that the necessary commands aren't going to the pump correctly.

However, in the process of trying out different RS-485 converters, I did discover a significant clue, which confirms that the behavior is not a problem caused by AqualinkD.

Assume that the pump and all electronics are running correctly, and the Raspberry Pi running AqualinkD is unplugged from the power outlet (i.e. turned off). Also assume that the RS-485 wires are not connected to the converter. From this condition, if I merely plug the RS-485 wires into the converter, but don't turn on the Raspberry Pi (and thus turn on the RS-485 converter), the pump almost immediately shuts off. Unplug the RS-485 connector and the pump turns back on.

If you have any insight into what could cause this I would love to know. My suspicion is that something must be screwing up the RS-485 bus, but I would expect in this case that the pump might not be able to be shut off (because the commands to shut off couldn't be sent over the compromised communication buss). However, the actual behavior is that the pump shuts down. It's almost like the pump needs a continuous string of "stay on" commands in order to stay running, which is very strange.

Anyway, I haven't reported back until now because I don't believe that the problem is related to AqualinkD, but I would greatly appreciate any insight that you might have.

smurry avatar Jun 17 '20 22:06 smurry

The pump (like SWG) needs constant communication with the control panel, if that is lost, both will go into a “local control state”, which means any local timers (If they exist) now become active. So yes it does need a constant “poll” From the control panel to keep running.

It sounds like you have a RS485 termination issue that when you plug the pi in, its drawing more power and therefor taking something else off the buss.

sfeakes avatar Jun 18 '20 00:06 sfeakes

That makes sense. I believe that the RS-485 is 120 ohm terminated. I expect that any of the RS-485 adapters would have this internal, but maybe not. I'll investigate and report back. Thanks for your quick reply.

smurry avatar Jun 18 '20 00:06 smurry

It does seem to depend on hardware version as so what is and isn’t terminated. Seems originally hardware was not terminated allowing people to daisychain devices. But that probably got confusing for pool installers so termination was added in hardware which also forced people to buy the RS485 expansion boards (more money for Jandy).

sfeakes avatar Jun 18 '20 01:06 sfeakes

This is interesting. I have a relatively new (~4 year old) system, which I guess from your description should have hardware termination. I did purchase the Jandy RS485 expansion board, but when I looked at it it appears to be nothing more than 4 screw-terminal connectors in parallel. I didn't see any terminating resistors/capacitors or any other components on the expansion board.

At this point, I'm considering either breaking out the logic analyzer to try to sniff the signals or just taking a guess at the correct terminating resistance and seeing if adding it helps.

All of this is a bit confusing because my cable length is really short (like 0.5m), so even if termination should be used in principle it seems like it shouldn't be necessary for this short cable length.

Good areas for further investigation, I guess...thanks again for your quick responses and helpful input.

smurry avatar Jun 18 '20 01:06 smurry

Another point is that the communication with the main controller seems to be fine (as I mentioned in my earlier post, I can turn on/off everything in the main controller). It's just communication with the pump (and possibly the heater as I haven't verified operation of it yet) which is a problem. If the termination were such a big issue, I'd expect it to be a problem in the communications with the main controller, too, not just with the pump.

smurry avatar Jun 18 '20 02:06 smurry

Remember that the control panel also powers the RS bus and even some circuitry of some devices. (Like the interface board of a SWG). On the wiring I assume you’ve read up in different types / kinds of RS485 wiring as some have mixed this up in the passed. But with that interface board I assume it’s hard to get it wrong. But Im Also surprised it seems so basic, nothing more than plugging multiple sets of wires in the panel form the sounds of it.

sfeakes avatar Jun 18 '20 02:06 sfeakes

Sorry, didn't get a chance to do a debug yet and it may be a day or two before I can. I'm currently wired with the USB /RS485 adapter coming off the One Touch inside control panel. There's about a foot of wire between the Control Panel and the RPI. As I said, I have a separate wire run off the Jandy RS 485 expansion block, but it didn't seem to make any difference. I can switch back if you want some testing. In my power center I have a Jandy Surge protector which prevents surges on the RS 485 bus and that connects to the a Jandy expansion board. (The expansion board has no terminators. It's a simple board that's way over priced if you bought it from a pool store!) I also have a Pentair VF Variable Flow pump and a Chlorine Translator attached to a PoolPilot Digital SWG (yes, currently set to 65%). I also have a Jandy SpaLink RS. Here's at least the log from today:

Jun 18 09:21:01 aqualinkd aqualinkd: Aqualink Daemon v2.0.1 Jun 18 09:21:01 aqualinkd aqualinkd: Config log_level = 7 Jun 18 09:21:01 aqualinkd aqualinkd: Config socket_port = 80 Jun 18 09:21:01 aqualinkd aqualinkd: Config serial_port = /dev/ttyUSB0 Jun 18 09:21:01 aqualinkd aqualinkd: Config web_directory = /var/www/aqualinkd/ Jun 18 09:21:01 aqualinkd aqualinkd: Config device_id = 0x0a Jun 18 09:21:01 aqualinkd aqualinkd: Config extra_device_id = 0x41 Jun 18 09:21:01 aqualinkd aqualinkd: Config extra_device_prog = YES Jun 18 09:21:01 aqualinkd aqualinkd: Config read_all_devices = YES Jun 18 09:21:01 aqualinkd aqualinkd: Config use_aux_labels = YES Jun 18 09:21:01 aqualinkd aqualinkd: Config override frz prot = NO Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_server = 192.168.1.6:1883 Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_dz_sub_topic = (null) Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_dz_pub_topic = (null) Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_aq_topic = aqualinkd Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_user = mqtt_hassio Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_passwd = XXXXXX Jun 18 09:21:01 aqualinkd aqualinkd: Config mqtt_ID = aqualinkd_b827eb18 Jun 18 09:21:01 aqualinkd aqualinkd: Config idx water temp = -999 Jun 18 09:21:01 aqualinkd aqualinkd: Config idx pool temp = -999 Jun 18 09:21:01 aqualinkd aqualinkd: Config idx spa temp = -999 Jun 18 09:21:01 aqualinkd aqualinkd: Config idx SWG Percent = 0 Jun 18 09:21:01 aqualinkd aqualinkd: Config idx SWG PPM = 0 Jun 18 09:21:01 aqualinkd aqualinkd: Config PDA Mode = NO Jun 18 09:21:01 aqualinkd aqualinkd: Config PDA Sleep Mode = NO Jun 18 09:21:01 aqualinkd aqualinkd: Config force SWG = YES Jun 18 09:21:01 aqualinkd aqualinkd: Config deamonize = YES Jun 18 09:21:01 aqualinkd aqualinkd: Config log_file = (null) Jun 18 09:21:01 aqualinkd aqualinkd: Config light_pgm_mode = 0.00 Jun 18 09:21:01 aqualinkd aqualinkd: Debug RS485 protocol = NO Jun 18 09:21:01 aqualinkd aqualinkd: Read Pentair Packets = YES Jun 18 09:21:01 aqualinkd aqualinkd: Display warnings in web = NO Jun 18 09:21:01 aqualinkd aqualinkd: Ignore SWG 0 msg count = 20 Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Filter_Pump = label Filter Pump | VSP ID 0x60 | PMP ID 1 | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Spa_Mode = label Spa Mode | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_1 = label Spa Blower | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_2 = label NONE | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_3 = label Patio Lights | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_4 = label Pool Light | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_5 = label NONE | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_6 = label NONE | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Aux_7 = label NONE | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Pool_Heater = label NONE | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Spa_Heater = label Spa Heater | Jun 18 09:21:01 aqualinkd aqualinkd: Config BTN Solar_Heater = label Solar Heater | Jun 18 09:21:01 aqualinkd aqualinkd: Starting web server on port 80 Jun 18 09:21:01 aqualinkd aqualinkd: Starting MQTT client to 192.168.1.6:1883 Jun 18 09:21:01 aqualinkd aqualinkd: Listening to Aqualink RS8 on serial port: /dev/ttyUSB0 Jun 18 09:21:01 aqualinkd aqualinkd: AqualinkD is using use ONETOUCH mode for VSP programming Jun 18 09:21:01 aqualinkd aqualinkd: AqualinkD is using use ONETOUCH mode for programming (where supported) Jun 18 09:21:11 aqualinkd aqualinkd: Control Panel E0260807 REV Q Jun 18 11:16:22 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0xef|0x10|0x02|0x20|0x02|0x00|0x00|0x00|0x00|0x00|0 x34|0x10|0x03| Jun 18 11:16:22 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring Jun 18 14:15:46 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0x72|0x10|0x02|0x20|0x02|0x00|0x00|0x00|0x00|0x00|0 x34|0x10|0x03| Jun 18 14:15:46 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring Jun 18 14:16:08 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0x82|0x10|0x02|0x20|0x02|0x00|0x00|0x00|0x00|0x00|0 x34|0x10|0x03| Jun 18 14:16:08 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring Jun 18 16:15:35 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0x3d|0x10|0x02|0x40|0x02|0x00|0x00|0x00|0x40|0x04|0 x98|0x10|0x03| Jun 18 16:15:35 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring Jun 18 16:16:08 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0x39|0x10|0x02|0x20|0x02|0x00|0x00|0x00|0x00|0x00|0 x34|0x10|0x03| Jun 18 16:16:08 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring

It's a clean install of Raspberry PI OS Lite from a week or so ago and all it runs is AqualinkD.

rgregrowe avatar Jun 19 '20 00:06 rgregrowe

The problem you are having is similar to an intermittent but ongoing problem I have had for the last year. I have a Pentair VSP, iAqualink, Chlorinator Pro/Goldline, and the RPI0 with AqualinkD. The iAqualink and RPI in a control box about 100ft away from the CP. I wire-nut the D+/D- wires to a pigtail that goes to the USB adapter, and another one to the iAqualink. The serial adapter is an Octagon Star FTDI that looks like it already has 120Ohm between D+/D- . I assume the iAqualink does as well.

This works fine about 98% of the the time. However, there are times it just decides to go haywire and I will get notifications that SWG is set to 0, and the SWG is bouncing while the RPM and Watts readings to all over the place in iAqualink.

Other times is when there is a Aqualink complete restart, about 50% of the time, the system will come back up and it seems like the iAqualink/AqualinkD is fighting or something. I end up powering everything down, shutting the AqualinkD service (or pulling power to the pi) , and powering back up. Then, waiting a few minutes and re-enabling AqualinkD. This will remain stable months, until for some random reason like this morning, everything seems to go out of sync again at about 2:14AM. The only unusual action around this time was I rebooted all my access points at about 2:05AM this morning which although is coincidental, I do not see how it can be related unless the iAqualink is is causing an issue when it is trying to re-connect. I still have the hourly bad packets errors as well, but just let that go as I was never able to find a solution . One thing that is interesting is that I have seen in the past, that if everything starts to go haywire and the iAqualink is reporting the strange SWG/Watt/RPM readings, I can shut down the AqualinkD service (pi is still powered), it it seems to stabilize on the iAqualink. I have not tested this recently but will when it happens again.

I sometimes wonder if how the AqualinkD talks to the CP eventually exposes some bug of some sort in the Jandy software on the CP or iAqualink.

niharmehta avatar Jun 28 '20 20:06 niharmehta

Sorry it took a while for these debug logs. First, I removed Aqualinkd from the system and reinstalled the latest 2.1.0. I let it run for a few days and it was pretty consistent that between 15 and 16 past the hour I got the "bad Jandy checksum". Sometimes, maybe once a day or once every other day, this would cause the SWG to go offline and start flashing an error on it's console. Stop and starting Aqualinkd would start it up again. The first RS485.log attached is with the AqualinkD daemon stopped and the following command run about 2 minutes prior to the quarter hour and going for about 2 minutes after. Since AqualinkD was stopped I have no idea if I got the bad checksum error or not. The second RS485.log is using the old debug method with config files changes of DEBUG_SERIAL and debug_RSProtocol_packets on. The debug.html page doesn't seem to work for me. Going to that page shows debugging enabled, but I can't stop it or post anything. I get this error in the log everytime I click on a button - "WEB: Old stanza, using old method to action" ?

The 2nd RS485 log does have the bad checksum error. Here's the startup info: Jul 2 17:15:29 aqualinkd aqualinkd: Aqualink Daemon v2.1.0 Jul 2 17:15:29 aqualinkd aqualinkd: Config log_level = 8 Jul 2 17:15:29 aqualinkd aqualinkd: Config device_id = 0x0a Jul 2 17:15:29 aqualinkd aqualinkd: Config extra_device_id = 0x41 Jul 2 17:15:29 aqualinkd aqualinkd: Config serial_port = /dev/ttyUSB0 Jul 2 17:15:29 aqualinkd aqualinkd: Config rs_panel_size = 8 Jul 2 17:15:29 aqualinkd aqualinkd: Config socket_port = 80 Jul 2 17:15:29 aqualinkd aqualinkd: Config web_directory = /var/www/aqualinkd/ Jul 2 17:15:29 aqualinkd aqualinkd: Config extra_device_prog = YES Jul 2 17:15:29 aqualinkd aqualinkd: Config read_all_devices = YES Jul 2 17:15:29 aqualinkd aqualinkd: Config use_aux_labels = YES Jul 2 17:15:29 aqualinkd aqualinkd: Config override frz prot = NO Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_server = 192.168.1.6:1883 Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_dz_sub_topic = (null) Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_dz_pub_topic = (null) Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_aq_topic = aqualinkd Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_user = mqtt_hassio Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_passwd = XXXXX Jul 2 17:15:29 aqualinkd aqualinkd: Config mqtt_ID = aqualinkd_b827eb18 Jul 2 17:15:29 aqualinkd aqualinkd: Config idx water temp = -999 Jul 2 17:15:29 aqualinkd aqualinkd: Config idx pool temp = -999 Jul 2 17:15:29 aqualinkd aqualinkd: Config idx spa temp = -999 Jul 2 17:15:29 aqualinkd aqualinkd: Config idx SWG Percent = 0 Jul 2 17:15:29 aqualinkd aqualinkd: Config idx SWG PPM = 0 Jul 2 17:15:29 aqualinkd aqualinkd: Config PDA Mode = NO Jul 2 17:15:29 aqualinkd aqualinkd: Config PDA Sleep Mode = NO Jul 2 17:15:29 aqualinkd aqualinkd: Config force SWG = YES Jul 2 17:15:29 aqualinkd aqualinkd: Config deamonize = YES Jul 2 17:15:29 aqualinkd aqualinkd: Config log_file = (null) Jul 2 17:15:29 aqualinkd aqualinkd: Config light_pgm_mode = 0.00 Jul 2 17:15:29 aqualinkd aqualinkd: Debug RS485 protocol = YES Jul 2 17:15:29 aqualinkd aqualinkd: Read Pentair Packets = YES Jul 2 17:15:29 aqualinkd aqualinkd: Display warnings in web = NO Jul 2 17:15:29 aqualinkd aqualinkd: Ignore SWG 0 msg count = 20 Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Filter_Pump = label Filter Pump | VSP ID 0x60 | PMP ID 1 | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Spa_Mode = label Spa Mode | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_1 = label Spa Blower | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_2 = label NONE | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_3 = label Patio Lights | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_4 = label Pool Light | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_5 = label NONE | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_6 = label NONE | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Aux_7 = label NONE | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Pool_Heater = label Pool Heater | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Spa_Heater = label Spa Heater | Jul 2 17:15:29 aqualinkd aqualinkd: Config BTN Solar_Heater = label Solar Heater | Jul 2 17:15:29 aqualinkd aqualinkd: Starting web server on port 80 Jul 2 17:15:29 aqualinkd aqualinkd: Starting MQTT client to 192.168.1.6:1883 Jul 2 17:15:29 aqualinkd aqualinkd: Listening to Aqualink RS8 on serial port: /dev/ttyUSB0 Jul 2 17:15:29 aqualinkd aqualinkd: AqualinkD is using use ONETOUCH mode for VSP programming Jul 2 17:15:29 aqualinkd aqualinkd: AqualinkD is using use ONETOUCH mode for programming (where supported) Jul 2 17:15:30 aqualinkd aqualinkd: Control Panel E0260807 REV Q Jul 2 17:15:32 aqualinkd aqualinkd: Programming: Get OneTouch setpoints Jul 2 17:16:09 aqualinkd aqualinkd: Programming: Get AUX labels Jul 2 17:16:14 aqualinkd aqualinkd: BAD PACKET Jandy Packet | HEX: 0x10|0x02|0xe0|0x10|0x02|0x0a|0x02|0x00|0x10|0x00|0x00|0x40|0x6e|0x10|0x03| Jul 2 17:16:14 aqualinkd aqualinkd: Serial read bad Jandy checksum, ignoring Jul 2 17:16:18 aqualinkd aqualinkd: AUX ID Aux_1 label set to 'Air Blower' Jul 2 17:16:20 aqualinkd aqualinkd: AUX ID Aux_2 has no control panel label using 'NONE' Jul 2 17:16:23 aqualinkd aqualinkd: AUX ID Aux_3 label set to 'Patio Light' Jul 2 17:16:23 aqualinkd aqualinkd: AUX ID Aux_4 label set to 'Pool Light' Jul 2 17:16:25 aqualinkd aqualinkd: AUX ID Aux_5 has no control panel label using 'NONE' Jul 2 17:16:27 aqualinkd aqualinkd: AUX ID Aux_6 has no control panel label using 'NONE' Jul 2 17:20:36 aqualinkd aqualinkd: Stopping!

FirstRS485raw.zip SecondRS485raw.zip

rgregrowe avatar Jul 02 '20 21:07 rgregrowe

I have a few ideas on what may be causing this. I've added some hidden functionality in the next release that may help, or at least catch the problem if my theory is correct. When I've packaged and posted the next release I'll post here on how to turn that functionality on.

sfeakes avatar Jul 11 '20 16:07 sfeakes

Great. Thank you.

rgregrowe avatar Jul 12 '20 11:07 rgregrowe

In the latest release V2.2.0. There is an undocumented config setting, serial_readahead_b4_write = yes. If you use that, I'd be interested to see if anything changes on this problem. If it does find something, I'll give some nice big errors in the UI and also log them. So keep an eye out for errors like SERIOUS ERROR on RS485, AqualinkD was too slow in replying to message! (please check OS for performance issues)

If you see that, post if up and see if we can figure out what's wrong. My theory on this is as follows. AqualinkD reads messages, acts on them, then replys to them. If something happens and it's too slow to reply, the panel will think it's replying to a different message, and makes everything go funky on you. This will catch that and log it. The problem is, to make the test also slows down the reply, so kind-a catch 22 going on, so I don't want to enable this by default.

sfeakes avatar Jul 18 '20 18:07 sfeakes

Would this message only be in Debug or in Info/Notice log settings ?

niharmehta avatar Jul 18 '20 20:07 niharmehta

It’s set as Error, (really should be notice or warning). I set to error so doesn’t matter what you set logging to, it will always be logged.

You will however need the “show errors in ui” (not exact syntax) setting in AqualinkD config if you want it shown in the web UI.

sfeakes avatar Jul 18 '20 23:07 sfeakes

Removed all AqualinkD files on my system and installed the latest release. I have an RS2/6 (dual equipment). In the new panel config, what should I put for panel_type ? I currently have "panel_type = RS-2/6 Combo" and it says on startup I have a RS8. I also tried setting the panel_type with the same results. Not sure if it's a problem though as everything appears OK on the web display.

I enabled the serial_readahead config entry. Nothing so far in the Web display, but every couple seconds I get the Error: RS Serial: SERIOUS ERROR on RS485, AqualinkD was too slow in replying to message! (please check OS for performance issues)

The system is a Raspberry PI4B with 2 GB of RAM with the latest Raspberry OS. Nothing else runs on it except AqualinkD.

Attached is a quick set of log files. First is the output from /var/log/aqualinkd.log. Second is debug from the Web interface and third is serial debug from the web interface. debug1.zip

rgregrowe avatar Jul 19 '20 01:07 rgregrowe

Here's the log with debug level and serial_readahead set in the config. It shows the BAD PACKET error I receive on the quarter hour if the pump is running (09:15:38). Sometimes the error will cause the SWG to go off line until AqualinkD is restarted and sometimes it won't. I've been running with a cron job that stops and restarts AqualinkD at 20 past the hour so I don't go a whole day without generating chlorine. No error messages were visible in the web interface when the error occurred, On a side note concerning my panel_type comment above, I had used the old serial logger. After compiling the new one I get:

Notice: RS Serial: Jandy Control Panel Model : RS-2/6 Dual Notice: RS Serial: Jandy Control Panel Version : REV Q Notice: RS Serial: Jandy ID's found Notice: RS Serial: ID 0x40 is in use <-- Onetouch device Notice: RS Serial: ID 0x20 is in use <-- Spa remote Notice: RS Serial: ID 0x50 is in use <-- Salt Water Generator (Aquarite mode) Notice: RS Serial: ID 0x60 is not used <-- can use for Aqualinkd (PDA mode only) Notice: RS Serial: ID 0x30 is not used <-- can use for Aqualinkd (Prefered Extended Device ID) Notice: RS Serial: ID 0x31 is not used <-- can use for Aqualinkd (Prefered Extended Device ID) Notice: RS Serial: ID 0x32 is not used <-- can use for Aqualinkd (Prefered Extended Device ID) Notice: RS Serial: ID 0x33 is not used <-- can use for Aqualinkd (Prefered Extended Device ID) Notice: RS Serial: ID 0x08 is not used <-- can use for Aqualinkd Notice: RS Serial: ID 0x09 is not used <-- can use for Aqualinkd Notice: RS Serial: ID 0x0a is not used <-- can use for Aqualinkd Notice: RS Serial: ID 0x0b is not used <-- can use for Aqualinkd Notice: RS Serial: ID 0x41 is not used <-- can use for Aqualinkd (Extended Device ID) Notice: RS Serial: ID 0x42 is not used <-- can use for Aqualinkd (Extended Device ID) Notice: RS Serial: ID 0x43 is not used <-- can use for Aqualinkd (Extended Device ID) Notice: RS Serial:

Notice: RS Serial: Pentair ID's found Notice: RS Serial: ID 0x10 is in use <-- Pentair Master (Probably Jandy RS Control Panel) Notice: RS Serial: ID 0x60 is in use <-- Pentair VSP Notice: RS Serial:

aqualinkd.log.zip

rgregrowe avatar Jul 19 '20 13:07 rgregrowe

The panel config RS-8 vs RS-2/6 is interesting. Can you post your /etc/aqualinkd.conf file?
In that file, also please check it's panel_type = RS-2/6 Dual, and you have no other panel_xxxx set.

Your last log shows

AqualinkD: Panel set to RS-6 Combo Pool/Spa

What you should see is

AqualinkD: Panel set to RS-6 Combo Pool/Spa Dual Equiptment

(Crap, I just noticed the typo in the code) Ultimately RS-6 Combo and RS-2/6 Dual use the exact same key codes, so everything should work, just have a 1 more aux button that won't do anything for you. But at some point I may be looking into how to address the other side of the Dual panels.

I'll post an update in a few hours, lets see what we can do about the "Too slow in replying" messages. But I'm interested if your SWG still goes funky? If this has fixed that issue, then I know what was happening and now just need to workout how to get AqualinkD to recover. BUT, you should be monitoring your system with TOP or something, keeping an eye on the CPU. Quick suggestion on things that would slow AqualinkD down that you would NOT see from CPU monitoring would be any network latency issues (like network mounted drives) / MQTT server latency, WiFi re-set or re-connect etc.

sfeakes avatar Jul 19 '20 14:07 sfeakes

After I posted the log I recompiled slog and reran it. I then set the config to "panel_type = RS-2/6 Dual" . I now see this on startup:

Jul-19-20 09:51:57 AM Notice: AqualinkD: Aqualink Daemon v2.2.0 Jul-19-20 09:51:57 AM Notice: AqualinkD: Panel set to RS-6 Combo Pool/Spa Dual Equiptment

Top shows the system pretty much idle except for AqualinkD. I've also watched it on the quarter hour and nothing is running that would cause the bad packet. I have a pretty beefy network within the house with a number of Raspberry's running various media and home automation tasks and multiple gig ethernet connected routers. The network shouldn't be an issue, but I can test with wired ethernet if you want? I only use the Sandisk Ultra SDHC cards in my Raspberry's and no network drives on the AqualinkD system. I also turned off MQTT in the config and that didn't affect the SERIOUS ERROR frequency. I was running AqualinkD on an PI 3B until 10 days ago when I switched to the 4B to see is system or network performance was a possible cause.

top - 11:20:52 up 10 days, 18:04, 2 users, load average: 0.02, 0.01, 0.00 Tasks: 115 total, 1 running, 114 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.2 us, 0.4 sy, 0.0 ni, 99.4 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st MiB Mem : 1939.4 total, 1524.2 free, 72.5 used, 342.8 buff/cache MiB Swap: 100.0 total, 100.0 free, 0.0 used. 1759.8 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
18952 root 20 0 12284 2008 1864 S 2.6 0.1 1:52.83 aqualinkd 19048 pi 20 0 10188 2908 2548 R 0.7 0.1 0:00.88 top
81 root -51 0 0 0 0 S 0.3 0.0 17:15.30 irq/36-mm+ 323 avahi 20 0 6036 3164 2724 S 0.3 0.2 27:50.63 avahi-dae+ 18957 root 20 0 0 0 0 I 0.3 0.0 0:04.57 kworker/u+ 19044 root 20 0 0 0 0 I 0.3 0.0 0:00.08 kworker/0+ 19049 root 20 0 0 0 0 I 0.3 0.0 0:00.06 kworker/u+ 1 root 20 0 34764 8148 6384 S 0.0 0.4 0:24.94 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.56 kthreadd
3 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_gp
4 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_par_gp 8 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 mm_percpu+ 9 root 20 0 0 0 0 S 0.0 0.0 0:03.94 ksoftirqd+

I've seen the SWG run a whole day without going offline on the quarter hour and watched it go off line 3-4 times during the pump run time. So far today, it hasn't gone offline. I'm getting the RS Serial: SERIOUS ERROR on RS485 sometimes every second and as long as 10 seconds before the next error. My config file is attached.

aqualinkd.conf.txt

rgregrowe avatar Jul 19 '20 15:07 rgregrowe

Thanks for this. I've uploaded v2.2.0a. Within this version there is another config value you can use to increase AqualinkD's poll speed.

network_poll_speed = 2

2 is default speed, 1 is fast, 0 is max. Try setting that to 1 and see if you see a reduction in RS Serial: SERIOUS ERROR, you can also try 0, but that will max out your CPU. (expect to see AqualinkD take 100% cpu if you use 0). These speeds may also see some other errors like serial resets, I've tried to overcome those, but if you see them, please also let me know.

I'll go over your latest logs, and once we've seen results from above, probably the next thing to do is to start measuring time for different actions within AqualinkD to see where the problems lie, I'll talk you enabeling that later.

sfeakes avatar Jul 19 '20 16:07 sfeakes

I've also just added a script to check a few things on the Pi, I can't check it on a Pi4, but if things haven't changed between 3 and 4 it should work. If you could download and run it, it'll check a few thinks on the Pi to see if there have been any system problems reported since last boot (like heat / power / voltage) that may cause a slowdown. You wouldn't pick these up with TOP or any process monitoring. Script is here https://github.com/sfeakes/AqualinkD/blob/master/extras/pi_health.sh

No need to get the whole of AqualinkD git, the following will do it for you.

wget https://raw.githubusercontent.com/sfeakes/AqualinkD/master/extras/pi_health.sh
chmod 777 ./pi_health.sh
sudo ./pi_health.sh

You should get an output like this.

CPU temperature: 60.7
CPU Voltage: 1.2000
Undervolt : OK
Undervolt history : OK
Throttled : OK
Throttled history : OK
Frequency Capped : OK
Frequency Capped history : OK

sfeakes avatar Jul 19 '20 17:07 sfeakes

Installed 2.2.0.a and added the network_poll_speed config entry starting with 1. May have slowed the errors some with an average of every 10 seconds, but then a burst of every 1 to 2 seconds. CPU usage went up to 14 -18%. Tried to set it to 0 and didn't notice any difference in error timing but CPU usage went up to 60-70%. Doesn't slow the system enough to make any difference in keyboard usage though. system is still snappy which is the advantage of the PI 4. PI health output is:

pi@aqualinkd:~ $ sudo ./pi_health.sh CPU temperature: 50.1 CPU Voltage: 0.8625 Undervolt : OK Undervolt history : OK Throttled : OK Throttled history : OK Frequency Capped : OK Frequency Capped history : OK

top - 13:36:11 up 10 days, 20:20, 2 users, load average: 0.83, 0.73, 0.49 Tasks: 114 total, 2 running, 112 sleeping, 0 stopped, 0 zombie %Cpu(s): 6.8 us, 9.2 sy, 0.0 ni, 84.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st MiB Mem : 1939.4 total, 1520.7 free, 73.1 used, 345.6 buff/cache MiB Swap: 100.0 total, 100.0 free, 0.0 used. 1759.2 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
19799 root 20 0 12284 2064 1920 R 64.1 0.1 10:14.04 aqualinkd 539 mosquit+ 20 0 8808 4784 4300 S 0.3 0.2 4:49.62 mosquitto 19810 root 20 0 0 0 0 I 0.3 0.0 0:00.40 kworker/u+ 1 root 20 0 34764 8152 6384 S 0.0 0.4 0:27.30 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.57 kthreadd
3 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_gp
4 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 rcu_par_gp 8 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 mm_percpu+ 9 root 20 0 0 0 0 S 0.0 0.0 0:04.00 ksoftirqd+ 10 root 20 0 0 0 0 I 0.0 0.0 1:07.88 rcu_sched 11 root 20 0 0 0 0 I 0.0 0.0 0:00.00 rcu_bh
12 root rt 0 0 0 0 S 0.0 0.0 0:00.20 migration+ 13 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/0
14 root 20 0 0 0 0 S 0.0 0.0 0:00.00 cpuhp/1

rgregrowe avatar Jul 19 '20 17:07 rgregrowe