Full Stack (Node + Express + MongoDb + Vue + Nuxt) application. Part 3: Logging, initialization splitting and more helpers

Logging

Console logging is good, but it doesn’t cover all needs. Server could turn off instantly and you won’t see any messages, or there’s plenty errors and you have no time to read a single one, etc.
Let’s take a look for other logging variations.
There’s already good module to achieve different behaviours:

1	yarn add winston

Files, belong using for init our application and other nifty functions which require config will land into server/engine directory. Make sure to include it into your module aliases list:

1	"@engine": "./server/engine"

Lets make a new file logger.js with console output:

const winston = require('winston')

const config = require('@config')
const {env} = require('@helpers')

const transports = []

/**
 * Console transporter
 */
transports.push(new winston.transports.Console({
  level: config.logging.console.level,
  colorize: true,
  prettyPrint: true,
  handleExceptions: env.isProduction()
}))

// [before]

const logger = new winston.Logger({
  level: 'debug',
  transports: transports,
  exitOnError: false
})

// [after]

module.exports = logger

As you can see we’re using config.logging.console.level variable to define level of console logging. Let’s extend our config.template.js for logging:

logging: {
  console: {
    level: 'debug'
  }
}

We could redefine this level for some environments. For production we could use this:

logging: {
  console: {
    level: 'error'
  }
}

Further loggers require some additional packages to install, some config and init function which should be placed [before] or [after] logger init.

File [before]

packages:

1	yarn add mkdirp winston-daily-rotate-file

config:

file: {
  enabled: true,
  path: path.normalize(path.join(__dirname, '..', '..', 'logs')),
  level: 'info',
  json: false,
  exceptionFile: true
}

NB: you should add const path = require('path') at the begin of your config files if you use path.
init:

const path = require('path')
const fs = require('fs')
const mkdirp = require('mkdirp')
/**
 * File transporter
 */
if (config.logging.file.enabled) {
  // Create logs directory
  const logDir = config.logging.file.path
  if (!fs.existsSync(logDir)) {
    mkdirp(logDir)
  }

  transports.push(new (require('winston-daily-rotate-file'))({
    filename: path.join(logDir, 'server.log'),
    level: config.logging.file.level || 'info',
    timestamp: true,
    json: config.logging.file.json || false,
    handleExceptions: true
  }))

  if (config.logging.file.exceptionFile) {
    transports.push(new winston.transports.File({
      filename: path.join(logDir, 'exceptions.log'),
      level: 'error',
      timestamp: true,
      json: config.logging.file.json || false,
      prettyPrint: true,
      handleExceptions: true,
      humanReadableUnhandledException: true
    }))
  }
}

Logentries [before]

packages:

1	yarn add le_node

config:

logentries: {
  enabled: false,
  token: null
}

init:

/**
 * Logentries transporter
 * https://logentries.com/
 */
if (config.logging.logentries.enabled && config.logging.logentries.token) {
  console.log('Logentries log transport enabled!')
  require('le_node')
  transports.push(new winston.transports.Logentries({
    level: 'debug',
    token: config.logging.logentries.token
  }))
}

Papertrail [before]

packages:

1	yarn add winston-papertrail

config:

papertrail: {
  enabled: false,
  host: null,
  port: null,
  level: 'debug',
  program: 'vem'
}

init:

/**
 * Papertrail transporter
 * https://papertrailapp.com/
 */
if (config.logging.papertrail.enabled) {
  console.log('Papertrail log transport enabled!')
  // eslint-disable-next-line no-unused-expressions
  require('winston-papertrail').Papertrail
  transports.push(new winston.transports.Papertrail(config.logging.papertrail))
}

Loggly [after]

packages:

1	yarn add winston-loggly-bulk

config:

loggly: {
  enabled: false,
  token: null,
  subdomain: null,
  tags: [],
  json: true
}

init:

/**
 * Loggly transporter
 * https://www.loggly.com/
 */
