v3: expose public interface for logger and add tests

test/api/v3/unit/libs/logger.js

@@ -0,0 +1,58 @@
+import winston from 'winston';
+
+/* eslint-disable global-require */
+describe('logger', () => {
+  let pathToLoggerLib = '../../../../../website/src/libs/api-v3/logger';
+  let infoSpy;
+  let errorSpy;
+
+  beforeEach(() => {
+    delete require.cache[require.resolve(pathToLoggerLib)];
+
+    infoSpy = sandbox.stub();
+    errorSpy = sandbox.stub();
+    sandbox.stub(winston, 'Logger').returns({
+      info: infoSpy,
+      error: errorSpy,
+    });
+  });
+
+  afterEach(() => {
+    sandbox.restore();
+  });
+
+  it('info', () => {
+    let attachLogger = require(pathToLoggerLib);
+    attachLogger.info(1, 2, 3);
+    expect(infoSpy).to.be.calledOnce;
+    expect(infoSpy).to.be.calledWith(1, 2, 3);
+  });
+
+  describe('error', () => {
+    it('with custom arguments', () => {
+      let attachLogger = require(pathToLoggerLib);
+      attachLogger.error(1, 2, 3, 4);
+      expect(errorSpy).to.be.calledOnce;
+      expect(errorSpy).to.be.calledWith(1, 2, 3, 4);
+    });
+
+    it('with error', () => {
+      let attachLogger = require(pathToLoggerLib);
+      let errInstance = new Error('An error.');
+      attachLogger.error(errInstance, {
+        data: 1,
+      }, 2, 3);
+      expect(errorSpy).to.be.calledOnce;
+      // using calledWith doesn't work
+      let lastCallArgs = errorSpy.lastCall.args;
+
+      expect(lastCallArgs[3]).to.equal(3);
+      expect(lastCallArgs[2]).to.equal(2);
+      expect(lastCallArgs[1]).to.eql({
+        data: 1,
+        fullError: errInstance,
+      });
+      expect(lastCallArgs[0]).to.eql(errInstance.stack);
+    });
+  });
+});

website/src/controllers/api-v3/auth.js

@@ -14,6 +14,7 @@ import {
 } from '../../libs/api-v3/errors';
 import Q from 'q';
 import * as passwordUtils from '../../libs/api-v3/password';
+import logger from '../../libs/api-v3/logger';
 import { model as User } from '../../models/user';
 import { model as Group } from '../../models/group';
 import { model as EmailUnsubscription } from '../../models/emailUnsubscription';
@@ -33,7 +34,7 @@ async function _handleGroupInvitation (user, invite) {
 
     // check that the invite has not expired (after 7 days)
     if (sentAt && moment().subtract(7, 'days').isAfter(sentAt)) {
-      let err = new Error('Invite expired');
+      let err = new Error('Invite expired.');
       err.privateData = invite;
       throw err;
     }
@@ -47,7 +48,7 @@ async function _handleGroupInvitation (user, invite) {
       user.invitations.guilds.push({id: group._id, name: group.name, inviter});
     }
   } catch (err) {
-    // TODO log errors
+    logger.error(err);
   }
 }
 

website/src/controllers/api-v3/challenges.js

@@ -499,7 +499,6 @@ export async function _closeChal (challenge, broken = {}) {
   ];
 
   Q.allSettled(backgroundTasks); // TODO look if allSettled could be useful somewhere else
