Logging in NodeJS microservices

Hello everyone, in this blog I will share how you can configure logging in NodeJS so that it’s easy to filter/sort and get meaningful insights.

One thing more, I will not be sharing how you can pull these logs into log aggregator like Nagios, AWS CloudWatch, Splunk etc.

I will be taking an example for NodeJS/Express Framework. But first let’s discuss what things we need to consider before diving logging.

• Logging Format
• Logging destination
• Logging Fields

I will discuss above points in brief, so that we are all on same page.

Logging Format

we need to decide the format in which we will be generating our logs. Most commonly used format is string and Json. But I would suggest go ahead with JSON format as it allows us to add filtering and sorting very easily. JSON format also allows us to change log structure.

Note, some log aggregator gives you option to parse your string and then do filtering and sorting, but this will not be efficient as all log statement needs to be parsed by the pattern you provide and of course no way of adding index on these extracted fields.

Logging destination

we also need to decide on logging destination. Most commonly used destination are log files and console (standard output/error).

If your application standalone and does not need to integrate with log aggregator, then you can go ahead with this option, where logs reside in a file. But make sure to configure your logging in file so that it can truncate if log file becomes too heavy and also make sure you application has write permissions to log directory.

console log is by far the most flexible way of dumping your logs as you don’t have to manage file permission or manage log file size. application does its work and just forwards the logs to console and now it would be up to log aggregator/external tools to integrate these logs. You application is just responsible for its core execution rest will be handled by external application.

There is one more way, in which your application sends the log to external API, typically a log aggregator.

Logging Fields

This is one the most important thing to decide, basically what information you will be keeping in your log record. whatever log format you decide or whatever logging destination you finalized, you need to make sure your log has enough information so that it can filtered and sorted easily.

Few fields that each log record(row) should include are as follows.

• service/app name -> helps you segregate logs at applications/microservices level. eg “webapi”, “cronjob” etc.
• timestamp -> date/time when event/log was generated, helps you to sort your logs in order
• environment -> It helps you to segregate your logs based on environment. e.g., development, staging, UAT, Production etc.
• version -> if your application is running on multiple version, you can add this details as well to indentify log source with respect to code deployed. It could app version or git commit/hash.
• message -> log details added by your application.
• log level -> helps you to decide criticality of log message and allows you to create trigger for some failure as well. e.g., log level could be info, error, warning etc.
• request/transaction id -> helps you to decide separate logs from same application at each web Api request or for particular transaction id.

Once you have decided on all these things then we could start integrating logging in our NodeJS Express application. In NodeJS, you can use library called Winston. So, let’s see logger integration in Winston.

  
import winston, { info } from 'winston';
  import config from 'config';
  import os from 'os';
  const logger = winston.createLogger({
    level: 'info',
    format: winston.format.json(),
    defaultMeta: {
      service: 'ecommerce-web-api',
      version: 12,
      env: 'dev',
    },
    transports: [
      new winston.transports.Console(),
    ],
  });


  export default logger;

In above file, we configure our logs format(json), log destination(console) and few fields.

Now next we will see how this can integrated in Express framework.

app.use((req, res, next) => {
        let requestId;
        if (req.headers['x-request-id']) {
            requestId = req.headers['x-request-id'];
        } else {
            //client request-id not present, generate and add one
            requestId = uuid();
            req.headers['x-request-id'] = requestId;
        }
        req.logger = logger.child({ requestId: requestId });
        next();
        // TODO:: Add request-id back to response
    });

Above we have defined new middleware that will be applied to all routes. then we check if we have received any requestId in header, if not we generate a new one.

Next we create a child logger which would take all metadata that we defined in logger.ts and append requestId to it, so that all of our log records which are generated/created by web api endpoint would have it. you can now use this in all of the API endpoint.

Just one more thing to add, if you are using typescript this may give error that logger property does not exists for request object, to handle this you can update type definition of express request object to also include logger property of type winston logger. This would remove the error in your code editor and also give you the auto-completion and suggestion.

app.get("/ping", (req, res) => {
req.logger.info('received ping request')
res.status(200).json({ response: "pong" })
});

and once you hit the Ping API, you would received following log in your console.

{"service":"ecommerce-web-api","env":"dev", "version":12,"level":"info","message":"received ping request","requestId":"143f83dc-77b7-4c1f-a1ca-68f1e94130c8","timestamp":"2023-04-05T12:05:10.665Z"}

With this approach, you can also additional metadata as well, by adding new one more middleware. for e.g., you can also attach userId to your logger and this middleware can be added for all authentication web api endpoint.

This code structure also allows you add logs which are specific to request and also you can directly use logger object from logger.ts file which would include all details except requestId and userId

{"service":"ecommerce-web-api","env":"dev", "version":12,"level":"info","message":"server started listning on 8080 port","timestamp":"2023-04-05T12:05:10.665Z"}

This is quite a broad topic so I may not have covered everything here, please do ask your question in comment section.

Thanks for reading…