if (config.logging.loggly.enabled && config.logging.loggly.token) {
  console.log('Loggly log transport enabled!')
  require('winston-loggly-bulk')
  logger.add(winston.transports.Loggly, {
    inputToken: config.logging.loggly.token,
    subdomain: config.logging.loggly.subdomain,
    tags: config.logging.loggly.tags,
    json: config.logging.loggly.json
  })
}

Logsene [after]

packages:

1	yarn add winston-logsene

config:

logsene: {
  enabled: false,
  token: null
}

init:

/**
 * Logsene transporter
 * https://sematext.com/logsene/
 */
if (config.logging.logsene.enabled && config.logging.logsene.token) {
  console.log('Logsene log transport enabled!')
  const logsene = require('winston-logsene')
  logger.add(logsene, {
    type: 'vem-server',
    token: config.logging.logsene.token
  })
}

Logz.io [after]

packages:

1	yarn add winston-logzio

config:

logzio: {
  enabled: false,
  token: null
}

init:

/**
 * Logz.io transporter
 * https://logz.io/
 */
if (config.logging.logzio.enabled && config.logging.logzio.token) {
  console.log('Logz.io log transport enabled!')
  const logzio = require('winston-logzio')
  logger.add(logzio, {
    token: config.logging.logzio.token
  })
}

Graylog [after]

packages:

1	yarn add winston-graylog2

config:

graylog: {
  enabled: false,
  servers: [{host: '192.168.1.100', port: 12201}],
  facility: 'MEVN'
}

init:

/**
 * Graylog transporter
 * https://www.graylog.org/
 */
if (config.logging.graylog.enabled) {
  console.log('Graylog log transport enabled! Servers: ' + JSON.stringify(config.logging.graylog.servers))
  let graylog = require('winston-graylog2')
  logger.add(graylog, {
    name: 'Graylog',
    level: 'debug',
    graylog: {
      servers: config.logging.graylog.servers,
      facility: config.logging.graylog.facility
    }
  })
}

Entry point

Our server/index.js intended for complete server init and have a lot of stuff to init to. Now there’s just express, sessions and nuxt init, but this file will grow. Best practice is split this file.
We already have an engine directory, so let’s move our express initialization into express.js file located in the engine directory:

const config = require('@config')
const {env} = require('@helpers')
const nuxtConfig = require('@/nuxt.config')

const express = require('express')
const session = require('express-session')
const cookieParser = require('cookie-parser')
const bodyParser = require('body-parser')
const {Nuxt, Builder} = require('nuxt')

/**
 * Initialize middlewares
 * @param {any} app
 */
function initMiddleware (app) {
  app.use(bodyParser.urlencoded({
    extended: true
  }))
  app.use(bodyParser.json())
  app.use(cookieParser())
  app.set('etag', true)
}

/**
 * Initialize session
 * @param {any} app
 */
function initSession (app) {
  app.use(session(config.session))
}

/**
 * Initialize Nuxt
 * @param {any} app
 */
function initNuxt (app) {
  nuxtConfig.dev = !env.isProduction()
  const nuxt = new Nuxt(nuxtConfig)
  if (nuxtConfig.dev) {
    new Builder(nuxt).build()
  }
  app.use(nuxt.render)
}

module.exports = () => {
  const app = express()

  initMiddleware(app)
  initSession(app)
  initNuxt(app)

  return app
}

server/index.js:

require('module-alias/register')
const app = require('@engine/express')()

app.listen(3000, () => {
  console.log(`Application was started at the 3000th port`)
})

exports = module.exports = app

It looks much better now, isn’t it?
We also split our middlewares just for make sure we’re using it in right order.

Express extras

First of all, lets define ip and port in our configs:

1 2	ip: process.env.NODE_IP \|\| '0.0.0.0', port: process.env.NODE_PORT \|\| 3000

Now we could add little bit more logging information on server start:

require('module-alias/register')
const config = require('@config')
const logger = require('@engine/logger')

const chalk = require('chalk')
const moment = require('moment')

const app = require('@engine/express')()

