node-red: Unexpected Node Error

Happy ending to my story: I upgraded to Node-RED v2.2.1 today (thank you for sneaking this patch in just in time) and was finally able to see the underlying errors. They lead me to suspect network issues and, ultimately, I just had to reseat an ethernet cable of all things. OSI Layer 1 strikes again! @Steve-Mcl I would be glad to buy you a beer or support any initiative you designate with a donation.

@sumoneelse Thanks for the info. I have now managed to re-create the issue.

Not having any TPLink devices, I fired up a simulator (tplink-smarthome-simulator) and re-created the problem.

It lead me to this line in the kasa node.

Essentially, there is an issue with that node whereby the nodes context is being bound to global (as in node globalThis) and therefore causing an error when trying to call expected logging functions from the Node class that are not present.

For example: Current code…

 promise
        .then(info =>
          node.send({
            topic: device.shortId,
            payload: {
              ...info,
              timestamp: moment().format()
            }
          })
        )
        .catch(node.error)

… gives us an error regarding self._flows.log function not found

Improvements for Kasa node…

Changing the kasa nodes code to …

      promise
        .then(info =>
          node.send({
            topic: device.shortId,
            payload: {
              ...info,
              timestamp: moment().format()
            }
          })
        )
        .catch(error => {
          node.error(`Error controlling device: ${error}`)
        })

… now gives the correct error info (a timeout in the TPLink node) and more importantly, doesn’t call the logging function with globalThis context (node is actually/correctly a node-red Node instance)

Improvements for node-red logging of exceptional cases

I have raised PR #3446 which attempts to better capture the real problem.

This is an example of the error output after the PR…

which clearly shows the problem emanates from tplink-smarthome-api

I’ve attached a completely fresh 3-node flow which queries a TP-Link Kasa device every 5 seconds and debugs the result. I’ve also attached the debug output (image) which happened to run as follows from launch: success, success, error, success. The error message is right where+when the object should have been returned.

If you were to delete the debug node, you would still see the error in the debug window unattributed to any node. But as the timestamps show, it’s coming in response to a getQuickInfo query to a Kasa node.

[ { “id”: “a8f2fd5e9bb60bcf”, “type”: “tab”, “label”: “Flow 1”, “disabled”: false, “info”: “”, “env”: [] }, { “id”: “51cbe3a0c014be3d”, “type”: “inject”, “z”: “a8f2fd5e9bb60bcf”, “name”: “”, “props”: [ { “p”: “payload” } ], “repeat”: “5”, “crontab”: “”, “once”: true, “onceDelay”: 0.1, “topic”: “”, “payload”: “getQuickInfo”, “payloadType”: “str”, “x”: 240, “y”: 140, “wires”: [ [ “8eeec5ba96b67b23” ] ] }, { “id”: “8eeec5ba96b67b23”, “type”: “kasa”, “z”: “a8f2fd5e9bb60bcf”, “name”: “”, “device”: “192.168.150.28”, “interval”: 60000, “eventInterval”: 15000, “payload”: “getInfo”, “payloadType”: “info”, “debug”: false, “x”: 390, “y”: 140, “wires”: [ [ “27a91ca5259df024” ] ] }, { “id”: “27a91ca5259df024”, “type”: “debug”, “z”: “a8f2fd5e9bb60bcf”, “name”: “”, “active”: true, “tosidebar”: true, “console”: false, “tostatus”: false, “complete”: “false”, “statusVal”: “”, “statusType”: “auto”, “x”: 530, “y”: 140, “wires”: [] } ]