Flows.js: stopNode(node,removed) => reject("Close timed out");

Hi All,
I've been running NR (1.01?) with --inspect regularly, and it often pauses on reject("Close timed out");
(line 576 in flow.js - the code does not seem to have changed since 1.01).

I'm no expert with promises, but should the timeout not be cancelled if closePromise is resolved?

I've been 'coping' with hitting run each time, but today decided to look at which node was failing to stop, and found that it was a simple multi-output function node with no async code in it (the one node I changed), and the flow was basically inactive at the time as well. Tracing the node.close() showed that the node had been closed synchronously.... so closePromise had already been resolved?

best regards,

Simon

Hi @btsimonh

if you look at the full function:

const closePromise = node.close(removed);
    const closeTimeout = new Promise((resolve,reject) => {
        setTimeout(() => {
            reject("Close timed out");
        }, nodeCloseTimeout);
    });
    return Promise.race([closePromise,closeTimeout]).then(() => {

The key thing is the last line I've shared above - the Promise.race line. That resolves/rejects according to which ever promise resolves/rejects first and any subsequent promise is ignored.

That means if the closePromise resolves first, then the closeTimeout is ignored - and vice versa.

It may be possible to make it more efficient, but there's nothing inherently wrong with the logic at this point as far as I can tell.

So the question comes to why are you seeing the Function node seemingly timeout. If it is timing out, you'd get a Error stopping node: .... message in the log - do you see that?

Hi nick,

I agree it does not seem harmful, but for me, the timeout always goes off.... and calls reject(), which makes the debugger pause.
I do not see 'Error stopping node'.
breakpointing on it and then doing a deploy of modified only for a single node hits 'Stopped node', but then 15s later, the timeout goes off.

Reading about promise.race, it seems that this will fire at the first promise of the two resolving, and I assume the .catch will apply if either reject.

so I'm trying this:

function stopNode(node,removed) {
    Log.trace("Stopping node "+node.type+":"+node.id+(removed?" removed":""));
    const start = Date.now();
    const closePromise = node.close(removed);
    let closeTimer = null;
    const closeTimeout = new Promise((resolve,reject) => {
        closeTimer = setTimeout(() => {
            Log.warn("Stopping node close timeout "+node.type+":"+node.id+(removed?" removed":"")+" name: "+node.name);
            reject("Close timed out");
        }, nodeCloseTimeout);
    });
    return Promise.race([closePromise,closeTimeout]).then(() => {
        clearTimeout(closeTimer);
        var delta = Date.now() - start;
        Log.trace("Stopped node "+node.type+":"+node.id+" ("+delta+"ms)" );
    }).catch(err => {
        node.error(Log._("nodes.flows.stopping-error",{message:err}));
        Log.debug(err.stack);
    })
}

which solves the issue for me.

I have not tested with changing to commit complete flows; but I'm kind of assuming that we end up with lots of timers, all of which hang around for the full 15s, then call reject against a promise which is no longer being observed?

br,

s

Not quite. It resolves/rejects according to the first promise that resolves/rejects. The remaining promises are entirely ignored.

Adding the closeTimer and clearing when done is a worthwhile change to proactively tidy up the resources and avoid the unnecessary work around rejecting the unused timeout.

If you wanted to PR that change (without the extra Log.warn you've added in the timeout handler), I'd gladly merge it. Or I'm happy to just make the change myself. Let me know.

best if you slip it in; I've not got my general repo up to date.... and I guess you have :).
It's not urgent either - nobody else has noticed.
I am glad to have investigated though; now I can be sure that the issue was not my nodes not closing - as you know I don't play nice inside Node-Red, and I was a little concerned that I'd stepped over a line....

thanks nick,

s

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.