logger.info(chalk.bold('-----------------[ Server starting at %s ]-----------------'), moment().format('YYYY-MM-DD HH:mm:ss.SSS'))

app.listen(config.port, config.ip, () => {
  logger.info('----------------------------[ Application started! ]----------------------------')
  logger.info(`Environment:\t${chalk.underline.bold(process.env.NODE_ENV)}`)
  logger.info(`IP:\t\t\t${config.ip}`)
  logger.info(`Port:\t\t\t${config.port}`)
  logger.info('--------------------------------------------------------------------------------')
})

exports = module.exports = app

Compression

This package will compress server response.

1	yarn add compression

Include this into middlewares list of express.js:

const compress = require('compression')
...
function initMiddleware (app) {
  app.use(compress({
    filter: (req, res) => {
      return /json|text|javascript|css/.test(res.getHeader('Content-Type'))
    },
    level: 3,
    threshold: 512
  }))
  ...
}

Morgan

It’s usefull to know what requests your server got. That’s why I recommend to include morgan:

1	yarn add morgan

express.js:

const logger = require('@engine/logger')
const morgan = require('morgan')
...
function initMiddleware (app) {
  ...
  if (env.isDev()) {
    const Stream = require('stream').Stream
    const mlStream = new Stream()
    mlStream.writable = true
    mlStream.write = data => {
      return logger.debug(data)
    }
    app.use(morgan('dev', {
      stream: mlStream
    }))
  }
}

This config using our winston logger for morgan.

Helmet

This little middleware adds some protection for requests to prevent some attacks.

1	yarn add helmet

const helmet = require('helmet')
...
/**
 * Initiliaze Helmet security module
 * @param {any} app
 */
function initHelmetHeaders (app) {
  app.use(helmet.xssFilter())
  app.use(helmet.noSniff())
  app.use(helmet.frameguard())
  app.use(helmet.ieNoOpen())
  app.use(helmet.hidePoweredBy())
}
...
module.exports = () => {
  const app = express()

  initMiddleware(app)
  initHelmetHeaders(app)
  initSession(app)
  initNuxt(app)

  return app
}

Extra helpers

Safe stop

For further work we have to be sure server stopped correctly, all connections closed, etc. So let’s make new helper safeStop.js:

const logger = require('@engine/logger')

const chalk = require('chalk')
const moment = require('moment')

const smoothExit = async () => {
  const exit = () => {
    logger.info()
    logger.info(chalk.bold('------[ Server stopped at %s Uptime: %s ]------'), moment().format('YYYY-MM-DD HH:mm:ss.SSS'), moment.duration(process.uptime() * 1000).humanize())
    return process.exit(0)
  }
  return exit()
}

process.on('SIGINT', smoothExit).on('SIGTERM', smoothExit)

And call this in the server/index.js before app.listen:

1
2
3

require('@helpers/safeStop')
...
app.listen(...)

System info

Let’s print information about system where server started. Make sysinfo.js helper.
It require some additional packages:

1	yarn add clui pretty-bytes

server/helpers/sysinfo.js:

const logger = require('@engine/logger')

const os = require('os')
const gauge = require('clui').Gauge
const pretty = require('pretty-bytes')

const total = os.totalmem()
const free = os.freemem()
const used = total - free
const human = pretty(free)

logger.info(`CPU:\t\t\tArch: ${os.arch()}, Cores: ${os.cpus().length}`)
logger.info(`Memory:\t\t${gauge(used, total, 20, total * 0.8, human + ' free')}`)
logger.info(`OS:\t\t\t${os.platform()} (${os.type()})`)

And call him after server start inside app.listen:

app.listen(..., () => {
  ...
  require('@helpers/sysinfo')
  logger.info('--------------------------------------------------------------------------------')
})

This part wraps up 03-logging-split-extras git branch.

← Full Stack (Node + Express + MongoDb + Vue + Nuxt) application. Part 2: Helpers, Configs and Session Full Stack (Node + Express + MongoDb + Vue + Nuxt) application. Part 4: MongoDb →