-  // TODO catch and handle
 }
 
 /**

website/src/controllers/api-v3/content.js

@@ -4,6 +4,7 @@ import { langCodes } from '../../libs/api-v3/i18n';
 import Q from 'q';
 import fsCallback from 'fs';
 import path from 'path';
+import logger from '../../libs/api-v3/logger';
 
 // Transform fs methods that accept callbacks in ones that return promises
 const fs = {
@@ -53,7 +54,7 @@ async function saveContentToDisk (language, content) {
       return saveContentToDisk(language, content);
     } else {
       cacheBeingWritten[language] = false;
-      // TODO log error
+      logger.error(err);
       return;
     }
   }

website/src/controllers/api-v3/tasks.js

@@ -107,7 +107,7 @@ api.createChallengeTasks = {
     res.respond(201, tasks.length === 1 ? tasks[0] : tasks);
 
     // If adding tasks to a challenge -> sync users
-    if (challenge) challenge.addTasks(tasks); // TODO catch/log
+    if (challenge) challenge.addTasks(tasks);
   },
 };
 
@@ -313,7 +313,7 @@ api.updateTask = {
 
     let savedTask = await task.save();
     res.respond(200, savedTask);
-    if (challenge) challenge.updateTask(savedTask); // TODO catch/log
+    if (challenge) challenge.updateTask(savedTask);
   },
 };
 

website/src/libs/api-v3/email.js

@@ -1,8 +1,8 @@
 import { createTransport } from 'nodemailer';
 import nconf from 'nconf';
-import logger from './logger';
 import { encrypt } from './encryption';
 import request from 'request';
+import logger from './logger';
 
 const IS_PROD = nconf.get('IS_PROD');
 const EMAIL_SERVER = {
@@ -25,9 +25,7 @@ let smtpTransporter = createTransport({
 // Send email directly from the server using the smtpTransporter,
 // used only to send password reset emails because users unsubscribed on Mandrill wouldn't get them
 export function send (mailData) {
-  return smtpTransporter
-    .sendMail(mailData)
-    .catch((error) => logger.error(error));
+  return smtpTransporter.sendMail(mailData); // promise
 }
 
 export function getUserInfo (user, fields = []) {

website/src/libs/api-v3/logger.js

@@ -1,11 +1,12 @@
 // Logger utility
 import winston from 'winston';
 import nconf from 'nconf';
+import _ from 'lodash';
 
 const IS_PROD = nconf.get('IS_PROD');
 const IS_TEST = nconf.get('IS_TEST');
 
-let logger = new winston.Logger();
+const logger = new winston.Logger();
 
 if (IS_PROD) {
   // TODO production logging, use loggly and new relic too
@@ -31,4 +32,27 @@ process.on('unhandledRejection', function handlePromiseRejection (reason, promis
   });
 });
 
-module.exports = logger;
+// exports a public interface insteaf of accessing directly the logger module
+module.exports = {
+  info (...args) {
+    logger.info(...args);
+  },
+
+  // Accepts two argument,
+  // an Error object (required)
+  // and an object of additional data to log alongside the error
+  // If the first argument isn't an Error, it'll call logger.error with all the arguments supplied
+  error (...args) {
+    let [err, errorData = {}, ...otherArgs] = args;
+
+    if (err instanceof Error) {
+      // pass the error stack as the first parameter to logger.error
+      let stack = err.stack || err.message || err;
+
+      if (_.isPlainObject(errorData) && !errorData.fullError) errorData.fullError = err;
+      logger.error(stack, errorData, ...otherArgs);
+    } else {
+      logger.error(...args);
+    }
+  },
+};

website/src/libs/api-v3/webhook.js

@@ -1,13 +1,14 @@
 import { each } from 'lodash';
 import { post } from 'request';
 import { isURL } from 'validator';
+import logger from './logger';
 
 let _sendWebhook = (url, body) => {
   post({
     url,
     body,
     json: true,
-  }); // TODO use promises and handle errors
+  }, (err) => logger.error(err));
 };
 
 let _isInvalidWebhook = (hook) => {

website/src/middlewares/api-v3/cron.js

@@ -380,7 +380,7 @@ module.exports = function cronMiddleware (req, res, next) {
         $lt: moment(now).subtract(user.isSubscribed() ? 90 : 30, 'days'),
       },
       'challenge.id': {$exists: false},
-    }).exec(); // TODO catch error or at least log it, wait before returning?
+    }).exec(); // TODO wait before returning?
 
     let ranCron = user.isModified();
     let quest = common.content.quests[user.party.quest.key];

website/src/middlewares/api-v3/errorHandler.js

@@ -9,14 +9,10 @@ import {
 import { map } from 'lodash';
 
 module.exports = function errorHandler (err, req, res, next) { // eslint-disable-line no-unused-vars
-  // Log the original error with some metadata
-  let stack = err.stack || err.message || err;
-
-  logger.error(stack, {
+  logger.error(err, {
     originalUrl: req.originalUrl,
     headers: req.headers,
     body: req.body,
-    fullError: err,
   });
 
   // In case of a CustomError class, use it's data

website/src/models/group.js

@@ -740,6 +740,6 @@ if (!nconf.get('IS_TEST')) {
       privacy: 'public',
     }).save({
       validateBeforeSave: false, // _id = 'habitrpg' would not be valid otherwise
-    }); // TODO catch/log?
+    });
   });
 }