tagyoureit / nodejs-poolController

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

Unhandled rejection TypeError: Cannot set property 'light' of undefined, with two Intellibrites and logging on #99

Closed emes closed 6 years ago

emes commented 6 years ago

Expected behavior and actual behavior

When logIntellibrite is on, I'm getting the following error:

Unhandled rejection TypeError: Cannot set property 'light' of undefined

and thereafter everything goes to hell :-) (all packetWrites fail)

What is actually happening (screenshots are helpful)

The actual exception:

Unhandled rejection TypeError: Cannot set property 'light' of undefined
    at Object.assignControllerLightGroup (/home/ms/nodejs-poolController/src/lib/equipment/circuit.js:774:61)
    at Object.process (/home/ms/nodejs-poolController/src/lib/comms/inbound/controller/39.js:34:27)
    at Object.processControllerPacket (/home/ms/nodejs-poolController/src/lib/comms/inbound/process-controller.js:115:45)
    at decode (/home/ms/nodejs-poolController/src/lib/comms/inbound/decode-helper.js:263:51)
    at Object.processChecksum (/home/ms/nodejs-poolController/src/lib/comms/inbound/decode-helper.js:301:13)
    at Object.iterateOverArrayOfArrays (/home/ms/nodejs-poolController/src/lib/comms/inbound/receive-buffer.js:117:44)
    at Object.push (/home/ms/nodejs-poolController/src/lib/comms/inbound/packet-buffer.js:36:37)
    at SerialPort.<anonymous> (/home/ms/nodejs-poolController/src/lib/comms/sp-helper.js:78:44)
    at emitNone (events.js:106:13)
    at SerialPort.emit (events.js:208:7)
    at emitReadable_ (_stream_readable.js:513:10)
    at emitReadable (_stream_readable.js:507:7)
    at addChunk (_stream_readable.js:274:7)
    at readableAddChunk (_stream_readable.js:250:11)
    at SerialPort.Readable.push (_stream_readable.js:208:10)
    at binding.read.then (/home/ms/nodejs-poolController/node_modules/serialport/lib/serialport.js:374:10)

Probably related, even without logIntellibrite, I see the following error in the javascript console when using the bootstrap UI.

Uncaught TypeError: Cannot read property 'colorSetStr' of undefined
    at Object.<anonymous> (main.js:791)
    at Function.each (jquery.js:360)
    at insertLightEdit (main.js:627)
    at r.<anonymous> (main.js:1051)
    at r.emit (index.js:83)
    at r.onevent (index.js:83)
    at r.onpacket (index.js:83)
    at r.<anonymous> (index.js:83)
    at r.emit (index.js:83)
    at r.ondecoded (index.js:83)

Steps to reproduce the problem

change config.json so log.logIntellibrite is 1

Specifications

  1. What version of the code are you using?

5.1.1

  1. All output from the file log

https://gist.github.com/emes/213c2d6d4adb1e1bf31b6c6862d63a9a

  1. Any errors that are in the console

see above.

  1. Your config.json or in-use configuration file

fresh install using default config.json, see logs for embedded config

  1. Your pool equipment

IntelliTouch 5+S (with IntelliChlor disabled), pool-only IntelliFlow VS (2) IntelliBrite lights, each on a separate relay (2) valve actuators, on when Pool Heat on

tagyoureit commented 6 years ago

Can you replace lines 774-779 with the following:

if (currentCircuitArrObj[cir].hasOwnProperty('light')) {
    currentCircuitArrObj[cir].light = new Light(diff1[key].rhs.position, 'off', 0)

    if (logIntellibrite) {
        container.logger.silly('NEW key:', JSON.stringify(diff1[key], null, 2))
        container.logger.verbose('Msg# %s  Light details added for circuit %s (%s):', counter, getFriendlyName(cir), cir, diff1[key].rhs.position)
    }
}
else {
    logger.warn('Trying to add light to circuit %s but it has no light property. \n\t %j', currentCircuitArrObj[cir].number, currentCircuitArrObj[cir])
}

Let me know what it says. I'm also working on a better way to debug these (capture/replay packets), but am waiting on Winston for some unrelated changes.

emes commented 6 years ago

Thanks. Did that, here's the output:

