Nodejs / Express / Winston logger: how to elegantly put req.headers.username in log format?

Question

My nodejs / Express js backend is using Winston logger.

src/utils/logger.ts:

import winston from 'winston'
import moment from 'moment';
import os from 'os';
import process from 'process';
import request from 'express';


const levels = {
  error: 0,
  warn: 1,
  info: 2,
  http: 3,
  debug: 4,
}

const level = () => {
  return 'debug'
}

const colors = {
  error: 'red',
  warn: 'yellow',
  info: 'green',
  http: 'magenta',
  debug: 'white',
}
winston.addColors(colors)

const timezonedTime = () => {
  return moment().local().format('YYYY-MMM-DD hh:mm:ss:ms');  
}; 
   

const format_string = winston.format.combine(
  winston.format.timestamp({format: timezonedTime}),
  winston.format.colorize({ all: true }),
  winston.format.printf(
    (info) => `${info.timestamp}  ${os.hostname()} ${process.pid} ${info.level}: ${info.message}`,
  ),
)

const format_json = winston.format.combine(
  winston.format.timestamp({format: timezonedTime}),
  winston.format.colorize({ all: true }),
  winston.format.printf(
    (info) => `${info.timestamp}  ${os.hostname()} ${process.pid} ${info.level}: ${info.message}`,
  ),
  winston.format.json(),
)


const options = {
  conosle: {
    format: format_string,
    level: 'info',
    handleExceptions: true,
    json: false,
    colorize: true,
  },

  error_logfile: {
    filename: 'logs/error.log',
    level: 'error',
    format: format_string,
    handleExceptions: true,
  }, 

  all_logfile: { 
    filename: 'logs/all.log', 
    format: format_string 
  },

  all_logfile_json: { 
    filename: 'logs/all_json.log',
    format: format_json
  }

};

const transports = [
  new winston.transports.Console(options.conosle),
  new winston.transports.File(options.error_logfile),
  new winston.transports.File(options.all_logfile),
  new winston.transports.File(options.all_logfile_json),
]

const Logger = winston.createLogger({
  level: level(),
  levels,
  transports,
})

export default Logger

My app is designed such that as long as a user has logged into his account, the request header will contain a username field.

I want to put this username into every log message caused by functions in the api endpoints. Right now I'm doing:

/src/routes.ts:

app.get('/api/organizations/project', organizations.getProject); 

And:

export const getProject = catchErrors( async (req, res) => {

  const username = req.header('username');
  if (!username) {
    Logger.warn(`no req.headers.username found!`);
    throw new NoUsernameError();
  }


  const user = await findUserWithOrganizationsByUsername(username);
  const userId = user.id; 
  const userType = user.userType; 
  Logger.info(`User ${req.headers.username} has id and type ${userId}, ${userType};`);


  const organizationId = req.query.organizationId; 
  
  const organization = await findEntityOrThrow(Organization, organizationId, {
    relations: ['users']
  });

  Logger.info(`User ${req.headers.username}:  got organization`);


  ...

Basically in many steps in the business logic code, I need to log a message with req.headers.username in it, just like level and timestamp are in all log entries.

Is there an elegant way to put it in? I don't want to do

Logger.info(`User ${req.headers.username}  ....bla bla bla ... `);

in every logger line.

Answer 1

To add something to every log event use defaultMeta (from the Winston docs):

const winston = require('winston');

const logger = winston.createLogger({
  level: 'info',
  format: winston.format.json(),
  defaultMeta: { service: 'user-service' },
  transports: [
    //
    // - Write all logs with importance level of `error` or less to `error.log`
    // - Write all logs with importance level of `info` or less to `combined.log`
    //
    new winston.transports.File({ filename: 'error.log', level: 'error' }),
    new winston.transports.File({ filename: 'combined.log' }),
  ],
});

To add additional context to a subset of log events, use a child logger:

const childLogger = logger.child({ requestId: '451' });
childLogger.info('This log will have an attached requestId');