sessionwinstonmorgan

Passing a unique session ID to Winston logger


I am trying to figure out if there is a way to use a unique (per request) session ID in all of the winston logger calls when an HTTP request is made.

Elaboration on the issue:

Given a scenario that several hundred requests hit a website per minute and each request passes through different functions which log out various messages.

My goal is to log messages including a unique session ID per request using winston logger, until the response is sent.

I generate a unique session ID for the request using app.use(session(...)) from express-session library.

Using morgan, the HTTP logs are printed with a unique session ID like so:

logger = winston.createLogger(...);

const myStream = {
  write: (text: string) => {
    logger.info(text);
  }
}

morgan.token('sessionid', function (req, res) { return req['sessionID'] });
app.use(morgan(':remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent"  ["SESSION_ID :sessionid"]', { stream: myStream }));

However, I also want to use the same session ID in other logger.* functions elsewhere in the code. I am able to do that but as the number of simulataneous requests (using k6 load test) increases, the session ID gets overwritten by a new session ID of another request.

My code for using the session ID in request in a winston transport is:

public static initializeLogger(appInstance: express.Application) {

        if (!appInstance) throw new Error(`Cannot initialize logger. Invalid express.Application instance passed. Logging may not be available`);
        
        appInstance.use((req, res, next) => {
            //this.m_sessionID = req["sessionID"];
            this.m_logger.clear();
            this.m_logger = winston.createLogger({
                level: LOG_LEVEL,
                levels: winston.config.syslog.levels,
                format: winston.format.json(),
                transports: [
                    new winston.transports.Console({ format: winston.format.simple() }),
                    new winston.transports.File({ filename: 'error.log', level: 'error' }),
                    new winston.transports.File({ filename: 'debug.log', level: 'debug' }),
                    new WinstonCloudWatch({
                        logGroupName: CLOUDWATCH_LOG_GROUP_NAME,
                        logStreamName: function () {
                            let date = new Date().toISOString().split('T')[0];
                            return 'k-server-logs-' + date;
                        },
                        awsRegion: AWS_REGION,
                        awsAccessKeyId: process.env.AWS_ACCESS_KEY_ID,
                        awsSecretKey: process.env.AWS_SECRET_ACCESS_KEY,
                        retentionInDays: process.env.CLOUDWATCH_LOG_RETENTION_DAYS ? Number(process.env.CLOUDWATCH_LOG_RETENTION_DAYS) : 30,
                        messageFormatter: (log) => {
                            return `${JSON.stringify({
                                message: log.message,
                                sessionID: req["sessionID"],
                                level: log.level
                            })}`
                        }
                    })
                ],
            });
            next();
        });
    }

I was hoping putting the winston logger in app.use(...) middleware would set up the cloudwatch transport for the winston logger along with using the req.sessionID as each request comes in.

However, this setup isn't working. If I send even 10 simultaneous requests, this code breaks and the sessionID is incorrectly stamped on logger.* messages and/or duplicated across multiple messages.

I reviewed other implementations such as https://solidgeargroup.com/en/express-logging-global-unique-request-identificator-nodejs/ but could not get it to work.

Hoping for some advice - I am sure my setup is off.

Thank you in advance.


Solution

  • Key hint from https://solidgeargroup.com/en/express-logging-global-unique-request-identificator-nodejs/

    Use express-http-context which has a set and get function that will ensure that the unique session ID is available throughout your code.

    import httpContext from 'express-http-context';
    ...
    ...
    logger.add(new WinstonCloudWatch({
                    level:LOG_LEVEL,
                    logGroupName: CLOUDWATCH_LOG_GROUP_NAME,
                    logStreamName: function () {
                        let date = new Date().toISOString().split('T')[0];
                        return `${process.env.CLOUDWATCH_LOG_FILE_NAMEPREFIX}-logs-${date}`;
                    },
                    awsRegion: AWS_REGION,
                    awsAccessKeyId: process.env.AWS_ACCESS_KEY_ID,
                    awsSecretKey: process.env.AWS_SECRET_ACCESS_KEY,
                    retentionInDays: process.env.CLOUDWATCH_LOG_RETENTION_DAYS ? Number(process.env.CLOUDWATCH_LOG_RETENTION_DAYS) : 30,
                    messageFormatter: (log) => {
                        return `${JSON.stringify({
                            message: log.message,
                            **sessionID: httpContext.get('reqId')**,
                            level: log.level
                        })}`
                    }
    }));