hepcat72 / node-red-contrib-life360

GNU General Public License v3.0
3 stars 4 forks source link

"No callbacks" message from Life360-Server node #1

Closed Prog72 closed 2 years ago

Prog72 commented 3 years ago

I'm getting this message constantly in the debug sidebar from the Life360-Server node.

Arriving/leaving activity still seems to be working as expected.

jpoeppelman1 commented 2 years ago

Has anyone been able to resolve the issue?

@hepcat72 - have you tried deploying NR using Docker similar to our setup? Might be worth it when reproducing the issue.

hepcat72 commented 2 years ago

Have either of you tried taking a snapshot of your container after node-red restart? I have a very strong hunch that that's related to the issue.

jpoeppelman1 commented 2 years ago

I haven't tried this, but seriously, isn't this just a bandaid? I like to upgrade my NR docker image when new versions of NR are released. It would be nice to avoid this entire step if possible. I'm mean really, isn't this just a small bug in the code somewhere?

hepcat72 commented 2 years ago

JavaScript is not my native language. I spent days trying to figure out how to quiet that message after initial install. The NR doc has stuff that I tried numerous times and it didn't work. If you have a better knowledge of node red and JavaScript, I welcome you to give it a shot. I don't doubt it may be something simple, but after spending days on it, and a restart solves the issue permanently, it didn't seem worth the extra effort.

brianmay commented 2 years ago

Its not JavaScript that is the problem here. As much as I like to criticise JavaScript whenever I can.

Rather node-red API seems to be poorly documented and has a number of gotchas.

Here is one example, I encountered recently. I don't think this is the problem here, but might help explain what could go wrong.

I countered this problem with another plugin: https://github.com/mikejac/node-red-contrib-google-smarthome/issues/174. Basically after a deploy, the plugin would stop working.

My belief is when you try to define a HTTP server call-back, e.g.:

RED.httpAdmin.get(url, callback)

If the URL is already registered, the call will silently fail, and you will end up with the old callback still being registered. And this exact situation happens for every redeploy. i.e. it won't automatically unregister URLs on deploy, you have to do that yourself. Arrgh.

Most of the time this isn't a problem because you the callback would be the exact same function anyway. I believe this is the case with the life360 code.

In the case of node-red-contrib-google-smarthome the old callback had references to old objects which had been replaced by the deploy, so it no longer worked. That is, its code looked like:

