Merge pull request #5 from stenington/validation-timing

Add validation timing to logs

lib/logger.js

@@ -1,13 +1,20 @@
 const bunyan = require('bunyan');
 const util = require('util');
 
+function validationSerializer(info) {
+  if ('resources' in info)
+    delete info.resources;
+  return info;
+}
+
 const log = module.exports = bunyan.createLogger({
   name: 'openbadges-validator-service',
   stream: process.stdout,
   level: 'info',
   serializers: {
     req: bunyan.stdSerializers.req,
-    res: bunyan.stdSerializers.res
+    res: bunyan.stdSerializers.res,
+    validation: validationSerializer
   }
 });
 

lib/website.js

@@ -1,5 +1,6 @@
 const validator = require('openbadges-validator');
 const dataurl = require('dataurl');
+const log = require('./logger');
 
 exports.index = function index(req, res, next) {
   res.render('index.html');
@@ -46,7 +47,21 @@ exports.validate = function validate(req, res, next) {
 
   res.locals.assertion = assertion;
 
+  const startTime = new Date();
+  log.info({ 
+    assertion: assertion
+  }, 'Validating');
+
   validator(assertion, function (err, info) {
+
+    const responseTime = new Date() - startTime;
+    log.info({ 
+      assertion: assertion,
+      err: err,
+      responseTime: responseTime,
+      validation: info
+    }, 'Validation result');
+
     // We might want to display the images that we found. The easiest
     // way to do that is to convert them to dataurls so we can just
     // stick 'em into <img> tags instead of trying to cache them and