Fs store sync triggering a lot like 50 times

Sahil333

I was not getting this before but from this evening I am getting the below log when processing the render request. Initially, I was getting this 2-3 times but as I repeated the request its number grew.

2019-12-10T12:57:29.918Z - debug: fs store sync is triggering reload, because /Users/sahil/Tesco/document-service/data/settings was changed by other process 2019-12-10T12:57:29.918Z - info: fs store is loading data

jan_blaha

Don't you have another jsreport instance running over the same data directory?

FYI you can display changes monitoring using

{ 
  "extensions":  {
    "fs-store": { "syncModifications": false }
  }
}

Sahil333

No, there is only a single instance node. I ran lsof -i tcp:8080 and got this. I'll restart my system and try again to be sure.

Google 62626 sahil 27u IPv6 0xe2cf8c914865fd6d 0t0 TCP localhost:56153->localhost:http-alt (CLOSE_WAIT)
Google 62626 sahil 30u IPv6 0xe2cf8c9148661c0d 0t0 TCP localhost:56154->localhost:http-alt (CLOSE_WAIT)
Google 62626 sahil 36u IPv6 0xe2cf8c9148662e6d 0t0 TCP localhost:56155->localhost:http-alt (CLOSE_WAIT)
Google 62626 sahil 38u IPv6 0xe2cf8c914866348d 0t0 TCP localhost:56156->localhost:http-alt (CLOSE_WAIT)
Google 62626 sahil 40u IPv6 0xe2cf8c914865eb0d 0t0 TCP localhost:56157->localhost:http-alt (CLOSE_WAIT)
Google 62626 sahil 44u IPv6 0xe2cf8c9138078fcd 0t0 TCP localhost:56158->localhost:http-alt (CLOSE_WAIT)
node 98371 sahil 24u IPv6 0xe2cf8c91486609ad 0t0 TCP *:http-alt (LISTEN)

Also, when I set literally any option for "fs-store" in extensions, I start getting this error and without it, no such error.

2019-12-11T05:43:21.084Z INFO /v1/socket.io/?EIO=3&transport=polling&t=MxpUxJt 404 - Correlation-Id - 23ceccb0-1bd9-11ea-99e7-7101baec6f0c - 0.916 ms

Sahil333

Ok, after restarting the system both the issue disappeared. I got the culprit of the issue. I have a mechanism for the graceful shutdown of the server as given below. The error doesn't appear if I do process.exit() after the shutdown. But the error starts to appear after commenting process.exit(0). It seems some background process remains alive even after doing shutdown and process.exit(0) closes that process. Is this behavior ok?

const shutdown = (signal, value) => {
  logger.info(`Shutting down server by ${signal}:${value}...`);
  server.shutdown((err) => {
    if (err) {
      logger.error(
        `STOPPING_SERVER: Stopping process to recover from unhandled exception.${err}`,
      );
      process.exit(1);
    } else {
      logger.info('Shut down server successfuly');
      process.exit(0);
    }
  });
};

PS. I am using nodemon for development purposes.

jan_blaha

I am a bit lost. Where do you have actually this script, what is server.shutdown?
Please try to describe more in the detail how do you run jsreport.
There should be no pending processes after process running jsreport exits, unless you use cli jsreport.exe render --keepAlive

Sahil333

OK, I have written a simple nodejs application with express and hosting jsreport studio on an endpoint '/v1' using jsreport nodejs sdk. Apart from that, I have two other endpoints, one to render a given template and other to merge a list of documents.

The sever.shutdown is the same as the server.close, I used this package https://www.npmjs.com/package/http-shutdown for this (I used server.close as well but faced the same problem). It is defined in the entry point of my application server.js. I run the application with node server.js.

const signals = {
  SIGINT: 2,
  SIGTERM: 15,
};
// Do any necessary shutdown logic for our application here
const shutdown = (signal, value) => {
  logger.info(`Shutting down server by ${signal}:${value}...`);
  server.shutdown((err) => {
    if (err) {
      logger.error(
        `STOPPING_SERVER: Stopping process to recover from unhandled exception.${err}`,
      );
      process.exit(1);
    } else {
      logger.info('Shut down server successfuly');
      process.exit(0);
    }
  });
};
// Create a listener for each of the signals that we want to handle
Object.keys(signals).forEach((signal) => {
  process.on(signal, () => {
    logger.info(`Process received a ${signal} signal`);
    shutdown(signal, signals[signal]);
  });
});

I'll elaborate on the two cases:

Case 1: Call process.exit() in the callback of server.shutdown()
1. I start the server.
2. Send a request on one of the endpoints and I see no fs store reload
3. Close the server.
4. Start the server again
5. Send request again and I see no fs store reload

Case 2: Does not call process.exit() in the callback of server.shutdown()
1. I start the server.
2. Send a request on one of the endpoints and I see no fs store reload
3. Close the server.
4. Start the server again
5. Send request again and I start seeing fs store reload
6. Now, on every subsequent restart, I see fs store reload after sending the request with more and more number of fs store reload.

jan_blaha

Hm. If I get it right you just close the HTTP server and start it again in the case 2.
Closing http server doesn't close jsreport, so if you are somewhere creating a new instance, you get the second instance running.
You should call jsreport.close() to shutdown jsreport.

Please let me know if this was the problem.

Sahil333

It worked! But jsreport.close() closes the express server as well on which jsreport is running. So after the promise of jsreport.close() is resolved when I do server.shuttdown(), I get an error server is not running.

jan_blaha

Ah ok, I submitted and issue to the backlog for this
https://github.com/jsreport/jsreport/issues/669

I think this workaround should work.

jsreport.express.server = null
jsreport.close()