01:28:03.425 INFO Potential expired/deprecated keys in
        file: config.json
        key: equipment.circuit.friendlyName.21:""
        key: equipment.circuit.friendlyName.22:""
        key: equipment.circuit.friendlyName.23:""
        key: equipment.circuit.friendlyName.24:""
        key: equipment.circuit.friendlyName.25:""
        key: equipment.circuit.friendlyName.26:""
        key: equipment.circuit.friendlyName.27:""
        key: equipment.circuit.friendlyName.28:""
        key: equipment.circuit.friendlyName.29:""
        key: equipment.circuit.friendlyName.30:""
        key: equipment.circuit.friendlyName.31:""
        key: equipment.circuit.friendlyName.32:""
        key: equipment.circuit.friendlyName.33:""
        key: equipment.circuit.friendlyName.34:""
        key: equipment.circuit.friendlyName.35:""
        key: equipment.circuit.friendlyName.36:""
        key: equipment.circuit.friendlyName.37:""
        key: equipment.circuit.friendlyName.38:""
        key: equipment.circuit.friendlyName.39:""
        key: equipment.circuit.friendlyName.40:""
        key: equipment.circuit.friendlyName.41:"Pump Medium"
        key: equipment.circuit.friendlyName.42:"Pump High"
        key: equipment.circuit.friendlyName.43:"Pump Max"
        key: equipment.circuit.friendlyName.44:"Cl Boost"
        key: equipment.circuit.friendlyName.45:"Cl Daily"
        key: equipment.circuit.friendlyName.46:""
        key: equipment.circuit.friendlyName.47:""
        key: equipment.circuit.friendlyName.48:""
        key: equipment.circuit.friendlyName.49:""
        key: equipment.circuit.friendlyName.50:""
01:28:03.565 INFO Starting up express server, https (port 33001)
01:28:03.582 INFO Starting up express server, http (port 33000)
01:28:03.593 INFO Starting up MDNS server
01:28:03.608 INFO initializing logger
01:28:03.685 DEBUG Initialized intellichem module
01:28:03.685 INFO Configuration settings:
01:28:03.685 INFO Settings:

*******************************
 Version: 5.1.0

