createRollingFileLogger() makes my app to hang

[HRK44]

trafficstars

I'm writing a node CLI app, let's call it toto.js

When I use the createSimpleLogger and execute my app

toto start

It runs it perfectly, create the log files + console logs and terminate the app.

When I switch to createRollingFileLogger, it creates the logs inside the file - no console logs -, execute the app, but doesn't exit the app anymore, it just hangs and I have to CTRL+C to terminate the app.

Any ideas on why?

Here's the config I use for both loggers :

{
    "dfltLevel": "info",
    "timestampFormat": "YYYY-MM-DD HH:mm:ss.SSS",
    "logDirectory": "logs",
    "fileNamePattern": "test_<DATE>.log",
    "dateFormat": "YYYY-MM-DD"
}

[p-g-krish]

Please check the open files, in my case same file open many times. Hence it will lead to handup of your app

[pbbadenhorst]

Not sure if this is related but this code creates an interval that kept mocha from exiting cleanly. I cannot find a place where clearInterval(rollTimer) is being called. It is created here in the RollingFileAppender:

     const startRollTimer = function() {
        rollTimer = createInterval(function() {
            if (appender.checkForRoll()) {
                openWriter();
            }
        }, 60 * 1000);
    };

I needed to add this method to my LogManager wrapper. It is a workaround, but it does allow my mocha tests to complete without the --exit argument:

    close() {
      (manager.getAppenders()).forEach(appender => {
        if (appender.__protected) {
          let rollTimer = appender.__protected()['rollTimer']
          if (rollTimer) {
            clearInterval(rollTimer)
          }
        }
      })
    }

Maybe the write method can be changed to do the logic of the roll checks instead of using an interval check? Something like below:

(I would also add a back off to checkForRoll so the file name changes are checked only once each minute like in the interval function)?

    /**
     * call formatter then write the entry to the console output
     * @param entry - the log entry
     */
    this.write = function(entry) {
        if (levels.indexOf( entry.level ) >= currentLevel) {
            if (appender.checkForRoll()) {
                openWriter();
            }
            const writer = getWriter();
            if (writer) {
                writer.write( appender.formatter( entry ) );
            } else {
                /*eslint no-console: "off"*/
                console.log( 'no writer...' );
            }
        }
    };

[nekdev]

This makes it unusable for CLI scripts, especially for scripts aimed for cron jobs.

const SimpleNodeLogger = require('simple-node-logger');

const log = SimpleNodeLogger.createRollingFileLogger({
  logDirectory: './logs',
  fileNamePattern: `test-<DATE>.log`
});

log.info('this is a simple info log statement/entry');
log.warn('this is a simple warn log statement/entry');
log.error('this is a simple error log statement/entry');
log.trace('this is a simple trace log statement (should not show)');
log.debug('this is a simple debug log statement (should not show)');
log.fatal('this is a simple fatal log statement/entry');

// EDIT: This will end the process and it will write to the log file
setTimeout(() => process.exit(0), 1000);

The process hangs and even process.exit() or process.nextTick(() => process.exit()) aren't a workaround because it writes nothing to the file if the process ends manually.

EDIT

At the examples, I can see in the https://github.com/darrylwest/simple-node-logger/blob/master/examples/rolling-logger.js#L27 there is an one second timeout that exists the process, so, I assume this is intended behaviour. It's inconvenient, but it works.

EDIT

@pbbadenhorst the closemethod you have works pretty well. I cloned this and created a npm package (@lytrax/simple-node-logger) with that close method, so, we can close the logger and end the timer like this log.close().