Merge pull request #2685 from colegleason/logging

chore(logging): add Winston and replace console.log

.gitignore

@@ -12,6 +12,8 @@ newrelic_agent.log
 .bower-tmp
 .bower-registry
 .bower-cache
+
+*.log
 src/*/*.map
 src/*/*/*.map
 test/*.js

.nodemonignore

@@ -6,4 +6,5 @@ Gruntfile.js
 CHANGELOG.md
 .idea*
 .git*
+*.log
 newrelic_agent.log

Gruntfile.js

@@ -78,7 +78,7 @@ module.exports = function(grunt) {
 
     nodemon: {
       dev: {
-        ignoredFiles: ['public/*', 'Gruntfile.js', 'CHANGELOG.md', 'views/*', 'build/*', '.idea*', '.git*']
+        ignoredFiles: ['public/*', 'Gruntfile.js', 'CHANGELOG.md', 'views/*', 'build/*', '.idea*', '.git*', '*.log']
       }
     },
 

config.json.example

@@ -11,6 +11,9 @@
     "SMTP_USER":"user@domain.com",
     "SMTP_PASS":"password",
     "SMTP_SERVICE":"Gmail",
+    "SMTP_HOST":"smtp.gmail.com",
+    "SMTP_PORT": 587,
+    "SMTP_TLS": true,
     "STRIPE_API_KEY":"aaaabbbbccccddddeeeeffff00001111",
     "STRIPE_PUB_KEY":"22223333444455556666777788889999",
     "PAYPAL_MERCHANT":"paypal-merchant@gmail.com",

package.json

@@ -45,7 +45,10 @@
     "passport": "~0.1.18",
     "passport-facebook": "~1.0.2",
     "newrelic": "~1.3.0",
-    "connect-ratelimit": "0.0.6"
+    "connect-ratelimit": "0.0.6",
+    "winston": "~0.7.2",
+    "winston-mail": "~0.2.7",
+    "winston-newrelic": "~0.1.4"
   },
   "private": true,
   "subdomain": "habitrpg",

src/controllers/challenges.js

@@ -7,6 +7,7 @@ var shared = require('habitrpg-shared');
 var User = require('./../models/user').model;
 var Group = require('./../models/group').model;
 var Challenge = require('./../models/challenge').model;
+var logging = require('./../logging');
 var csv = require('express-csv');
 var api = module.exports;
 
@@ -214,7 +215,7 @@ api.update = function(req, res){
       // Compare whether any changes have been made to tasks. If so, we'll want to sync those changes to subscribers
       if (before.isOutdated(req.body)) {
         User.find({_id: {$in: saved.members}}, function(err, users){
-          console.log('Challenge updated, sync to subscribers');
+          logging.info('Challenge updated, sync to subscribers');
           if (err) throw err;
           _.each(users, function(user){
             saved.syncToUser(user);

src/controllers/user.js

@@ -12,6 +12,7 @@ var sanitize = validator.sanitize;
 var User = require('./../models/user').model;
 var Group = require('./../models/group').model;
 var Challenge = require('./../models/challenge').model;
+var logging = require('./../logging');
 var acceptablePUTPaths;
 var api = module.exports;
 
@@ -349,7 +350,7 @@ api.buyGemsPaypalIPN = function(req, res, next) {
         user.balance += 5;
         //user.purchased.ads = true;
         user.save();
-        console.log('PayPal transaction completed and user updated');
+        logging.info('PayPal transaction completed and user updated');
       });
     }
   });
@@ -518,4 +519,4 @@ api.batchUpdate = function(req, res, next) {
       res.json(200, {_v: response._v});
     }
   });
-};
+};

src/logging.js

@@ -0,0 +1,52 @@
+var nconf = require('nconf');
+var winston = require('winston');
+require('winston-mail').Mail;
+require('winston-newrelic');
+
+var logger;
+
+if (logger == null) {
+        logger = new (winston.Logger)({
+            transports: [
+                new (winston.transports.Console)({colorize: true}),
+                new (winston.transports.File)({ filename: 'habitrpg.log' })
+                // TODO: Add email, loggly, or mongodb transports
+            ]
+        });
+    if (nconf.get('NODE_ENV') == 'production') {
+       logger.add(winston.transport.newrelic, {});
+        logger.add(winston.transports.Mail, {
+            to: nconf.get('ADMIN_EMAIL') || nconf.get('SMTP_USER'),
+            from: "HabitRPG <" + nconf.get('SMTP_USER') + ">",
+            subject: "HabitRPG Error",
+            host: nconf.get('SMTP_HOST'),
+            port: nconf.get('SMTP_PORT'),
+            tls: nconf.get('SMTP_TLS'),
+            username: nconf.get('SMTP_USER'),
+            password: nconf.get('SMTP_PASS'),
+            level: 'error'
+        });
+    }
+}
+
+// A custom log function that wraps Winston. Makes it easy to instrument code
+// and still possible to replace Winston in the future.
+module.exports.log = function(/* variable args */) {
+    if (logger)
+        logger.log.apply(logger, arguments);
+};
+
+module.exports.info = function(/* variable args */) {
+    if (logger)
+        logger.info.apply(logger, arguments);
+};
+
+module.exports.warn = function(/* variable args */) {
+    if (logger)
+        logger.warn.apply(logger, arguments);
+};
+
+module.exports.error = function(/* variable args */) {
+    if (logger)
+        logger.error.apply(logger, arguments);
+};