Configuration file name: config.json
*******************************{
    "version": "5.1.0",
    "equipment": {
        "controller": {
            "intellicom": {
                "installed": 0,
                "friendlyName": ""
            },
            "intellitouch": {
                "installed": 1,
                "friendlyName": ""
            },
            "virtual": {
                "pumpController": "default",
                "chlorinatorController": "default"
            }
        },
        "circuit": {
            "hideAux": false,
            "friendlyName": {
                "1": "",
                "2": "Levolor",
                "3": "Pool Light",
                "4": "Pool Light",
                "5": "Chlorinator",
                "6": "Pool",
                "7": "",
                "8": "",
                "9": "",
                "10": "",
                "11": "",
                "12": "",
                "13": "",
                "14": "",
                "15": "",
                "16": "",
                "17": "",
                "18": "",
                "19": "",
                "20": "",
                "21": "",
                "22": "",
                "23": "",
                "24": "",
                "25": "",
                "26": "",
                "27": "",
                "28": "",
                "29": "",
                "30": "",
                "31": "",
                "32": "",
                "33": "",
                "34": "",
                "35": "",
                "36": "",
                "37": "",
                "38": "",
                "39": "",
                "40": "",
                "41": "Pump Medium",
                "42": "Pump High",
                "43": "Pump Max",
                "44": "Cl Boost",
                "45": "Cl Daily",
                "46": "",
                "47": "",
                "48": "",
                "49": "",
                "50": ""
            }
        },
        "chlorinator": {
            "installed": 0,
            "desiredOutput": {
                "pool": 0,
                "spa": 0
            },
            "friendlyName": "",
            "id": {
                "productName": "                "
            }
        },
        "pump": {
            "1": {
                "type": "VS",
                "externalProgram": {
                    "1": -1,
                    "2": -1,
                    "3": -1,
                    "4": -1
                },
                "friendlyName": ""
            },
            "2": {
                "type": "none",
                "externalProgram": {
                    "1": -1,
                    "2": -1,
                    "3": -1,
                    "4": -1
                },
                "friendlyName": ""
            }
        },
        "intellichem": {
            "installed": 0
        },
        "spa": {
            "installed": 0
        },
        "solar": {
            "installed": 0
        }
    },
    "poolController": {
        "appAddress": 33,
        "http": {
            "enabled": 1,
            "expressPort": 33000,
            "redirectToHttps": 0,
            "expressAuth": 0,
            "expressAuthFile": "/users.htpasswd"
        },
        "https": {
            "enabled": 1,
            "expressPort": 33001,
            "expressAuth": 0,
            "expressAuthFile": "/users.htpasswd",
            "expressKeyFile": "certs/privkey.pem",
            "expressCertFile": "certs/fullchain.pem"
        },
        "network": {
            "rs485Port": "/dev/ttyUSB0",
            "netConnect": 0,
            "netHost": "raspberrypi",
            "netPort": 9801,
            "inactivityRetry": 10
        },
        "log": {
            "logLevel": "silly",
            "socketLogLevel": "warn",
            "logPumpMessages": 0,
            "logDuplicateMessages": 0,
            "logConsoleNotDecoded": 0,
            "logConfigMessages": 0,
            "logMessageDecoding": 0,
            "logChlorinator": 0,
            "logIntellichem": 0,
            "logPacketWrites": 0,
            "logPumpTimers": 0,
            "logReload": 0,
            "logApi": 0,
            "logIntellibrite": 1,
            "fileLog": {
                "enable": 1,
                "fileLogLevel": "silly",
                "fileName": "output.log"
            }
        },
        "database": {
            "influx": {
                "enabled": 0,
                "host": "localhost",
                "port": 8086,
                "database": "pool"
            }
        }
    },
    "meta": {
        "notifications": {
            "version": {
                "remote": {
                    "version": "5.1.1",
                    "tag_name": "v5.1.1",
                    "dismissUntilNextRemoteVersionBump": true
                }
            }
        }
    },
    "outputToNodeRED": {
        "username": "blank",
        "password": "blank",
        "address": "rp.reade.tribeca.com",
        "port": 1880,
        "Variables": {
            "temperatures": {
                "airTemp": 90,
                "poolTemp": 91,
                "poolSetPoint": 92,
                "poolHeatMode": 93,
                "heaterActive": 94
            },
            "circuit": {
                "2": {
                    "status": 2
                },
                "3": {
                    "status": 3
                },
                "4": {
                    "status": 4
                },
                "5": {
                    "status": 5
                },
                "6": {
                    "status": 6
                },
                "41": {
                    "status": 41
                },
                "42": {
                    "status": 42
                },
                "43": {
                    "status": 43
                },
                "44": {
                    "status": 44
                },
                "45": {
                    "status": 45
                }
            },
            "pump": {
                "1": {
                    "watts": 25,
                    "rpm": 24
                }
            }
        }
    },
    "integrations": {
        "outputToNodeRED": 0
    }
}
01:28:03.687 VERBOSE Express Server https listening at port 33001
01:28:03.711 VERBOSE Socket.IO https server listening.
01:28:03.711 VERBOSE Express Server http listening at port 33000
01:28:03.711 VERBOSE Socket.IO http server listening.
01:28:03.732 SILLY updateAvail: reading local version at: /home/ms/pooldock/nodejs-poolController/package.json
01:28:03.733 INFO Starting up SSDP server
01:28:03.744 VERBOSE SSDP/UPnP Server started.
01:28:03.745 DEBUG Server starting complete.
        ["Server https started.","Server http started.","Server SSDP started.","Server MDNS started."]
01:28:03.745 VERBOSE Serial Port opened
01:28:03.882 SILLY updateAvailable.getLatestRelease from Github (latest published release)... v5.1.1
01:28:03.885 SILLY updateAvail.compareLocaltoSavedLocal: (current) published release (5.1.1) to cached/last published config.json version (5.1.1)
01:28:03.886 SILLY updateAvail: no change in current remote version compared to local cached config.json version of app
01:28:03.887 SILLY updateAvail: versions discovered:
        {"local":{"version":"5.1.0"},"remote":{"tag_name":"v5.1.1","version":"5.1.1"}}
