2: Server processes do not close and exit properly when terminated from the terminal

[nunoguedelha]

Refer to #33 :

#	type	Severity	Reported Observations	Comments
2	[bug]	H	The iCubTelemVizServer remains active in the background when pressing Ctrl+C, and it has to be killed > manually every time, otherwise there are address conflicts when restarting.	This is related to the default processing of the event signals SIGTERM, SIGINT, SIGQUIT, which does not implement a robust termination sequence

Further Details on the Affected Components and Conditions

• This issue affects only iCubTelemVizServer which creates connections with the YARP ports and the requests from the client browser through socket connections, unlike the openmctStaticServer. The later handles the Open MCT libraries installation on the remote client browser, along with the dictionary of telemetry entries and the Open MCT plugins associating the GUI widgets to the http (history and realtime) requests sent to iCubTelemVizServer.
• The issue occurs independently from the changes done in Run both telemetry server and openmct visualizer Node.js applications through a single command #25 . It will occur even if iCubTelemVizServer is running alone, and openmctStaticServer is never started, not even from the terminal.
• The issue almost never occurs if there are no connections with the RPC wholeBodyDynamics and WalkingModule servers.

Implementation Steps & issues

• Capture SIGINT, SIGTERM, SIGQUIT signal events for iCubTelemVizServer Node.js process.
• Process SIGINT, SIGTERM, SIGQUIT signal events for iCubTelemVizServer Node.js process. #40
• Capture SIGINT, SIGTERM, SIGQUIT signal events for openmctStaticServer Node.js process. #41
• Process SIGINT, SIGTERM, SIGQUIT signal events for openmctStaticServer Node.js process. #42
• Avoid double SIGINT on openmctStaticServer process #44

[nunoguedelha]

Servers Termination

Objective and Background

We have to make sure the user is capable of terminating the servers from the terminal, and that they follow a proper termination, closing any child processes if necessary and opened YARP ports. This requires a proper processing of the events generated when the user either hits CTRL+C on the terminal shell where the server application is running, or terminates the application with a kill -3 <pid>. The respective signals triggered by these actions are:

* **SIGINT**: triggered by <CTRL>+"C"

* **SIGTERM**:  triggered by `kill -3 <pid>`

The respective events 'SIGINT' and 'SIGTERM' are emitted when the Node.js process receives these signals.

Refer to

https://nodejs.org/api/process.html
https://nodejs.org/api/process.html#process_signal_events

Implementation

We have to define the listeners that will implement the desired actions upon reception of the mentioned events. Typically...

const process = require('process');
...
process.on('SIGINT', () => {
  console.log('Received SIGINT. Press Control-D to exit.');
});

Instead of an anonymous function definition, we can pass an already defined anonymous function handler (pointer). Side note: process is imported by default in the main JS script.

Tests & issues

* I'm still having some problems capturing the <CTRL>+"C" input and respective event in the **iCubtelemVizServer** process.

* The `process.on` callbacks are not working as expected in the debugging mode on Webstorm.

* On Webstorm, in normal run mode, the <CTRL>+"C" input and triggered signal are closing properly the main process (`node iCubTelemVizServer.js`), but is captured only by the default SIGINT listener, and not by the implemented one.

For some reason the listener on +"C" is ignored. Maybe this is related to an occasional warning we are getting when running the iCubTelemVizServer process:

[INFO] |yarp.os.Port| Port /yarpjs/wholeBodyDynamics/rpc:o active at tcp://192.168.1.100:10125/
(node) warning: possible EventEmitter memory leak detected. 11 exit listeners added. Use emitter.setMaxListeners() to increase limit.

Analyzing...

Originally posted by @nunoguedelha in #25 (comment)

[nunoguedelha]

Capturing SIGINT signal event: Analysis

The issue of SIGINT not being captured by the implemented listener might be related to the maximum number of listeners being occasionally exceeded. Indeed we sometimes get the warning:

[INFO] |yarp.os.Port| Port /yarpjs/wholeBodyDynamics/rpc:o active at tcp://192.168.1.100:10125/
(node) warning: possible EventEmitter memory leak detected. 11 exit listeners added. Use emitter.setMaxListeners() to increase limit.

Although the warning is not systematically emitted, this deserves some further investigation.