src/middleware.js

@@ -4,6 +4,7 @@ var fs = require('fs');
 var path = require('path');
 var User = require('./models/user').model
 var limiter = require('connect-ratelimit');
+var logging = require('./logging');
 
 module.exports.apiThrottle = function(app) {
   app.use(limiter({
@@ -16,7 +17,7 @@ module.exports.apiThrottle = function(app) {
       }
     }
   })).use(function(req,res,next){
-    //console.log(res.ratelimit);
+    //logging.info(res.ratelimit);
     if (res.ratelimit.exceeded) return res.json(429,{err:'Rate limit exceeded'});
     next();
   });
@@ -92,15 +93,15 @@ var getManifestFiles = function(page){
   var css = '';
 
   _.each(files.css, function(file){
-    css += '<link rel="stylesheet" type="text/css" href="' + getBuildUrl(file) + '">'; 
+    css += '<link rel="stylesheet" type="text/css" href="' + getBuildUrl(file) + '">';
   });
 
   if(nconf.get('NODE_ENV') === 'production'){
-    return css + '<script type="text/javascript" src="' + getBuildUrl(page + '.js') + '"></script>'; 
+    return css + '<script type="text/javascript" src="' + getBuildUrl(page + '.js') + '"></script>';
   }else{
     var results = css;
     _.each(files.js, function(file){
-      results += '<script type="text/javascript" src="' + getBuildUrl(file) + '"></script>'; 
+      results += '<script type="text/javascript" src="' + getBuildUrl(file) + '"></script>';
     });
     return results;
   }
@@ -184,16 +185,16 @@ var getUserLanguage = function(req, callback){
       }
     });
   }else{
-    return callback(null, _.find(avalaibleLanguages, {code: getFromBrowser()}));    
+    return callback(null, _.find(avalaibleLanguages, {code: getFromBrowser()}));
   }
 }
 
 module.exports.locals = function(req, res, next) {
   getUserLanguage(req, function(err, language){
-    if(err) return res.json(500, {err: err});    
+    if(err) return res.json(500, {err: err});
 
     language.momentLang = (momentLangs[language.code] || undefined);
-    
+
     res.locals.habitrpg = {
       NODE_ENV: nconf.get('NODE_ENV'),
       BASE_URL: nconf.get('BASE_URL'),
@@ -209,11 +210,11 @@ module.exports.locals = function(req, res, next) {
         var string = translations[language.code][stringName];
         if(!string) return _.template(translations[language.code].stringNotFound, {string: stringName});
 
-        return vars === undefined ? string : _.template(string, vars);    
+        return vars === undefined ? string : _.template(string, vars);
       },
       siteVersion: siteVersion
     }
 
-    next(); 
+    next();
   });
-}
+}

src/routes/apiv1.js

@@ -6,6 +6,7 @@ var icalendar = require('icalendar');
 var api = require('./../controllers/user');
 var auth = require('./../controllers/auth');
 var middleware = require('../middleware');
+var logging = require('./../logging');
 
 /* ---------- Deprecated API ------------*/
 
