martin-doyle / node-red-contrib-aedes

MQTT broker for Node-RED based on Aedes
MIT License
60 stars 10 forks source link

Error stopping node: Close timed out #46

Open hybuild-project opened 3 years ago

hybuild-project commented 3 years ago

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 commented 3 years ago

Let me check. It might take some time.

martin-doyle commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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

martin-doyle commented 3 years ago

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 commented 3 years ago

@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 commented 3 years ago

Cool. Yes please do. Thanks a lot.

Steve-Mcl commented 2 years ago

@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 https://github.com/node-red/node-red/issues/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 commented 2 years ago

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 commented 2 years ago

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.