httpAuthRegister(...) {
        let me = this;

        appHttp.get(..., function(req, res) {
            # code that refers to me variable a lot
        }
}

So with every deploy, the value of me would be different, and as a result, a different callback function was needed to refer to the new value of me. But the callback wasn't being reregistered because it already existed.

There were two solutions:

  1. Create a new http server that gets recreated on deploy. But this is annoying.
  2. Create this horrible looking unregister function: https://github.com/mikejac/node-red-contrib-google-smarthome/blob/46ee1afd5f4825f5aaed56f7a1e951fbaba824c1/lib/SmartHome.js#L130-L157

In the case of this app however, I don't think that is the problem, as the callbacks I think are only used for configuration (correct me if I got this wrong). And the callbacks don't use locally scoped variables that change for each deploy.

brianmay commented 2 years ago

Looking through the code I see this: https://github.com/hepcat72/node-red-contrib-life360/blob/master/nodes/server.js#L44-L46

setInterval(function () {
    node.updateLife360();
}, 15000);

Makes me wonder if a redeploy will cancel the old timer or not. My guess is maybe not. If after deploy you end up with two timers, one that refers to the old node value, that probably would explain the messages that appear.

But this would only explain why the errors appear, it doesn't explain why it stopped working.

I think I will retest make sure it really stops working. Just in case I was getting confused.

My unconfirmed gut feeling is you might need to cancel the old timer on redeploy, but no idea how to do this.

brianmay commented 2 years ago

Oh, forgot to say, I redeploy by clicking the button, Nothing fancy. Use the defaults everywhere.

brianmay commented 2 years ago

Confirmed, no notifications get through after a redeploy. My gut feeling is it might still be related to the setInterval call, but I still don't understand. Will continue investigating tomorrow.

hepcat72 commented 2 years ago

I have not heard reports before about messages not working (redeploying or not), although I have not really tested in the case where the "no callbacks" messages are happening - I just restarted - so that's entirely possible.

Let me see if I can dig up the thread about this when I was trying to solve this issue with help from node red discourse. If I find the thread, I'll post a link here. Might help to provide some extra insights, but so far, you seem to be on the right track. It is consistent with my recollection when I tried to tackle this long ago...

hepcat72 commented 2 years ago

Well, no responses to this thread, but it describes my working theory, which seems similar to yours...

https://discourse.nodered.org/t/config-node-acting-like-its-not-set-up-when-it-is/36948

And I think I have conflated my work on this issue with the issue described here, but perhaps they're related...

https://discourse.nodered.org/t/how-to-delete-zombie-config-nodes/35926

But this longer thread starts to talk about cleaning up old nodes(/vestigial node copies?) on deploy. Seems the most relevant:

https://discourse.nodered.org/t/dumb-question-about-editing-a-node/34434/59?u=hepcat72

And this is the suggestion I tried numerous times in multiple places, but it never seemed to silence the messages from the config node or it's deleted copy:

https://discourse.nodered.org/t/dumb-question-about-editing-a-node/34434/65?u=hepcat72

I swear I had conversations elsewhere where people described these still running zombie copies, but I didn't find a thread that mirrors my recollection...

Perhaps also related, I had investigated how to disable specific callbacks when a node was disabled, but still on the flow:

https://discourse.nodered.org/t/how-to-disable-enable-specific-options-on-change/34466

brianmay commented 2 years ago

I added some debugging. But today seem to be getting a number of server 500/502 errors.

i.e. console.log(circle) logs:

{
  errorMessage: 'An Internal Error Has Occurred.',
  url: '/v3/circles/<censored>',
  status: 500
}

and

<html>
<head><title>502 Bad Gateway</title></head>
<body bgcolor="white">
<center><h1>502 Bad Gateway</h1></center>
<hr><center>nginx</center>
</body>
</html>

and

undefined

Which I think in turn causes other problems:

Unhandled rejection TypeError: Cannot read property 'name' of undefined
    at ServerNode.sendChanged (/data/node_modules/node-red-contrib-life360/nodes/server.js:67:37)
    at /data/node_modules/node-red-contrib-life360/nodes/server.js:246:26
    at /data/node_modules/node-red-contrib-life360/nodes/server.js:253:17
    at tryCatcher (/data/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/data/node_modules/bluebird/js/release/promise.js:547:31)
    at Promise._settlePromise (/data/node_modules/bluebird/js/release/promise.js:604:18)
    at Promise._settlePromise0 (/data/node_modules/bluebird/js/release/promise.js:649:10)
    at Promise._settlePromises (/data/node_modules/bluebird/js/release/promise.js:729:18)
    at _drainQueueStep (/data/node_modules/bluebird/js/release/async.js:93:12)
    at _drainQueue (/data/node_modules/bluebird/js/release/async.js:86:9)
    at Async._drainQueues (/data/node_modules/bluebird/js/release/async.js:102:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/data/node_modules/bluebird/js/release/async.js:15:14)
    at processImmediate (internal/timers.js:464:21)
Unhandled rejection TypeError: Cannot read property 'length' of undefined
    at /data/node_modules/node-red-contrib-life360/nodes/server.js:262:37
    at tryCatcher (/data/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/data/node_modules/bluebird/js/release/promise.js:547:31)
    at Promise._settlePromise (/data/node_modules/bluebird/js/release/promise.js:604:18)
    at Promise._settlePromise0 (/data/node_modules/bluebird/js/release/promise.js:649:10)
    at Promise._settlePromises (/data/node_modules/bluebird/js/release/promise.js:729:18)
    at _drainQueueStep (/data/node_modules/bluebird/js/release/async.js:93:12)
    at _drainQueue (/data/node_modules/bluebird/js/release/async.js:86:9)
    at Async._drainQueues (/data/node_modules/bluebird/js/release/async.js:102:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/data/node_modules/bluebird/js/release/async.js:15:14)
    at processImmediate (internal/timers.js:464:21)

Don't think I saw anything like the javascript errors before. So now may not be the best time to test stuff. But I wanted to record these errors anyway.

brianmay commented 2 years ago

I can confirm: After 1st deploy, the timer function is called 2 times every 15 seconds. After 2nd deploy it is called 3 times every 15 seconds. Which probably isn't good for the load on the life360 server. Will try to find a solution here.

brianmay commented 2 years ago

I believe this code will solve the call-backs warning after deploy problem:

            if (node.username && node.password) {
                node.warn("setInterval");
                node.updateLife360();
                let timer = setInterval(function () {
                    node.warn("got interval");
                    node.updateLife360();
                }, 15000);
                node.warn("setInterval done", timer);

                node.on('close', function(removed, done) {
                    node.warn("clearInterval1", timer);
                    clearInterval(timer);
                    done();
                });
            }

Still testing. If this continues to work I will submit a PR, minus excessive logging.

Would like to think this is why I wasn't getting events. My suspicion is that might be unrelated. Maybe related to the unreliability of the server even.

Probably the code should be made more robust if the server returns unexpected data. The unexpected response should be logged, and we should not attempt to otherwise use it.

brianmay commented 2 years ago

I think updating every request in index.js to include the following should help with the 500 errors:

    request(options)
      .then(response => {
        if (response.statusCode != 200) {
            reject(new Error(`Server error: ${response.statusCode}`));
        }

Still testing. Will create a PR for this when done.

So far seems to work however:

Unhandled rejection Error: Server error: 500
    at /data/node_modules/node-red-contrib-life360/index.js:108:20
    at tryCatcher (/data/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/data/node_modules/bluebird/js/release/promise.js:547:31)
    at Promise._settlePromise (/data/node_modules/bluebird/js/release/promise.js:604:18)
    at Promise._settlePromise0 (/data/node_modules/bluebird/js/release/promise.js:649:10)
    at Promise._settlePromises (/data/node_modules/bluebird/js/release/promise.js:729:18)
    at Promise._fulfill (/data/node_modules/bluebird/js/release/promise.js:673:18)
    at Request._callback (/data/node_modules/bluebird/js/release/nodeback.js:42:21)
    at Request.self.callback (/data/node_modules/request/request.js:185:22)
    at Request.emit (events.js:400:28)
    at Request.<anonymous> (/data/node_modules/request/request.js:1154:10)
    at Request.emit (events.js:400:28)
    at IncomingMessage.<anonymous> (/data/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (events.js:519:28)
    at IncomingMessage.emit (events.js:412:35)
    at endReadableNT (internal/streams/readable.js:1334:12)

Later: Possibly if the server errors are too frequent, might not want to log every one. Not sure about that yet.

brianmay commented 2 years ago

Pull requests created.

jpoeppelman1 commented 2 years ago

Hi All,

Did this issue get fixed? I see there were code changes, but when I look in Node Red, I still see the old version? Check out the screen shot.

image
hepcat72 commented 2 years ago

I believe it is, but you're right, it hasn't been released yet. It would be great to have some more testing to show it's stable. As I understand it, there is the potential for other newly reported and somewhat frequent errors. If you could install it from the repo (not from npm), it would be great to have some more testing to show its stable.

jpoeppelman1 commented 2 years ago

I can try it out.. Is there a way to install this safely in node red dockers container and option to backout?

rik1984 commented 1 year ago

I still face the issue as described in this post. Restart of NodeRED works as a solution, but I was curious whether the fix has been released already?

And how to get that version. I've tried the regular installation using the palette (node-red-contrib-life360) and the latest development version (npm i https://github.com/hepcat72/node-red-contrib-life360)

hepcat72 commented 1 year ago

Version 1.1.0 was published to npm 6 months ago and the last merge addressing this issue was Nov 20, 2021, so it should be available in the palette now.

jpoeppelman1 commented 1 year ago

Version 1.1.0 was published to npm 6 months ago and the last merge addressing this issue was Nov 20, 2021, so it should be available in the palette now.

I restarted node red docker container and still I can't see the new version. Are you sure we are able to download the new version? Hmmm...

image

brianmay commented 1 year ago

It has been a while since I looked at this, but I don't remember having any problems updating.

npm is correct also:

https://www.npmjs.com/package/node-red-contrib-life360

Sorry, can't help more then that. I rewrote my stuff to use other solutions and don't currently use node-red. Wonder if there is some sort of update npm index operation.

rik1984 commented 1 year ago

It has something to do with the sync between npm and NodeRED I suppose. If I look for the node in node-red I only find v1.0.0 (https://flows.nodered.org/search?term=life360)

Might this be the solution? https://stackoverflow.com/questions/69419743/new-version-of-package-is-published-but-does-not-show-up-on-npm-and-is-not-insta

I think it is the one who publishes who could add that.

Or is there another way how I can get a package in that is not in the node-red library?