01:28:03.888 SILLY updateAvail: local ver: 5.1.0    latest published release ver: 5.1.1
01:28:03.889 WARN Update available!  Version 5.1.1 can be installed.  You have 5.1.0
01:28:03.892 SILLY Outputting socket  updateAvailable
01:28:03.894 SILLY Socket.IO checking if we need to output updateAvail: true (will send if false)
01:28:03.894 SILLY updateAvail: finished successfully
01:28:04.084 INFO Queueing messages to retrieve configuration from Intellitouch
01:28:04.085 VERBOSE Queueing messages to retrieve SW Version
01:28:04.088 VERBOSE Queueing messages to retrieve time
01:28:04.089 VERBOSE Queueing messages to retrieve Pool/Spa Heat Mode
01:28:04.090 VERBOSE Queueing messages to retrieve Valve information
01:28:04.090 VERBOSE Queueing messages to retrieve settings(?)
01:28:04.091 VERBOSE Queueing messages to retrieve Custom Names
01:28:04.092 VERBOSE Queueing messages to retrieve Circuit Names
01:28:04.093 VERBOSE Queueing messages to retrieve light groups/positions
01:28:04.094 VERBOSE Queueing messages to retrieve Schedules
01:28:04.095 VERBOSE Queueing messages to retrieve pump configurations
01:28:04.098 SILLY Outputting socket  time
01:28:04.100 SILLY Outputting socket  temp
01:28:04.118 INFO Received valve status packet.
        Possible association with undefined.
          valve data: 165,1,15,16,2,29,1,27,32,0,0,0,0,0,0,0,64,0,0,0,75,75,0,0,73,0,0,0,0,4,0,0,0,1,3,2,71
01:28:04.119 SILLY Outputting socket  valve
01:28:04.345 SILLY Outputting socket  time
01:28:04.527 SILLY Outputting socket  heat
01:28:04.528 SILLY Outputting socket  temp
01:28:06.947 SILLY Outputting socket  pump
01:28:08.723 INFO
  Custom Circuit Names retrieved from configuration:
        ["Levolor","Medium","High","Max","Cl Boost","Cl Daily","TEST","East Light","West Light","Bleach Pump"]
01:28:10.864 SILLY Outputting socket  pump
01:28:18.470 INFO
  Circuit Array Discovered from configuration:
Circuit 1: NOT USED Function: Spa Status: 0 Freeze Protection: off Macro: 0
Circuit 2: Levolor Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 3: East Light Function: Intellibrite Status: 0 Freeze Protection: off Macro: 0
Circuit 4: West Light Function: Intellibrite Status: 0 Freeze Protection: off Macro: 0
Circuit 5: Bleach Pump Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 6: POOL Function: Pool Status: 1 Freeze Protection: off Macro: 0
Circuit 7: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 8: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 9: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 10: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 11: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 12: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 13: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 14: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 15: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 16: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 17: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 18: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 19: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 20: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 21: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 22: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 23: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 24: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 25: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 26: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 27: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 28: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 29: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 30: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 31: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 32: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 33: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 34: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 35: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 36: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 37: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 38: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 39: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 40: NOT USED Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 41: Medium Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 42: High Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 43: Max Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 44: Cl Boost Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 45: Cl Daily Function: Generic Status: 0 Freeze Protection: off Macro: 0
Circuit 46: NOT USED Function: Valve Status: 0 Freeze Protection: off Macro: 0
Circuit 47: NOT USED Function: Valve Status: 0 Freeze Protection: off Macro: 0
Circuit 48: NOT USED Function: Valve Status: 0 Freeze Protection: off Macro: 0
Circuit 49: NOT USED Function: Valve Status: 0 Freeze Protection: off Macro: 0
Circuit 50: NOT USED Function: Valve Status: 0 Freeze Protection: off Macro: 0

01:28:18.472 SILLY Outputting socket  circuit
01:28:18.669 DEBUG Msg# 94  Light all on/off and position packet is: 0,3,0,0,0,4,16,10,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
01:28:18.671 SILLY Intellibrite All on/off groups indexBy:  {
  "undefined": {
    "position": 1,
    "colorSet": 0,
    "colorSetStr": "White",
    "colorSwimDelay": 0
  }
}
01:28:18.671 DEBUG Intellibrite all on/off differences: [
  {
    "kind": "N",
    "path": [
      "undefined"
    ],
    "rhs": {
      "position": 1,
      "colorSet": 0,
      "colorSetStr": "White",
      "colorSwimDelay": 0
    }
  }
]
        Full packet:
