tagyoureit / nodejs-poolController

An application to control pool equipment from various manufacturers.
GNU Affero General Public License v3.0
323 stars 94 forks source link

Phantom Circuits/Features #278

Closed johnny2678 closed 3 years ago

johnny2678 commented 3 years ago

Creating a new issue for tracking purposes.

I'm on v7 across the board now (njspc/dash/REM), but still seeing those phantom circuits I referenced below. If you need a fresh replay of the startup sequence or addl info, please let me know. Low priority.

==============================

logs attached.

not sure if it's related to this issue but the last pull cleared out my body sizes and my acid tank capacity so I had a bunch of errors at startup. Once I re-entered in setup pH dosing seemed to return to normal but now this is repeating in the console:

1|poolController  | failed on alarm: flow/@bind=data.alarms.flow.val;
1|poolController  | failed on chemController:alarm: flow desc/@bind=data.alarms.flow.desc; {"id":50,"saturationIndex":0.036,"flowDetected":true,"orp":{"probe":{"saltLevel":0,"level":732.9},"tank":{"capacity":0,"level":0,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":false,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":0,"doseTime":0,"lockout":false,"level":732.9,"mixTimeRemaining":0,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":1,"name":"monitoring","desc":"Monitoring"},"enabled":true,"dailyVolumeDosed":0,"pump":{"isDosing":false},"setpoint":720},"ph":{"probe":{"temperature":81,"level":7.598,"tempUnits":{"val":0,"name":"F","desc":"Fahrenheit"}},"tank":{"capacity":3.5,"level":3.0944623340757995,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":true,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":23,"doseTime":12,"lockout":false,"level":7.598,"mixTimeRemaining":148,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":2,"name":"mixing","desc":"Mixing"},"enabled":true,"dailyVolumeDosed":1481,"demand":95,"pump":{"isDosing":false},"setpoint":7.57,"volumeDosed":0},"flowSensor":{},"type":{"val":4,"name":"rem","desc":"REM Chem","ph":{"min":6.8,"max":8},"hasAddress":false},"alarms":{"comms":{"val":0,"name":"ok","desc":"Ok"},"flowSensorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"chlorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"bodyFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"orp":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pHTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pH":{"val":0,"name":"ok","desc":"Ok - No alarm"}},"status":{"val":0,"name":"ok","desc":"Ok"},"lastComm":1616934672626,"isBodyOn":true,"warnings":{"orpDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"chlorinatorCommError":{"val":0,"name":"ok","desc":"Ok - No Warning"},"pHLockout":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"pHDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"waterChemistry":{"val":0,"name":"ok","desc":"Ok - No Warning"}},"name":"REM ChemControl","isActive":true}
1|poolController  | failed on alarm: flow/@bind=data.alarms.flow.val;
1|poolController  | failed on chemController:alarm: flow desc/@bind=data.alarms.flow.desc; {"id":50,"saturationIndex":0.036,"flowDetected":true,"orp":{"probe":{"saltLevel":0,"level":732.9},"tank":{"capacity":0,"level":0,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":false,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":0,"doseTime":0,"lockout":false,"level":732.9,"mixTimeRemaining":0,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":1,"name":"monitoring","desc":"Monitoring"},"enabled":true,"dailyVolumeDosed":0,"pump":{"isDosing":false},"setpoint":720},"ph":{"probe":{"temperature":81,"level":7.598,"tempUnits":{"val":0,"name":"F","desc":"Fahrenheit"}},"tank":{"capacity":3.5,"level":3.0944623340757995,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":true,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":23,"doseTime":12,"lockout":false,"level":7.598,"mixTimeRemaining":147,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":2,"name":"mixing","desc":"Mixing"},"enabled":true,"dailyVolumeDosed":1481,"demand":95,"pump":{"isDosing":false},"setpoint":7.57,"volumeDosed":0},"flowSensor":{},"type":{"val":4,"name":"rem","desc":"REM Chem","ph":{"min":6.8,"max":8},"hasAddress":false},"alarms":{"comms":{"val":0,"name":"ok","desc":"Ok"},"flowSensorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"chlorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"bodyFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"orp":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pHTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pH":{"val":0,"name":"ok","desc":"Ok - No alarm"}},"status":{"val":0,"name":"ok","desc":"Ok"},"lastComm":1616934672626,"isBodyOn":true,"warnings":{"orpDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"chlorinatorCommError":{"val":0,"name":"ok","desc":"Ok - No Warning"},"pHLockout":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"pHDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"waterChemistry":{"val":0,"name":"ok","desc":"Ok - No Warning"}},"name":"REM ChemControl","isActive":true}
1|poolController  | failed on alarm: flow/@bind=data.alarms.flow.val;
1|poolController  | failed on chemController:alarm: flow desc/@bind=data.alarms.flow.desc; {"id":50,"saturationIndex":0.036,"flowDetected":true,"orp":{"probe":{"saltLevel":0,"level":732.9},"tank":{"capacity":0,"level":0,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":false,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":0,"doseTime":0,"lockout":false,"level":732.9,"mixTimeRemaining":0,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":1,"name":"monitoring","desc":"Monitoring"},"enabled":true,"dailyVolumeDosed":0,"pump":{"isDosing":false},"setpoint":720},"ph":{"probe":{"temperature":81,"level":7.598,"tempUnits":{"val":0,"name":"F","desc":"Fahrenheit"}},"tank":{"capacity":3.5,"level":3.0944623340757995,"units":{"val":1,"name":"gal","desc":"Gallons"},"alarmEmptyEnabled":true,"alarmEmptyLevel":20},"dosingTimeRemaining":0,"delayTimeRemaining":0,"dosingVolumeRemaining":0,"doseVolume":23,"doseTime":12,"lockout":false,"level":7.598,"mixTimeRemaining":146,"dailyLimitReached":false,"manualDosing":false,"flowDelay":false,"dosingStatus":{"val":2,"name":"mixing","desc":"Mixing"},"enabled":true,"dailyVolumeDosed":1481,"demand":95,"pump":{"isDosing":false},"setpoint":7.57,"volumeDosed":0},"flowSensor":{},"type":{"val":4,"name":"rem","desc":"REM Chem","ph":{"min":6.8,"max":8},"hasAddress":false},"alarms":{"comms":{"val":0,"name":"ok","desc":"Ok"},"flowSensorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"chlorFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHProbeFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"pHPumpFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"bodyFault":{"val":0,"name":"ok","desc":"Ok - No Faults"},"orpTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"orp":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pHTank":{"val":0,"name":"ok","desc":"Ok - No alarm"},"pH":{"val":0,"name":"ok","desc":"Ok - No alarm"}},"status":{"val":0,"name":"ok","desc":"Ok"},"lastComm":1616934672626,"isBodyOn":true,"warnings":{"orpDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"chlorinatorCommError":{"val":0,"name":"ok","desc":"Ok - No Warning"},"pHLockout":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"pHDailyLimitReached":{"val":0,"name":"ok","desc":"Ok - No limits reached"},"waterChemistry":{"val":0,"name":"ok","desc":"Ok - No Warning"}},"name":"REM ChemControl","isActive":true}
1|poolController  | failed on alarm: flow/@bind=data.alarms.flow.val;

Going to try one more restart to see if it clears... nope. still there.

replay (2).zip poolConfig.txt poolState.txt

edit: the good news is the connection to REM seems stable!

Originally posted by @johnny2678 in https://github.com/tagyoureit/nodejs-poolController/issues/275#issuecomment-808891194

rstrouse commented 3 years ago

Interesting that these features are only in the state and not in the config. Is there anything else sending state to njsPC?

johnny2678 commented 3 years ago

hmm, SWG dosing logic is updating state through NodeRed currently (until it gets built into REM).

And my solar priming logic is updating state by running the pump at a higher RPM when the solar turns on... maybe some other examples.

I do this by sending an MQTT payload like {"id":15,"isOn":"on"} to pool/easytouch2-4/state/feature/setState, which works great. ID 15 is a pool feature that sets the pump to a higher RPM.

All of this works - has the desired effect... should I be doing it differently?

image

rstrouse commented 3 years ago

These would be with one of the following ids, 14, 17, or 18.

tagyoureit commented 3 years ago

Do the phantom circuits ever turn on/off? :)

rstrouse commented 3 years ago

Ok so your version listed in the poolState.json is 6.5.2 not 7.0.0. The messages above were my first clue because we made those messages much more descriptive. You are still on the next repo.

Run the following command from the local directories for each of the projects. git checkout master git pull npm i

That also explains why the chemController settings were not preserved on reset.

johnny2678 commented 3 years ago

These would be with one of the following ids, 14, 17, or 18.

yea, that's what's odd - I don't think I have these IDs in my system - when I adjust pump speed, it's on of the following ids - 13,12,11,15,16,4

And I don't even have any logic that does this right now (long story - used to adjust pump speed based on solar temps to maximize heat transfer but never ported it over from my old python control script to my current node red control flow).

The only time I change pump speeds is when the solar kicks on (screenshot above using feature id 15) and 1 hour a day at a higher rpm (feature id 15) for the in floor cleaning, via a schedule.

Do the phantom circuits ever turn on/off? :)

I've never seen them on. I just went out to the pad and turned each on individually from dashPanel, but nothing happened on the pad ;)

Ok so your version listed in the poolState.json is 6.5.2 not 7.0.0. The messages above were my first clue because we made those messages much more descriptive. You are still on the next repo.

correct - the logs i posted were taken under 6.5.2. was just noting that the phantom features were still there after the upgrade to 7, which I am now on. I can take another replay if you like?

edit: grammar

rstrouse commented 3 years ago

Yes please there have been fixes to take care of the message output as well as shore up equipment items that are not part of the configuration.

johnny2678 commented 3 years ago

ok, let me know if this covers it

replay.zip

rstrouse commented 3 years ago

Pull njspc and lets see if those features disappear. You may need to F5 your dashPanel.

johnny2678 commented 3 years ago

yep, that did it! didn't even have to refresh dashPanel ;)

image

rstrouse commented 3 years ago

You know if you uncheck Show as Feature for Pool and Spa it will still allow you to click the large pool button or spa button but remove them from the list on the right. That is also true for AUX 4 if it isn't used for anything.

johnny2678 commented 3 years ago

yea, I've done that but something happens along the way where those settings get reset. Same thing happens with the body sizes (gallons) every once in a while. Prob something I'm doing but it's an easy fix so I don't look into it.

Another example just now... I was admiring how dashPanel looked without the phantom features when i noticed my pH was above threshold and not dosing, but no errors. Turns out somehow my acid tank capacity had been reset to 0.

again quick fix so I don't really give it much thought.

edit: another example, I only have one pump but somehow a 2nd pump entry keeps showing up that i have to delete. all of these are harmless and not worth your time. If I happen to isolate any one of them in the future, I can open another issue.

rstrouse commented 3 years ago

I think it happens on EasyTouch when the config is reloaded. We are slowly plugging all those holes. The reason it happens is because EasyTouch doesn't store this information anywhere.

johnny2678 commented 3 years ago

I think it happens on EasyTouch when the config is reloaded. We are slowly plugging all those holes. The reason it happens is because EasyTouch doesn't store this information anywhere.

I'm sure you're right, but easyTouch isn't aware of my acidTank level. Thinking that happened with the v7 upgrade and it just didn't carry over but 🤷‍♂️

rstrouse commented 3 years ago

I think our culprit is when you do a capture replay and the Capture Configuration Reload checkbox is selected. This process clears out the existing config and asks the OCP for whatever information it has. This was fine and consistent with the Touch series controllers until we started extending the data. We have been adding code to preserve this information during the reload.

johnny2678 commented 3 years ago

ahhh... I certainly did that when i grabbed the new replay. Never connected the two. Just randomly noticed features again that had been deleted.

no harm done - v7 is running pretty well. thx!

rstrouse commented 3 years ago

Yeah I am pretty impressed with REM Chem. You guys worked out all the warts before I got my controller finished. For shucks I have been keeping my pH at 7.4 and it really zeros in on it. What mix times are you using? My pool is big (36,000gal) and I have been dosing a max of 150mL with a mix of 30 minutes. It stays between 7.37 and 7.42 pretty consistently. TA is currently at 80 so I have it a bit lower and dropped it from 110 in about a week without the hassle of dosing and measuring.

emes commented 3 years ago

Sorry to jump on to this ticket, happy to create another...

I've been running on next, now on 7.0.0, so not a new issue.

My phantoms:

These I could care less about, just mentioning in case helpful.

I deleted data/poolConfig.json and data/poolState.json, to get a fresh config discovery.

Replay is here

emes commented 3 years ago

Hadn't seen last commit. Updated for https://github.com/tagyoureit/nodejs-poolController/commit/bded0b6e472f5b85ea3a7acdfaf7b92c72974c9b

Unused features 47-50 are gone. Thanks.

johnny2678 commented 3 years ago

What mix times are you using?

My pool is smaller, 15K - using a 10 sec dosing time (~34mL) and 5 min mixing time.

Looks like I'm averaging around little less than 1L of 1:1 water:20 baume MA / day

acid creeps up overnight when the pump is off and REM brings it right back down in 1-2 hours and maintains throughout the day.

Here's today's graph: image

rstrouse commented 3 years ago

@johnny2678 That looks really good. I have been pushing my TA down so I set it to 7.4 and have been trying to see if I can manipulate my TA down to 60-70. I plan on testing today. Then I think I will target 7.6 as my pH standard.

@emes I am looking at the extra valves, pumps, and spa circuit. I may need your help to make sure we have the macros appropriately set up. It appears there is code in there to declare macros as features and groups. Perhaps this has to do with limits in the number of features for IntelliTouch. Also, it appears you have 5 macros defined. I thought there was a limit of 3 macros in IntelliTouch.

johnny2678 commented 3 years ago

yea, I went down to 7.5 to see if that changed my weird inverse ORP/SWG relationship but it's still the same. I keep TA around 80 and the CSI measurement likes pH around 7.7 so that's where I'm at currently.

on the ORP/SWG relationship, best i can figure is the electrical current from running the SWG at 100% is actually driving down ORP until it has some time to mix. I've tried setting the dosing % to 80% which does dull the immediate ORP drop but it still goes down. A typical ORP/SWG monitor/dosing cycle goes like this:

  1. Running SWG at an output slightly below observable average output that meets the FCl demand (currently set at 15%)
  2. ORP falls below threshold (currently set at 640)
  3. SWG dosing kicks in (80% output, 20mins on, 40 mins off)
  4. immediate effect is it drive ORP further south, so it continues dosing/mixing for the rest of the day
  5. the next day, ORP is noticeably higher and FCL readings have jumped by 3-5ppm 🤷‍♂️

Just a guess - thinking the most direct way to do Cl dosing using ORP to monitor is with an SWG for everyday dosing and a Cl tank to "top-off" FCl supply based on ORP readings. You will get a more direct and immediate ORP response with Cl.

I have no plans to add a bleach tank anytime soon so I'll keep playing with the SWG dosing to get it dialed in.

rstrouse commented 3 years ago

My ORP does not match perfectly either. I have my CYA down ~25 right now to see how it operates that way. The one thing that I have noticed is that the ORP probe is much more stable when there is no air running into the flow cell. I get a burst of air that gets purged when the solar kicks on. They are not large bubbles but a bit like tiny fizz smaller than soda water. During this time my ORP plummets then stabilizes after many minutes. I have an ORP right now of 707.5 and when I tested FC last Sunday it was at 4 with no CC. I haven't seen it go over 710.

johnny2678 commented 3 years ago

I get a burst of air that gets purged when the solar kicks on.

hmm, do you have your flow cell lead tap after your solar return? Mine is before the solar return and I don't see any air in the cell when the pump is running. or do you have an o3 (ozone) device?

ORP stays pretty static throughout the day, with only a slight fall from the day start to finish. Most fluctuations are due to acid dosing and i only dose a little bit at a time so it's not that noticeable.

image

rstrouse commented 3 years ago

Yes I have the input just after the solar return which is why I get the bubbles. I have never had an ORP that high but then again I typically keep my FC ~3 and it always seems to hover around 700 or so except when the solar first kicks on then it drops to 695 or so. I need to get my Influx stuff running again as I keep cannibalizing all the Pis I have for other things. I should just get another one and leave my production system alone.

I kicked the solar on and this is what it did. In a little bit it will be back up to around 705 or so. Just looking for reasons why your ORP could be dropping. Perhaps this also has to do with flow because while it is purging I am sure the pressure fluctuates. image

johnny2678 commented 3 years ago

ahh yea, there's no correlation between my ORP dips and Solar AFAIK. Pretty sure it's directly related to running the SWG @ high output affecting the ORP probe. Regardless, I'll get it dialed in and then 2 inches of rain will throw the ALK and CYA off and I'll have to start all over ;)

