src: replace winston logger with pino logger

PR-URL: #44

README.md

@@ -72,8 +72,9 @@ PORT_DEV=<port number> # browser-sync listeing port; default is 3000
 At `env` section in `process.yml` are environment variables that will override `.env.json` for running in production environment.
 
 ### Environment Variables
-- LOGGER_SILENT: if `false` enables log, `true` disables log
-- LOGGER_LEVEL: select a [logging level](https://github.com/winstonjs/winston#logging-levels)
+- LOGGER_ENABLE: if `true` enables log, `false` disables log
+- LOGGER_LEVEL: select a [logging level](https://github.com/pinojs/pino/blob/master/docs/API.md#level)
+- LOGGER_PRETTY: pretty print log (should be set to `false` in production)
 - PORT: application port
 - PORT_DEV: **FOR DEVELOPMENT ONLY** will take effect when run `npm run dev`
 - KANCOLLE_SERVER_MASTER: A host name for main Kancolle server that have interface`/kcsapi/api_world/get_id` for requesting players world id

bin/www

@@ -2,7 +2,7 @@
 
 'use strict'
 
-const winston = require('winston')
+const pino = require('pino')()
 const app = require('../src/')
 const http = require('http')
 
@@ -63,11 +63,11 @@ function onError(error) {
   // handle specific listen errors with friendly messages
   switch (error.code) {
   case 'EACCES':
-    winston.error(bind + ' requires elevated privileges')
+    pino.error(bind + ' requires elevated privileges')
     process.exit(1)
     break
   case 'EADDRINUSE':
-    winston.error(bind + ' is already in use')
+    pino.error(bind + ' is already in use')
     process.exit(1)
     break
   default:
@@ -84,5 +84,5 @@ function onListening() {
   const bind = typeof addr === 'string'
     ? 'pipe ' + addr
     : 'port ' + addr.port
-  winston.info('modcolle is listening on ' + bind)
+  pino.info('modcolle is listening on ' + bind)
 }

package.json

@@ -38,13 +38,13 @@
     "morgan": "1.8.1",
     "passport": "0.3.2",
     "passport-local": "1.0.0",
+    "pino": "4.4.0",
     "request": "2.81.0",
     "request-promise": "4.2.0",
     "tough-cookie": "2.3.2",
     "url-join": "2.0.1",
     "url-parse": "1.1.8",
-    "validator": "7.0.0",
-    "winston": "2.3.1"
+    "validator": "7.0.0"
   },
   "devDependencies": {
     "app-root-path": "2.0.1",

process.yml

@@ -10,7 +10,8 @@ apps:
      pid_file: ./log/modcolle.pid
 
      env:
-      LOGGER_SILENT: false
+      LOGGER_ENABLE: true
+      LOGGER_PRETTY: true
       LOGGER_LEVEL: info
       PORT: 5000
 
@@ -39,3 +40,4 @@ apps:
      env_production:
       NODE_ENV: production
       PORT: 5000
+      LOGGER_PRETTY: false

src/dmm/agent.js

@@ -76,7 +76,7 @@ function authenticate(email, password, dmmAjaxToken) {
 
     if(loginGranted) {
       log.info('%s granted access to user %s', options.uri, email)
-      log.verbose('get "%s"\'s cookies given by %s', email, options.uri)
+      log.debug('get "%s"\'s cookies given by %s', email, options.uri)
 
       const cookies = response.headers['set-cookie'].map(Cookie.parse)
       const session = cookies.find(cookie => cookie.key === 'INT_SESID')

src/dmm/cookie-injector.js

@@ -21,17 +21,17 @@ class Injector {
     const targetCookie = {key: 'ckcy', value: 1}
 
     log.info('revoke foriegner (non-japan) access restriction')
-    log.verbose('include to original cookie', targetCookie)
+    log.debug('include to original cookie', targetCookie)
     this.cookies = removeAndInjectCookie(this, targetCookie)
     return this.cookies
   }
 }
 
 function removeAndInjectCookie(self, targetCookie) {
   let cookies
-  log.verbose(`remove cookie ${targetCookie.key}`)
+  log.debug(`remove cookie ${targetCookie.key}`)
   cookies = removeCookie(self.cookies, targetCookie)
-  log.verbose(`${targetCookie.key} include target domain and subdomains`, self.domain, self.subdomains)
+  log.debug(`${targetCookie.key} include target domain and subdomains`, self.domain, self.subdomains)
   cookies = cookies.concat(generateCookies(targetCookie, [self.domain], self.subdomains))
   return cookies
 }

src/dmm/osapi.js

@@ -69,7 +69,7 @@ function proxyRequest(targetUrl, gadgetInfo) {
   return rp.post(options)
   .then(response => {
     log.info('unwrap response from %s', options.url)
-    log.verbose(response)
+    log.debug(response)
 
     const wrapper = 'throw 1; < don\'t be evil\' >'
     log.debug('remove response wrapper (%s)', wrapper)
@@ -99,7 +99,7 @@ function proxyRequest(targetUrl, gadgetInfo) {
 }
 
 function _getGadgetInfo(htmlString) {
-  log.verbose('get unparsed json from variable gadgetInfo')
+  log.debug('get unparsed json from variable gadgetInfo')
   const varName = 'gadgetInfo = '
   let gadgetInfo = htmlString.match(new RegExp(varName + '{([^}]*)}', 'g'))
   if(!gadgetInfo)

src/kancolle/game.js

@@ -18,11 +18,11 @@ function fetchConfig() {
   return rp.get({url})
   .then(jsCode => {
     log.info('extract Kancolle server IP addresses, URL info, and maintenance info')
-    log.verbose('append js code to output variable value')
+    log.debug('append js code to output variable value')
     const var2export = 'JSON.stringify({ConstServerInfo, ConstURLInfo, MaintenanceInfo})'
     jsCode += ';' + var2export
 
-    log.verbose(`emulate javascripts assuming that code from ${url} is trusted`)
+    log.debug(`emulate javascripts assuming that code from ${url} is trusted`)
     const json = JSON.parse(eval(jsCode))
     log.debug('parsed json result', json)
     return Promise.resolve(json)

src/kancolle/server/server.js

@@ -58,7 +58,7 @@ class KancolleServer {
 
 function forgeKancolleHttpRequestHeader(fullUrl, initialHttpHeaders) {
   initialHttpHeaders = initialHttpHeaders || {}
-  log.verbose('forge HTTP header as if it comes from a browser')
+  log.debug('forge HTTP header as if it comes from a browser')
 
   let headers = initialHttpHeaders
   headers = asIfInitiateByBrowser(headers, fullUrl)

src/logger.js

@@ -1,33 +1,24 @@
 'use strict'
 
-const LOGGER_SILENT = process.env.LOGGER_SILENT
+const LOGGER_ENABLE = process.env.LOGGER_ENABLE
 const LOGGER_LEVEL = process.env.LOGGER_LEVEL
+const LOGGER_PRETTY = process.env.LOGGER_PRETTY
 
-const winston = require('winston')
+const pino = require('pino')
 const labels = ['app:middleware', 'app:router', 'service:dmm', 'service:kancolle']
 
 const loggers = {}
 labels.forEach(label => {
-  createCustomWinstonLogger(label)
-  loggers[label] = winston.loggers.get(label)
+  loggers[label] = pino({
+    name: label,
+    enabled: LOGGER_ENABLE,
+    level: LOGGER_LEVEL,
+    prettyPrint: LOGGER_PRETTY
+  })
 })
 
 module.exports = function(label) {
   if(!loggers[label])
     return winston
   return loggers[label]
 }
-
-function createCustomWinstonLogger(label) {
-  const loggerConfig = {
-    console: {
-      label: label,
-      level: LOGGER_LEVEL,
-      colorize: 'all',
-      silent: LOGGER_SILENT === 'true',
-      timestamp: true,
-      prettyPrint: false,
-    }
-  }
-  winston.loggers.add(label, loggerConfig)
-}

src/login-strategy.js

@@ -39,7 +39,7 @@ function dmmSession(session, _, done) {
 
 function _injectCookies(session, subdomains) {
   const injector = new CookieInjector([session], subdomains)
-  log.verbose('revoke region restriction')
+  log.debug('revoke region restriction')
   injector.revokeRegionRestriction()
   return injector.cookies
 }

src/modcolle.js

@@ -35,23 +35,23 @@ function setupRouting() {
 
 function setupMiddleware() {
   log.info('setup middlewares')
-  log.verbose('setup POST body parser')
+  log.debug('setup POST body parser')
   app.use(bodyParser.json())
   app.use(bodyParser.urlencoded({ extended: true }))
-  log.verbose('initialize passport')
+  log.debug('initialize passport')
   app.use(passport.initialize())
   passport.use('dmm-account', new LocalStrategy(loginStrategy.dmmAccount))
   passport.use('dmm-session', new LocalStrategy({
     usernameField: 'dmm_session', passwordField: 'dmm_session'},
   loginStrategy.dmmSession))
 
-  log.verbose('configure stream log messages from morgan')
-  log.stream = {
-    write: function(message){
+  log.debug('configure stream log messages from morgan')
+  const writeStream = {
+    write(message){
       log.info(message)
     }
   }
-  app.use(morgan('combined', {stream: log.stream}))
+  app.use(morgan('combined', {stream: writeStream}))
 }
 
 function setupTemplateEngine() {

src/routing/assets.js

@@ -42,11 +42,11 @@ router.get('/resources/image/world/:worldImg', (req, res, next) => {
   const proxyRequest = targetServer.download(url)
   proxyRequest.on('error', next)
   proxyRequest.on('response', () => {
-    log.verbose(`connected to ${url}`)
+    log.debug(`connected to ${url}`)
   })
   proxyRequest.on('end', () => {
     log.info(`pipe ${url} to client completed`)
-    log.verbose(`terminate connection ${url}`)
+    log.debug(`terminate connection ${url}`)
   })
 
   proxyRequest.pipe(res)
@@ -60,10 +60,10 @@ function getHost(worldImageFilename) {
   const ipStrip = basename.split('_').map(Number).join('.')
   if(validator.isIP(ipStrip)) {
     host = ipStrip
-    log.verbose(`${worldImageFilename} 'is an ip address. Resolved as ${host}`)
+    log.debug(`${worldImageFilename} 'is an ip address. Resolved as ${host}`)
   } else {
     host = basename.split('_').join('.')
-    log.verbose(`${worldImageFilename} 'is a hostname. Resolved as ${host}`)
+    log.debug(`${worldImageFilename} 'is a hostname. Resolved as ${host}`)
   }
   return host
 }

src/routing/game.js

@@ -42,7 +42,7 @@ function redirectKancolleNetworkTraffic(url) {
   const server = kancolle.getServer(url.hostname)
   const apiTokenWithExtraEmbededInfo = [server.worldId, url.query.api_token].join('_') // embed player's info so that any API POST request from flash will contain this information
 
-  log.verbose(`remove host name ${url.hostname} from url`)
+  log.debug(`remove host name ${url.hostname} from url`)
   const interceptedUrl = urljoin(
     url.pathname, // remove hostname from flash url so that it makes http request to this site
     `?api_token=${apiTokenWithExtraEmbededInfo}`,

src/routing/kcsapi/index.js

@@ -12,7 +12,7 @@ router.post('/*', extractWorldIdFromApiToken, (req, res, next) => {
     return res.sendStatus(400)
   }
 
-  log.verbose(`remove worldId ${req.body.worldId} from payload`)
+  log.debug(`remove worldId ${req.body.worldId} from payload`)
   delete req.body.worldId
 
   log.info(`call Kancolle host ${server.host} with API ${req.originalUrl}`)
@@ -21,7 +21,7 @@ router.post('/*', extractWorldIdFromApiToken, (req, res, next) => {
   .then(apiResponse => {
     apiResponse = apiResponse.replace('svdata=', '')
     apiResponse = JSON.parse(apiResponse)
-    log.verbose(`${server.host} API ${req.originalUrl} respond %j`, apiResponse)
+    log.debug(`${server.host} API ${req.originalUrl} respond %j`, apiResponse)
     res.json(apiResponse)
   })
   .catch(next)
@@ -35,14 +35,14 @@ function extractWorldIdFromApiToken(req, res, next) {
   }
 
   const delimiter = '_'
-  log.verbose(`looking for server id by splitting api_token using '${delimiter}' as a delimiter`)
+  log.debug(`looking for server id by splitting api_token using '${delimiter}' as a delimiter`)
   const extraInfos = api_token.split(delimiter)
   if(extraInfos.length == 1) {
     log.info(`splitting api_token using '${delimiter}', found only api_token. Modcolle requires server id in front of api_token. Send HTTP status code 400`)
     return res.sendStatus(400)
   }
 
-  log.verbose('extract id from api token assuming that id comes before api token')
+  log.debug('extract id from api token assuming that id comes before api token')
   req.body.worldId = extraInfos[0]
   req.body.api_token = extraInfos[1]
   return next()