Unhandled rejection TypeError: Cannot read property 'hasOwnProperty' of undefined
    at Object.assignControllerLightGroup (/home/ms/pooldock/nodejs-poolController/src/lib/equipment/circuit.js:774:31)
    at Object.process (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/controller/39.js:34:27)
    at Object.processControllerPacket (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/process-controller.js:115:45)
    at decode (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/decode-helper.js:263:51)
    at Object.processChecksum (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/decode-helper.js:301:13)
    at Object.iterateOverArrayOfArrays (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/receive-buffer.js:117:44)
    at Object.push (/home/ms/pooldock/nodejs-poolController/src/lib/comms/inbound/packet-buffer.js:36:37)
    at SerialPort.<anonymous> (/home/ms/pooldock/nodejs-poolController/src/lib/comms/sp-helper.js:78:44)
    at emitNone (events.js:106:13)
    at SerialPort.emit (events.js:208:7)
    at emitReadable_ (_stream_readable.js:513:10)
    at emitReadable (_stream_readable.js:507:7)
    at addChunk (_stream_readable.js:274:7)
    at readableAddChunk (_stream_readable.js:250:11)
    at SerialPort.Readable.push (_stream_readable.js:208:10)
    at binding.read.then (/home/ms/pooldock/nodejs-poolController/node_modules/serialport/lib/serialport.js:374:10)

01:28:21.166 WARN Error writing controller packet 'Get Schedule' to serial bus.  Tried 5 times to write 255,0,255,165,1,16,33,209,1,1,1,170
01:28:23.553 ERROR Aborting controller packet Get Schedule.  Tried 10 times to write 255,0,255,165,1,16,33,209,1,1,1,170
01:28:26.113 WARN Error writing controller packet 'Get Schedule' to serial bus.  Tried 5 times to write 255,0,255,165,1,16,33,209,1,2,1,171
01:28:28.502 ERROR Aborting controller packet Get Schedule.  Tried 10 times to write 255,0,255,165,1,16,33,209,1,2,1,171
01:28:28.654 ERROR Serial port connection lost.  Will retry every 10 seconds to reconnect.
01:28:28.658 INFO Serial port recovering from lost connection.
01:28:38.658 INFO Serial port recovering from lost connection.
^CShutting down open processes
01:28:39.418 SILLY http has 0 connections in it:
01:28:39.420 DEBUG Stopping Socket IO Server
01:28:39.420 SILLY All sockets removed from connection
01:28:39.421 DEBUG Socket IO Server closed
01:28:39.421 SILLY https has 0 connections in it:
01:28:39.422 DEBUG Stopping Socket IO Server
01:28:39.422 SILLY All sockets removed from connection
01:28:39.422 DEBUG Socket IO Server closed
01:28:39.423 VERBOSE SSDP/uPNP Server closed
01:28:39.424 VERBOSE Express Server http closed
01:28:39.424 VERBOSE Express Server https closed
01:28:39.424 VERBOSE All express + ssdp servers closed
nodejs-poolController services stopped successfully
nodejs-poolController has closed successfully.
emes commented 6 years ago

And here's output.log with all logging on...

output.log

tagyoureit commented 6 years ago

There are a few places that the code needs to change. I think I have most of them identified, which is the good news. Bad news is that you'll need to wait until I fix them for the Intellibrites work.

In the mean time, if you want the rest of the code working without it crashing sans Intellibrite, you can comment out the following lines:

emes commented 6 years ago

All good. Thanks.

Also, typo I'm sure you'd notice anyway...

--- a/src/lib/comms/inbound/controller/96.js
+++ b/src/lib/comms/inbound/controller/96.js
@@ -28,7 +28,7 @@ module.exports = function(container) {
         //eg RED: 165,16,16,34,96,2,195,0,2,12
         // data[6] = color
         // data[7] = light group
-        if (container.settings.get('logIntellibret')) {
+        if (container.settings.get('logIntellibrite')) {
tagyoureit commented 6 years ago

Thanks for the typo note... I just pushed up a 5.2 Dev branch. Can you try this out? It should be good for reading the Intellibrite messages. I took a stab at coding the set/change methods (change color, swim delay, light position) in the same manner. I'm curious if they will work for you. If not, I'll need your help with some packet captures.

This branch should also fix the

and thereafter everything goes to hell :-) (all packetWrites fail)

Cheers.

emes commented 6 years ago

Thanks again!