• There is a listener counter that can be checked (https://github.com/nodejs/node/blob/711e073596f29b047086e2f3d4ab3706b98462f7/lib/events.js#L703-L740)

  listenerCount definition

  /**
   * Returns the number of listeners listening to the event name
   * specified as `type`.
   * @deprecated since v3.2.0
   * @param {EventEmitter} emitter
   * @param {string | symbol} type
   * @returns {number}
   */
  EventEmitter.listenerCount = function(emitter, type) {
    if (typeof emitter.listenerCount === 'function') {
      return emitter.listenerCount(type);
    }
    return FunctionPrototypeCall(listenerCount, emitter, type);
  };
  
  EventEmitter.prototype.listenerCount = listenerCount;
  
  /**
   * Returns the number of listeners listening to event name
   * specified as `type`.
   * @param {string | symbol} type
   * @returns {number}
   */
  function listenerCount(type) {
    const events = this._events;
  
  
    if (events !== undefined) {
      const evlistener = events[type];
  
  
      if (typeof evlistener === 'function') {
        return 1;
      } else if (evlistener !== undefined) {
        return evlistener.length;
      }
    }
  
  
    return 0;
  }

  The listener counter was far below the defined upper limit (10). In addition, the QUIT signal (number 3) event is captured propely. IT is actually the only one, as all the other signals are not

  1       HUP (hang up)
  2       INT (interrupt)
  6       ABRT (abort)
  9       KILL (non-catchable, non-ignorable kill)
  14      ALRM (alarm clock)
  15      TERM (software termination signal)
  

• This issue occurs only with the iCubTelemVizServer module running with Node.js v4.2.2, not with openmctStaticServer running with Node.js v14.17.0 where we manage to capture all the signals.

• It still works with openmctStaticServer when running it directly from the terminal and not as a child process spawned from iCubTelemVizServer.

• Running directly node iCubTelemVizServer fails the same way.

• Removing the option $NODE_DEBUG_OPTION from the npm start script does not solve the problem

  "scripts": {
    "start": ". ${NVM_DIR}/nvm.sh; nvm use v4.2.2; node ${NODE_DEBUG_OPTION} iCubTelemVizServer.js"
  },

• Display the listeners on SIGINT.
  The following code snippet added to the end of .../iCubTelemVizServer/iCubTelemVizServer.js or .../openmctStaticServer/server.js allows to count and display the registered listeners for a given event myEvent`, including the listener we added.

  myEvent = 'SIGQUIT';
  console.log('listeners count for event %s: %d',myEvent,process.listenerCount(myEvent));
  process.on(myEvent, () => {console.log('Received ',myEvent);});
  console.log('listeners count for event %s: %d',myEvent,process.listenerCount(myEvent));
  
  process.listeners(myEvent).forEach((func) => {
      console.log(func.toString());
  });

  When running .../iCubTelemVizServer/iCubTelemVizServer.js we got the following output for myEvent=SIGQUIT:

  listeners count for event SIGQUIT: 0
  listeners count for event SIGQUIT: 1
  () => {console.log('Received ',myEvent);}

  and the following output for myEvent=SIGINT:

  listeners count for event SIGINT: 1
  listeners count for event SIGINT: 2
  function (){
      process.exit();
  }
  () => {console.log('Received ',myEvent);}

  and similar for SIGTERM.

  Otherwise, when running .../openmctStaticServer/server.js we got the following output for SIGINT:

  listeners count for event SIGINT: 0
  listeners count for event SIGINT: 1
  () => {console.log('Received ',myEvent);}

  and similar for all other events.

  This shows why we were seeing the problem only on .../iCubTelemVizServer/iCubTelemVizServer.js, and that it occurs because of the order of appearence of the listeners: for SIGINT, the listener executing process.exit(); is the first to run and kills the process even before our listener gets a chance to be executed.

• Check if changing the stdio configuration between npm and the node.js child process changes anything.

References

Events Emitted by Node.js when Signal Received

• https://nodejs.org/api/process.html
• https://nodejs.org/api/process.html#process_signal_events
• Linux supported POSIX standard: https://man7.org/linux/man-pages/man7/signal.7.html

Signal listeners and Class EventEmitter

• https://nodejs.org/api/events.html
• https://nodejs.org/api/events.html#events_emitter_emit_eventname_args
• https://nodejs.org/api/events.html#events_asynchronous_vs_synchronous

  The EventEmitter calls all listeners synchronously in the order in which they were registered.

• https://nodejs.org/api/events.html#events_handling_events_only_once
• https://nodejs.org/api/events.html#events_emitter_on_eventname_listener
• https://nodejs.org/api/events.html#events_emitter_once_eventname_listener
• https://nodejs.org/api/events.html#events_emitter_prependlistener_eventname_listener

[nunoguedelha]

Capturing SIGINT signal event: Root cause and Fix

Root cause

As we described previously, the issue was due to the fact that two listeners are registered for the event 'SIGINT`, and ours does not come first in the list.

listeners count for event SIGINT: 2
function (){
    process.exit();
}
() => {console.log('Received ',myEvent);}

Actually, the first one is not a default listener^*, it has been added by one of the packets included in the main script iCubTelemVizServer.js. This can be confirmed by counting the number of added listeners in the very first line of the script, which returns 0.

(*) The default listener associated to an event is called when no other listener is added for that event, and is replaced by added events.

By dichotomy, counting the listeners before and after a code block, we narrowed down the search to the line

var yarp = require('YarpJS');

More precisely in the installed file node_modules/YarpJS/yarp.js

// make sure to close stuff when Ctrl+C arrives
process.on('SIGINT',function(){
    process.exit();
});

// make sure to close stuff when closing signal arrives
process.on('SIGTERM',function(){
    process.exit();
});

which could have been found by a simple grep on SIGINT actually, but the first search method is more deterministic.

Fix

We have two possible approaches:

1. Define our listener in the very beginning of the script. This does not avoid that another listener is added before our main script is run, in the case it is run within another calling script.
2. Force our listener to be the first in the list, even without removing the existing ones. This is a more robust approach, and can be done by using the process.prependListener(eventName, listener) function.

   process.prependListener('SIGINT', () => {closeServers('SIGINT');});

But EventEmitter.prependListener is not supported in Node.js v4.2.2, so we have no choice but to implement option 1.

We add to the top of the main script:

process.on('SIGQUIT', () => {closeServers('SIGQUIT');});
process.once('SIGTERM', () => {closeServers('SIGTERM');});
process.once('SIGINT', () => {closeServers('SIGINT');});

We use process.once instead of process.on such that if the closing steps fail for some reason and the other registered listeners do not terminate the main Node.js process, subsequent events SIGINT will execute the default termination procedure and exit the process immediately.

Note

The process.once function is automatically expanded to the following:

function g() {
    this.removeListener(type, g);

    if (!fired) {
      fired = true;
      listener.apply(this, arguments);
    }
}

This content can be get by displaying the signal event callback as described in #34 (comment).

[nunoguedelha]

Processing the SIGINT event: closeServers(signal) function

The function closeServers(signal) implements the following ordered sequence of closure actions:

• Stop the child Node.js process running the OpenMCT static server which served the installation of the telemetry web client (visualizer web GUI).
• Stop the Telemetry HTTP server telemServer from accepting new connections from the still running client web page.
• Flush the unfinished processing or responses to the pending requests.
• Stop sending "real-time telemetry data" messages (notifications) to subscribers, i.e. remove the subscriptions.
• Stop reading the YARP ports associated to the telemetry entries in portInConfig (turn off the respective listeners).
• Close the respective YARP port connections and YARP ports instantiated by the main Node.js process.
• Stop the Control Console HTTP server consoleServer from accepting new RPC commands from the control console web client.
• Stop an eventual ongoing "ping" process.
• Flush the unfinished processing or responses to the pending commands.
• Close the respective YARP RPC port connections and RPC read ports instantiated by the main Node.js process.
• exit the process (should be automatic if there no pending action left).

Moved to #40 .

[nunoguedelha]

References on Node.js

• Main documentation: https://nodejs.org/api/index.html,https://nodejs.org/docs/latest-v4.x/api/index.html
• Another complete tutorial: https://nodejs.dev/learn

How to properly exit a Node.js process

Avoid process.exit()

https://stackoverflow.com/questions/5266152/how-to-exit-in-node-js

Calling process.exit() will force the process to exit as quickly as possible even if there are still asynchronous operations pending that have not yet completed fully, including I/O operations to process.stdout and process.stderr.
In most situations, it is not actually necessary to call process.exit() explicitly. The Node.js process will exit on its own if there is no additional work pending in the event loop. The process.exitCode property can be set to tell the process which exit code to use when the process exits gracefully.

https://nodejs.dev/learn/how-to-exit-from-a-nodejs-program

SIGKILL is the signal that tells a process to immediately terminate, and would ideally act like process.exit().

The steps

https://nodejs.dev/learn/how-to-exit-from-a-nodejs-program

Node.js http.Server.close(callback) method

• https://www.w3schools.com/nodejs/met_server_close.asp
• https://nodejs.org/api/http.html#http_event_close
• https://nodejs.org/api/net.html#net_server_close_callback

Stops the HTTP server from accepting new connections.
callback: Optional. Specifies a function to be executed after the server stops listening for connections and emits a 'close' event. It will be called with an Error as its only argument if the server was not open when it was closed.

[nunoguedelha]

The main problem with the server closure seems to come from the fact that if the telemetry server is created as follows:

const telemServer = app.listen(portTelemetryRespOrigin, function () {
    console.log('ICubTelemetry History hosted at http://localhost:' + portTelemetryRespOrigin + '/history');
    console.log('ICubTelemetry Realtime hosted at ws://localhost:' + portTelemetryRespOrigin + '/realtime');
});

and for stopping it, we should do:

telemServer.close(() => {
        console.log('iCub Telemetry Server closed. No further incoming requests accepted.');
    })

but the close() apparently does nothing (the debugger displays the function body as being [native code]), and we don't see the unlisten callback (previously returned by ICubTelemetry.prototype.listen()) being called.

Or maybe the event close is being send but not caught. Probably it has to do with the definition of RealtimeServer(device) constructor, which is using the express packet instead of express-ws (the later is wrapped with the websocket interface). To be checked tomorrow...

[nunoguedelha]

The reason was that telemServer.close(...) only keeps the server from accepting additional connections, but doesn't close the already established ones (https://nodejs.org/api/http.html#http_server_close_callback).

We need to use websocket.terminate() or socket.destroy() on the open sockets in order to close the connections (https://github.com/websockets/ws/blob/master/doc/ws.md#websocketterminate).

[nunoguedelha]

References on Express and Express-ws, routing etc

Main

https://expressjs.com/

App, Router

https://expressjs.com/en/4x/api.html#app

The app object conventionally denotes the Express application. Create it by calling the top-level express() function exported by the Express module.

https://expressjs.com/en/4x/api.html#router

Using middleware

https://expressjs.com/en/guide/using-middleware.html

Express is a routing and middleware web framework that has minimal functionality of its own: An Express application is essentially a series of middleware function calls.

Middleware functions are functions that have access to the request object (req), the response object (res), and the next middleware function in the application’s request-response cycle. The next middleware function is commonly denoted by a variable named next.

Middleware functions can perform the following tasks:

• Execute any code.
• Make changes to the request and the response objects.
• End the request-response cycle.
• Call the next middleware function in the stack.

Routing

https://expressjs.com/en/guide/routing.html

app.METHOD(path, callback [, callback ...])

https://expressjs.com/en/4x/api.html#app.METHOD

Routes the HTTP method "METHOD" (in lowercase) request to the specified path with the specified callback functions.

Argument	Description	Default
path	The path for which the middleware function is invoked; can be any of: A string representing a path. A path pattern. A regular expression pattern to match paths. An array of combinations of any of the above. For examples, see Path examples.	'/' (root path)
callback	Callback functions; can be: A middleware function. A series of middleware functions (separated by commas). An array of middleware functions. A combination of all of the above. You can provide multiple callback functions that behave just like middleware, except that these callbacks can invoke next('route') to bypass the remaining route callback(s). You can use this mechanism to impose pre-conditions on a route, then pass control to subsequent routes if there is no reason to proceed with the current route. Since router and app implement the middleware interface, you can use them as you would any other middleware function. For examples, see Middleware callback function examples.	None

...
If a middleware (callback) function is not an end-point (ending the req/res cycle), it has to call next() in order to let subsequent middleware functions in the same route stack to be processed, or call next('route') in order to continue matching subsequent routes.
...

app.use([path,] callback [, callback...])

https://expressjs.com/en/4x/api.html#app.use

Mounts the specified middleware function or functions at the specified path: the middleware function is executed when the base of the requested path matches path. A route will match any path that follows its path immediately with a “/”. For example: app.use('/apple', ...) will match “/apple”, “/apple/images”, “/apple/images/news”, and so on.

Hypertext Transfer Protocol (authentication, request methods)

https://en.wikipedia.org/wiki/Hypertext_Transfer_Protocol#Request_methods

express-ws

The following code snipport

    var router = express.Router();
    router.ws('/', function (ws) {...};

calls addWsRoute(route) {...} in node_modules/express-ws/lib/add-ws-method.js.

websocket

https://github.com/websockets/ws/blob/master/doc/ws.md
https://nicedoc.io/websockets/ws/blob/master/doc/ws.md

websocket.readyState : {Number} The current state of the connection. This is one of the ready state constants.
websocket.terminate(): Forcibly close the connection. Internally this calls socket.destroy().
websocket.onclose : {Function} An event listener to be called when connection is closed. The listener receives a CloseEvent named "close".

Ready state constants

Constant	Value	Description
CONNECTING	0	The connection is not yet open.
OPEN	1	The connection is open and ready to communicate.
CLOSING	2	The connection is in the process of closing.
CLOSED	3	The connection is closed.

We should check that websocket.readyState === websocket.OPEN (= 1) before sending any data.

Javascript Async and Promises

https://www.w3schools.com/js/js_async.asp
https://www.w3schools.com/js/js_promise.asp
https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Promise/all

The Promise.all() method takes an iterable of promises as an input, and returns a single Promise that resolves to an array of the results of the input promises. This returned promise will resolve when all of the input's promises have resolved.

[nunoguedelha]

CC @S-Dafarra @RiccardoGrieco @evalli-iit @traversaro