How to enable logging for Mongoose and the MongoDB Node.JS driver

Collecting detailed logs is a critical step when debugging connection related issues with MongoDB. In this short post, we will show how to enable logging on the MongoDB Node.JS driver and Mongoose. We refer to the Mongoose version 5.x and the driver version 3.5 in this discussion.

Logging the MongoDB Node.JS Driver

The logging mechanism for the native driver is explained well in the logging documentation. Essential features are:

  • There are 3 log levels – debug, info, warn and error. The default is error. info is a decent choice when attempting to debug issues. debug enables extremely detailed tracing, so use that only when the logs generated at the info level are not enough.
  • By default logs go to console.log()

Setting the log level

In code

const MongoClient = require('mongodb').MongoClient;
const Logger = require('mongodb').Logger;
Logger.setLevel('info');

When setting the log level in code, you can also add filters for specific classes. E.g.

Logger.filter('class', ['Connection', 'Pool']); // Log only Connection and Pool create things

Via options

The logger and logLevel can also be passed via connection options, we show you an example in the Mongoose section.

Logging for Mongoose

Enabling debug level logging for Mongoose is simple:

mongoose.set('debug', true)

However, this only enables logging of MongoDB operations like queries and updates. If you are looking to debug issues related to the connection, connection pool, etc, then this is of no help.

On the other hand, since Mongoose utilizes the MongoDB Node.JS driver underneath, if we enable logging for the driver, we will be able to obtain logs from the driver as well. The easiest way to do this is to pass log related options. E.g.

// logging options for the driver
var options = {
    logger: console.log,
    loggerLevel: 'info',
    poolSize: 10
}

var uri = 'mongodb://user:pass@localhost:port,anotherhost:port,yetanother:port/mydatabase';
// with options
mongoose.connect(uri, options);

Except the Mongoose specific options, Mongoose passes all the other options down to the driver. The driver documentation explains the following options:

  • loggerLevel – string – optional – The logging level (error/warn/info/debug)
  • logger – object – optional – Custom logger object

In the example above, we pass the loggerLevel as info and the logger as console.log.

How to enable logging for Mongoose and the MongoDB Node.JS driverClick To Tweet

Custom Logger

Even though the driver documentation provides an example on writing custom loggers, it isn’t very useful. Usually, we would try to send these logs to a different file, away from the standard application logs and we can use the custom logger functionality to be able to do that.

If you look at the logging source code of the driver, the following becomes clear:

  • Default logger is theconsole.log
  • The logger must be a function
  • The logger function takes two arguments:
    • The message string in the format as follows:
      [LEVEL-className:pid] timestamp logMsg

      For example:

      [INFO-Server:9224] 1589439590772 server sg-example-100.servers.scalegrid.io:27017 fired event error out with message {"name":"MongoNetworkError"}
    • A state object which contains the following information:
      var state = {
        type: 'warn', // level
        message: message, // log message
        className: className, // className
        pid: pid,
        date: dateTime
      };

      For example:

      {
         type: 'info',
        message:
         'server sg-rs-91.servers.scalegrid.io:27017 fired event error out with message {"name":"MongoNetworkError"}',
         className: 'Server',
         pid: 9224,
         date: 1589439590772
      }
      

So, in order to write a custom logger, you can simply write a function to use a logging framework of your choice to log these messages in a format that you wish.

Here is a fairly primitive Bunyan logger set up as a custom logger:

var Logger = require('bunyan');
var log = Logger.createLogger({
  name: "MongoDB Driver",
  streams: [
  {
    stream: process.stdout,
    level: 'info'
  },
  {
      stream: process.stdout,
      level: 'debug'
  },
  {
      stream: process.stderr,
      level: 'error'
  }
  ],
});
 
function mongoLogger(msg, state) {
  // console.log(msg, state);
 
  switch (state.type) {
    case 'debug':
      log.debug(state);
      break;
    case 'info':
      log.info(state);
      break;
    case 'warn':
      log.warn(state);
    case 'error':
    default:
      log.error(state);
  }
}

Then pass it in your options:

var options = {
  logger: mongoLogger,
  loggerLevel : 'info'
}

The output from console.log will then be:

[INFO-Server:9413] 1589442507330 server SG-example-85.servers.scalegrid.io:27017 fired event close out with message {"name":"MongoNetworkError","message":"getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017","stack":"Error: getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017\n	at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:56:26)"} { type: 'info',
  message:
   'server SG-example-85.servers.scalegrid.io:27017 fired event close out with message {"name":"MongoNetworkError","message":"getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017","stack":"Error: getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017\\n	at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:56:26)"}',
  className: 'Server',
  pid: 9413,
  date: 1589442507330 }

The Bunyan output will be:

{"name":"MongoDB Driver","hostname":"<hostname>","pid":9413,"level":30,"type":"info","message":"server SG-example-85.servers.scalegrid.io:27017 fired event close out with message {\"name\":\"MongoNetworkError\",\"message\":\"getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017\",\"stack\":\"Error: getaddrinfo ENOTFOUND SG-example-85.servers.scalegrid.io SG-example-85.servers.scalegrid.io:27017\\n	at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:56:26)\"}","className":"Server","date":1589442507330,"msg":"","time":"2020-05-14T07:48:27.331Z","v":0}

You will then be able to use all the features of Bunyan to deal with the logs as you see fit e.g. sending them to a rotating file, separating out error and info messages etc.

We hope this guide on enabling logging on the MongoDB Node.JS driver and Mongoose has been helpful for you in your setup. Feel free to leave a comment in the comment section below if you have any questions or need any help.


Vaibhaw is a Member of the Technical Staff at ScaleGrid.io (Formerly MongoDirector). You can reach out to him at @_vaibhaw


0 Shares
+1
Tweet
Share
Share
Pin