logger implementation using winston , morgan and winston-daily-rotate-file

Question

I am trying to implement a logger in node js which will create a new log file every day on a custom format for logs

for this i have used three packages

1. winston
2. morgan
3. winston-daily-rotate-file

so the final output should every day a new log file should create in logs folder and it should log all the http(morgan logs) and typed logs (winston logs) into a single file in the below format

Date || Filename || statusCode || logMessage || uuid (for tracing)

eg: Fri Jan 18 2019 13:48:18 GMT+0530 (IST) || [index.js] || 200 || calling the new route || 287dccb0-1afa-11e9-88a0-dfb1c665be9d

so for this i have written three files index.js(root file of nodejs) logger.js(logger implementation and configuration) and logger.test.js(test cases for logger using jest)

additional packages

1. cors
2. uuid
3. http-context
4. app-root-path
5. express-http-context
6. jest

the problems that i have

1. if i put a logger.error({message: {statusCode:200, logMsg: "the server will be starting in port 3000"}}) in the index.js on app.listen before to console.log() the uuid is null
2. the test cases that i have written is wrong, i am new to jest i just want to know how can i check all that cases.
3. why when i test the suits uuid is null, how can i pass the uuid for test cases also
4. how can i check whether new folder will be created and if already logs folder are there new file is created kind of test cases.
5. How can i add other levels , info, debuge , warn based on the env. How can i improve this code to implement the logger functionality

// index.js

const app = require('express')();
const cors = require('cors')
const morgan = require('morgan') // HTTP request logger middleware 
const logger = require('./config/logger')(module) //Logger
const uuid = require('uuid')
const httpContext = require('express-http-context')

// Use any third party middleware that does not need access to the context here
// app.use(some3rdParty.middleware);

app.use(httpContext.middleware);
// all code from here on has access to the same context for each request

// Run the context for each request.
// Assigning a unique identifier to each request
app.use((req, res, next) => {
  httpContext.set('reqId', uuid.v1());
  next()
})


// using morgan with winston(logger)
app.use(morgan('combined', {
  stream: {
    write: (message) => logger.error(message)
  }
}))


app.use(cors());

app.use("/new", (req, res) => {
  logger.error({
    message: {
      statusCode: 400,
      logMsg: "hitting new route"
    }
  })
  nextLayer(res)
})

const nextLayer = (res) => {
  logger.error({
    message: {
      statusCode: 400,
      logMsg: "hitting in nextLayer function"
    }
  })
  res.send("OK")
}

app.listen(4000, () => {
  console.log('Server running on port 4000');
})





// Logger.js

const appRoot = require('app-root-path')
const {
  createLogger,
  format,
  transports
} = require('winston')
const {
  combine,
  timestamp,
  label,
  printf
} = format
const path = require('path')
require('winston-daily-rotate-file');
const httpContext = require('express-http-context')

/**
 * @method checkMessageProp
 * @param {message} can be object if developer defined, else it will be string
 *                  if its a network request
 * @returns a fixed format how the status code and message should show
 */
const checkMessageProp = (message) => {
  switch (typeof message) {
    case "object":
      const {
        statusCode,
        logMsg
      } = message
      return `${statusCode ? statusCode : "Not Defined"} || ${logMsg ? logMsg : "Not Defined"}`;
    case "string":
      let messageSplit = message.split(`"`)
      var message = messageSplit ? `${messageSplit[2].trim().split(" ")[0]} || ${messageSplit[1]}` : null
      return message
    default:
      return message
  }
}

/**
 * @method customFormat
 * @param {log} the log passed by the developer or based on network requests
 * @returns a customFormat how it should be logged to the log files
 */
const customFormat = printf(log => {
  const now = new Date();
  const reqId = httpContext.get('reqId');
  return `${log.timestamp ? new Date(log.timestamp) : now} || [${log.label}] || ${checkMessageProp(log.message)} || ${reqId ? reqId : null}`
});

/**
 * @method getFileName
 * @param {moduleObj} the module realted object passed from the require of logger file 
 * @returns the file name where the logger was invoked
 */
const getFileName = moduleObj => {
  if (Object.keys(moduleObj).length > 0) {
    let parts = moduleObj.filename.split(path.sep)
    return parts.pop()
  } else {
    return "Module not passed while requiring the logger"
  }
}

// Custom settings for each transport 
const options = moduleObj => {
  return {
    dailyRotateFile: {
      filename: `${appRoot}/logs/TPS-UI-%DATE%.log`,
      datePattern: 'YYYY-MM-DD',
      prepend: true,
      level: "error",
      timestamp: new Date(),
      localTime: true
    }
  }
}

// Instantiate a Winston Logger with the settings
let logger = moduleObj => {
  return createLogger({
    format: combine(
      label({
        label: getFileName(moduleObj)
      }),
      customFormat
    ),
    transports: [
      new transports.DailyRotateFile(options(moduleObj).dailyRotateFile)
    ],
    exitOnError: false // do not exit on handled exceptions
  })
}



module.exports = logger








// logger.test.js

const logger = require('./logger')

beforeEach(() => {
  mockLoggerMessageObject = {
    message: {
      statusCode: 400,
      logMsg: "Calling in test suite"
    }
  }
  mockLoggerMessageString = `::ffff:127.0.0.1 - - [18/Jan/2019:04:50:57 +0000] 
                               "GET /new HTTP/1.1" 200 2 "http://localhost/" "Mozilla/5.0 
                               (linux) AppleWebKit/537.36 (KHTML, like Gecko) jsdom/11.12.0"`
  mockLoggerMessageNumberFormat = 123
  mockLoggerMessageArrayFormat = ["data", "test", 123]
})

describe(`Logger test cases`, () => {
  test('should invoke the logger function with the mock Logger message object', () => {
    expect(logger(module).error(mockLoggerMessageObject)).toBeDefined()
  })
  test(`should invoke the logger function with empty object`, () => {
    expect(logger(module).error({})).toBeDefined()
  })
  test(`should invoke the logger function without any module object`, () => {
    expect(logger({}).error(mockLoggerMessageObject)).toBeDefined()
  })
  test(`should invoke the logger function without any module and message object`, () => {
    expect(logger({}).error({})).toBeDefined()
  })
  test(`should invoke the logger function with the http request`, () => {
    expect(logger(module).error(mockLoggerMessageString)).toBeDefined()
  })
  test(`should invoke the logger function with the number format`, () => {
    expect(logger(module).error(mockLoggerMessageNumberFormat)).toBeDefined()
  })
  test(`should invoke the logger function with the array format`, () => {
    expect(logger(module).error(mockLoggerMessageArrayFormat)).toBeDefined()
  })

})

Answer 1

for winston i'm using timestamp(), like this it will automatically add timestamp() property to the object

const {transports, createLogger, format} = require('winston');
const logger = createLogger({
        format: format.combine(
            format.timestamp(),
            format.json()
        ),

Also to check if it creates file you can mock date, to say 2019-01-01 and check is it create file 2019-01-01.log than move date to 2019-01-02 and log something else. Winston will create new folder and gzip archive and you can check is file exists and can be unzipped and contains information

Try to read winston's documentation. Basically i would say that you may need to use

format.timestamp()
format.json()
colorize()

dailyRotate with zippedArchive:true

If morgan doesn't suits your needs you can try to log directly in

app.use((req, res, next) => { 
    logger.silly({ message:'start', req,res}); 

    return next().then(r=>logger.silly({ message:'end', req,res}; return r;);
}