Error stopping node: Close timed out

[hybuild-project]

Steps to reproduce the error
Import the flow in: https://cookbook.nodered.org/mqtt/connect-to-broker, configure Aedes node (localhost:1883) and deploy

What happens
Every time the flow is deployed, the MQTT in node gets stuck for a while, then output: "Error stopping node: Close timed out"

Expected behaviour
The MQTT in node would immediately close without errors and the flow would be deployed without error and time wasting, as it happens if you use an external MQTT broker (e.g., Mosquitto)

Environment
Node-RED version: 1.3.2
Node.js version: 14.6.1

[martin-doyle]

Let me check. It might take some time.

[martin-doyle]

Thank you for reporting this issue.
I can confirm this error for Node-RED since version 1.3.
I checked Node-RED 1.2.9 and everything works as expected. Node-RED made some changes to the MQTT nodes and I need to check what the issue is.

[martin-doyle]

Additional observation.
This behaviour exists only if you do a "Full" deploy or stop Node-RED. It does not occur when deploy Modified Flows or Modified Nodes only.

[martin-doyle]

There is a fix for the Node-RED MQTT node in preparation. See Ensure mqtt-close message is published when closing mqtt nodes.
I will check the next Node-RED release and see if this issue is fixed.

[hybuild-project]

Many thanks, this is really helpful. Congratulations for your excellent work!

[martin-doyle]

Unfortunately, Node-RED 1.3.3 does not fix this issue. Looking at the logs it seems that Node-RED closes the broker first and then the MQTT nodes. The MQTT nodes send a disconnect but the broker is already down. No problem with external brokers since they keep running while Node-RED shuts down.
I will ask for a solution in the Node-RED project.
By the way, this issue is critical for the project since all test fail now.

[dbaba]

@martin-doyle I've created a workaround for this issue. Can I issue a PR so that you can review the change?
I tested with NR v1.3.5. All mocha tests were passed with the workaround.

[martin-doyle]

Cool. Yes please do. Thanks a lot.

[Steve-Mcl]

@martin-doyle

I have been working on this problem in node-red core and believe I have managed to stabilise the situation somewhat.

However, you might remember Nick saying the order of close events in node-red changed (so that regular nodes are signalled to close before config nodes) in node-red/node-red#2934 ?

Seeing as your aedes broker node does not use the config mechanism, it can be closed before other MQTT nodes meaning sometimes (depending on position of aedes in the flow file) can prevent close message being published..

I have done a lot of testing (aedes 1st in the flow file JSON, middle of the flow file JSON, end of flow file JSON, restarting node-red, full deploy, modify aedes then partial deploy etc etc etc) and believe there is an elegant solution to resolve the close message part of this problem.

If you delay the code inside node.on('close' by wrapping the content in a nextTick it puts your node to the end of the queue (so to speak) ensuring other nodes are closed first.

Code I used in testing...

    this.on('close', function (done) {
      nextTick(function onCloseDelayed() {
        broker.close(function () {
          node.log('Unbinding aedes mqtt server from port: ' + config.mqtt_port);
          server.close(function () {
            node.debug('after server.close(): ');
            if (node.mqtt_ws_path !== '') {
              node.log('Unbinding aedes mqtt server from ws path: ' + node.fullPath);
              delete listenerNodes[node.fullPath];
              node.server.close();
            }
            if (wss) {
              node.log('Unbinding aedes mqtt server from ws port: ' + config.mqtt_ws_port);
              wss.close(function () {
                node.debug('after wss.close(): ');
                httpServer.close(function () {
                  node.debug('after httpServer.close(): ');
                  done();
                });
              });
            } else {
              done();
            }
          });
        });
      })
    });

This greatly improves the situation ensuring the close message is sent etc.

NOTE: this is only part of the puzzle - I will also be publishing a general overall improvement to node-red core soon.

[Steve-Mcl]

For those following this thread, if you have the opportunity to update to node-red 2.2.2, this problem should now be improved. The other part will require an update to this node as I described in the previous comment above.

[martin-doyle]

Hi Steve, thank you for providing this fix. Unfortunately, it did not work on my computer with Node-RED V2.2.1.
But I can confirm that version 2.2.2 works now.