@@ -78,7 +79,7 @@ var batchUpdate = function(req, res, next) {
     req.body = action.data;
     res.send = res.json = function(code, data) {
       if (_.isNumber(code) && code >= 400) {
-        console.error({
+        logging.error({
           code: code,
           data: data
         });
@@ -168,4 +169,4 @@ router.get('*', deprecated);
 router.post('*', deprecated);
 router.put('*', deprecated);
 
-module.exports = router;
+module.exports = router;

src/seed.js

@@ -1,6 +1,7 @@
 require('coffee-script') // for habitrpg-shared
 var nconf = require('nconf');
 var utils = require('./utils');
+var logging = require('./logging');
 utils.setupConfig();
 var async = require('async');
 var mongoose = require('mongoose');
@@ -15,7 +16,7 @@ async.waterfall([
     Group.findById('habitrpg', cb);
   },
   function(tavern, cb){
-    console.log({tavern:tavern,cb:cb});
+    logging.info({tavern:tavern,cb:cb});
     if (!tavern) {
       tavern = new Group({
         _id: 'habitrpg',
@@ -31,6 +32,6 @@ async.waterfall([
   }
 ],function(err){
   if (err) throw err;
-  console.log("Done initializing database");
+  logging.info("Done initializing database");
   mongoose.disconnect();
 })

src/server.js

@@ -4,7 +4,7 @@ var _ = require('lodash');
 var nconf = require('nconf');
 var utils = require('./utils');
 utils.setupConfig();
-
+var logging = require('./logging');
 var isProd = nconf.get('NODE_ENV') === 'production';
 var isDev = nconf.get('NODE_ENV') === 'development';
 
@@ -16,7 +16,7 @@ if (cluster.isMaster && (isDev || isProd)) {
 
   cluster.on('exit', function(worker, code, signal) {
     var w = cluster.fork(); // replace the dead worker
-    console.error('[%s] [master:%s] worker:%s disconnect! new worker:%s fork', new Date(), process.pid, worker.process.pid, w.process.pid);
+    logging.error('[%s] [master:%s] worker:%s disconnect! new worker:%s fork', new Date(), process.pid, worker.process.pid, w.process.pid);
   });
 
 } else {
@@ -40,7 +40,7 @@ if (cluster.isMaster && (isDev || isProd)) {
   require('./models/challenge');
   mongoose.connect(nconf.get('NODE_DB_URI'), {auto_reconnect:true}, function(err) {
       if (err) throw err;
-      console.info('Connected with Mongoose');
+      logging.info('Connected with Mongoose');
   });
 
 
@@ -141,8 +141,8 @@ if (cluster.isMaster && (isDev || isProd)) {
 
   server.on('request', app);
   server.listen(app.get("port"), function() {
-    return console.log("Express server listening on port " + app.get("port"));
+    return logging.info("Express server listening on port " + app.get("port"));
   });
 
   module.exports = server;
-}
+}

src/utils.js

@@ -5,15 +5,16 @@ var path = require("path");
 
 module.exports.sendEmail = function(mailData) {
   var smtpTransport = nodemailer.createTransport("SMTP",{
-    service: nconf.get('SMTP_SERVICE'),
+      service: nconf.get('SMTP_SERVICE'),
     auth: {
-      user: nconf.get('SMTP_USER'),
-      pass: nconf.get('SMTP_PASS')
+        user: nconf.get('SMTP_USER'),
+        pass: nconf.get('SMTP_PASS')
     }
   });
   smtpTransport.sendMail(mailData, function(error, response){
-    if(error) console.log(error);
-    else console.log("Message sent: " + response.message);
+      var logging = require('./logging');
+    if(error) logging.error(error);
+    else logging.info("Message sent: " + response.message);
     smtpTransport.close(); // shut down the connection pool, no more messages
   });
 }
@@ -48,7 +49,8 @@ module.exports.setupConfig = function(){
 //      // * https://developers.google.com/chrome-developer-tools/docs/heap-profiling
 //      // * https://developers.google.com/chrome-developer-tools/docs/memory-analysis-101
 //      agent = require('webkit-devtools-agent');
-//      console.log("To debug memory leaks:" +
+//      var logging = require('./logging');
+//      logging.info("To debug memory leaks:" +
 //          "\n\t(1) Run `kill -SIGUSR2 " + process.pid + "`" +
 //          "\n\t(2) open http://c4milo.github.com/node-webkit-agent/21.0.1180.57/inspector.html?host=localhost:1337&page=0");
 //  }
@@ -69,15 +71,10 @@ module.exports.errorHandler = function(err, req, res, next) {
     "\n\nheaders: " + JSON.stringify(req.headers) +
     "\n\nbody: " + JSON.stringify(req.body) +
     (res.locals.ops ? "\n\ncompleted ops: " + JSON.stringify(res.locals.ops) : "");
-  module.exports.sendEmail({
-    from: "HabitRPG <" + nconf.get('SMTP_USER') + ">",
-    to: nconf.get('ADMIN_EMAIL') || nconf.get('SMTP_USER'),
-    subject: "HabitRPG Error",
-    text: stack
-  });
-  console.error(stack);
+  var logging = require('./logging');
+  logging.error(stack);
   var message = err.message ? err.message : err;
   message =  (message.length < 200) ? message : message.substring(0,100) + message.substring(message.length-100,message.length);
   res.json(500,{err:message}); //res.end(err.message);
   process.exit(0);
-}
+}