How to add uuid in every winston log node js per request?

Question

I am using winston logger. I want to add uuid in every logs having same uuid per request.

In app.js

var distributorapp = require('./routes/distributorapp');
app.use('/dstapp',distributorapp);

In routes/distributorapp.js(Middleware)

var qs = require('querystring');
var request = require('request');
var logger = require('../locallibs/logger');
var uuid = require('uuid/v1');
module.exports = {
    mddlw: function (req, res, next) {
        req.bodyData = qs.parse(req.body); // parsing body and added to request object
        req.uuid = uuid(); // Adding uuid to request to available every where throught request
        callHsmRest(req, res); // function to do some logic and handle middleware functionality
    }
};

In logger.js

var winston = require('winston');
var fs = require('fs');
var moment = require('moment');
var today = moment().format('YYYY-MM-DD');

if (!fs.existsSync(today)) {
    fs.mkdirSync(today);
}


function customFileFormatter(options) {
    console.log(options);
    return options.timestamp() + ' [' + options.level.toUpperCase() + '] ' + (undefined !== options.message ? options.message : '') +
            (options.meta && Object.keys(options.meta).length ? JSON.stringify(options.meta) : '');
}

var logger = new (winston.Logger)({
    transports: [
        new (winston.transports.File)({
            timestamp: function () {
                return moment().format();
            },
            json: false,
            filename: today + '/test.log',
            formatter: customFileFormatter
        })
    ]
});

Now in every request I want to generate uuid and add it to request body.So I have added in Middleware.But how it will be available to logger.js in customFileFormatter formatter function?

When some one uses this logger to log any data i want that uuid to be prepended in logger formatter in every logs through request.

If some one require logger.js and do

logger.info("Hello");
logger.info("Hi");

Currently following I have following logs

2017-02-24T12:36:23+05:30 [INFO] "Hello"
2017-02-24T12:36:23+05:30 [INFO] "Hi"

But I want

2017-02-24T12:36:23+05:30 [INFO] c00d6800-fa5f-11e6-83c2-f531bfc95472 "Hello"
2017-02-24T12:36:23+05:30 [INFO] c00d6800-fa5f-11e6-83c2-f531bfc95472 "Hi"

---

Also I want to change logger file path according to route middleware.

Currently when request came from /dstapp it uses distributorapp Middleware and every subsequent logs from this request goes to path dstapp/2017-02-24/test.log
But when request came from lets say /anotherapp it uses anotherapp Middleware and subsequent logs from this request goes to path anotherapp/2017-02-24/test.log

I have searched through every where but can't find any solution Thanks in Advance

Answer 1

Use logFormatter from winston to add more fields to each logs:-

One example below for adding reqId to each logger:

const { format} = require("winston");
var reqId = '123123' //use your uuid generator function here
const addRequestId = format((info, opts) => {
    if(reqId)
        info.reqId= reqId;
    return info;
});

Then add below config while creating log

var config = {
format: format.combine(
  addRequestId(),
  format.timestamp(new Date().toISOString()),
  format.json(),
),
transports: [new transports.Console()],
level: 'debug'
 }
const logger = createLogger(config);

Be aware that, when multiple requests occur simultaneously, reqId may be overwritten. This is only suitable for low volume applications. To prevent this problem, you need to use classes to create a separate container for each request flow. Use the parent class as a space to store the reqId that can be accessed by the logger. Not advisable for existing applications.

Answer 2

Take a look at AsyncLocalStorage (https://nodejs.org/api/async_hooks.html#async_hooks_class_asynclocalstorage), it requires Node.js 12.17.0+, 13.14.0+, or 14.0.0+.

A package which uses this under the hood is: CLS-RTRACER (https://github.com/puzpuzpuz/cls-rtracer)

It helped me a lot!

Answer 3

I had to face this same problem. I found out a solution using node-uuid library to generate a unique uuid for each request, and continuation-local-storage library to share information among modules.

1º. I added a middleware functionality to create the uuid for each request and add it to the namespace I had created:

var uuid = require('node-uuid');
var createNamespace = require('continuation-local-storage').createNamespace;
var myRequest = createNamespace('my request');

// Run the context for each request. Assign a unique identifier to each request
app.use(function(req, res, next) {
    myRequest.run(function() {
        myRequest.set('reqId', uuid.v1());
        next();
    });
});

2º. I wrapped winston library to print get the id of the request and add it to every log, something like this:

var winston = require('winston');
var getNamespace = require('continuation-local-storage').getNamespace;

// Wrap Winston logger to print reqId in each log
var formatMessage = function(message) {
    var myRequest = getNamespace('my request');
    message = myRequest && myRequest.get('reqId') ? message + " reqId: " + myRequest.get('reqId') : message;
    return message;
};

var logger = {
    log: function(level, message) {
        winstonLogger.log(level, formatMessage(message));
    },
    error: function(message) {
        winstonLogger.error(formatMessage(message));
    },
    warn: function(message) {
        winstonLogger.warn(formatMessage(message));
    },
    verbose: function(message) {
        winstonLogger.verbose(formatMessage(message));
    },
    info: function(message) {
        winstonLogger.info(formatMessage(message));
    },
    debug: function(message) {
        winstonLogger.debug(formatMessage(message));
    },
    silly: function(message) {
        winstonLogger.silly(formatMessage(message));
    }
};
module.exports = logger;

With this 2 pieces of code you get it.

To make it easier, I created a library that implements all this, and you can use it as winston, without being worried about all this stuff: https://github.com/davicente/express-logger-unique-req-id

If you want to get into it a little bit more, you can take a look to this article: https://solidgeargroup.com/express-logging-global-unique-request-identificator-nodejs

Answer 4

I have found way around for this.

In app.js

var logger = require('./locallibs/logger');
app.use(logger)
app.use('/dstapp',distributorapp);

My logger.js

var winston = require('winston');
var fs = require('fs');
var moment = require('moment');
var today = moment().format('YYYY-MM-DD');
var uuid = require('uuid/v1');
if (!fs.existsSync(today)) {
    fs.mkdirSync(today);
}


function customFileFormatter(options) {
    return options.timestamp() + ' [' + options.level.toUpperCase() + '] ' + uuid() + ' ' + (undefined !== options.message ? options.message : '') +
            (options.meta && Object.keys(options.meta).length ? JSON.stringify(options.meta) : '');
}

winston.remove(winston.transports.Console);
winston.add(winston.transports.File,
        {
            timestamp: function () {
                return moment().format();
            },
            json: false,
            filename: today + '/test.log',
            formatter: customFileFormatter
        }
);

module.exports = function (req, res, next) {
    next()
};

In any file

var logger = require('winston');
logger.info("First Log");
logger.info("Second Log");

Output is

2017-02-24T18:51:39+05:30 [INFO] 2cf92c90-fa94-11e6-83ba-ebaf5a4e7acd First Log
2017-02-24T18:51:39+05:30 [INFO] 2cf9c8d0-fa94-11e6-83ba-ebaf5a4e7acd Second Log

Answer 5

I did something similar with ES6 Proxy. In middleware I generate unique requestId and add it to app.locals. Then in logger.js I added proxy handler for log functions:

let logProxyHandler = {
    apply (target, thisArg, args) {
        var app = getApp(),
            id = '';
        // Some requests do not have unique ID  
        if (app && app.locals && app.locals.requestId) {
            id = `[${app.locals.requestId}]`;
        }
        args[0] = `${id} ${args[0]}`;
        return Reflect.apply(target, thisArg, args);
    }
}

And then add this:

logger.info = new Proxy(logger.info, logProxyHandler)