edit: wording

rstrouse commented 3 years ago

Don't have a rain problem here. We won't see liquid sunshine until November.

rstrouse commented 3 years ago

@emes - Pull master njspc, dashPanel, and REM if you use it. I believe I took care of the valves, spa circuit, and pumps. I don't have this equipment anymore so its tough to make sure we hit all the nuances.

emes commented 3 years ago

Thanks for your help with this @rstrouse

Getting this on startup, with or without poolConfig and poolState on startup.

/app/controller/comms/messages/config/ValveMessage.ts:140
            if (!valve.isActive) {
                       ^
TypeError: Cannot read property 'isActive' of undefined
    at Function.process_ValveAssignment_IT (/app/controller/comms/messages/config/ValveMessage.ts:140:24)
    at Function.process (/app/controller/comms/messages/config/ValveMessage.ts:60:38)
    at Inbound.processBroadcast (/app/controller/comms/messages/Messages.ts:576:38)
    at Inbound.process (/app/controller/comms/messages/Messages.ts:740:22)
    at SendRecieveBuffer.processCompletedMessage (/app/controller/comms/Comms.ts:452:17)
    at SendRecieveBuffer.processInbound (/app/controller/comms/Comms.ts:490:48)
    at SendRecieveBuffer.processPackets (/app/controller/comms/Comms.ts:281:21)
    at Timeout._onTimeout (/app/controller/comms/Comms.ts:254:109)
    at listOnTimeout (internal/timers.js:554:17)
    at processTimers (internal/timers.js:497:7)
tagyoureit commented 3 years ago

Pull again. @rstrouse pushed up a change for this recently.

emes commented 3 years ago

That's with latest commit https://github.com/tagyoureit/nodejs-poolController/commit/a0c7c8a431cec94e5d9e2d4d85fba4e1dab3491a

rstrouse commented 3 years ago

Pull again. I found the condition where you would see it and a shared model OCP would not.

emes commented 3 years ago

Nice! That took care of all.

rstrouse commented 3 years ago

Awesome. Coding blind sometimes.