extended request logging

libs/logger.js

@@ -1,17 +1,17 @@
-const config = require("../config.json");
+const config = require('../config.json');
-const moment = require("moment");
+const moment = require('moment');
 
 // constants
-const LOG_PREFIX_DEBUG = "debug";
+const LOG_PREFIX_DEBUG = 'debug';
-const LOG_PREFIX_INFO = "info";
+const LOG_PREFIX_INFO = 'info';
-const LOG_PREFIX_WARNING = "warning";
+const LOG_PREFIX_WARNING = 'warning';
-const LOG_PREFIX_ERROR = "error";
+const LOG_PREFIX_ERROR = 'error';
 const LOGLEVEL_DEBUG = 0;
 const LOGLEVEL_INFO = 1;
 const LOGLEVEL_WARNING = 2;
 const LOGLEVEL_ERROR = 3;
 
-// set loglevel on "require"
+// set loglevel on 'require'
 const loglevel = function () {
     switch (config.log.level) {
         case LOG_PREFIX_DEBUG:
@@ -31,18 +31,31 @@ const loglevel = function() {
     }
 }();
 
-// log a http request
+// log a http request - response object
-function request(request) {
+function http(object) {
-    let message = "[" + request.method + "] url: \"" + request.url + "\"";
+    if (object == undefined) {
+        return;
+    }
+    let message = '[' + object.request.method + ':' + object.code + '] url: \'' + object.request.url + '\'';
     let counter = 1;
-    for (let param in request.body) {
+    for (let param in object.request.body) {
-        message += ", parameter " + counter + ": \"" + param + "=" + request.body[param] + "\"";
+        message += ', parameter ' + counter + ': \'' + param + '=' + object.request.body[param] + '\'';
         counter++;
     }
+    if (object.request.timestamp) {
+        message += ' > ' + (new Date().getTime() - object.request.timestamp) + 'ms';
+    }
+    if (object.data) {
+        message += ' > data: ' + object.data;
+    }
+    if (object.code != 200) {
+        error(message.trim());
+        return;
+    }
     debug(message.trim());
 }
 
-// prefix log with "info"
+// prefix log with 'info'
 function info(message) {
     if (loglevel > LOGLEVEL_INFO) {
         return;
@@ -50,28 +63,28 @@ function info(message) {
     trace(message);
 }
 
-// prefix log with "info"
+// prefix log with 'info'
 function warn(message) {
     if (loglevel > LOGLEVEL_WARNING) {
         return;
     }
-    trace(message, "warning");
+    trace(message, 'warning');
 }
 
-// prefix log with "debug"
+// prefix log with 'debug'
 function debug(message) {
     if (loglevel > LOGLEVEL_DEBUG) {
         return;
     }
-    trace(message, "debug");
+    trace(message, 'debug');
 }
 
-// prefix log with "error"
+// prefix log with 'error'
 function error(message) {
     if (loglevel > LOGLEVEL_ERROR) {
         return;
     }
-    trace(message, "error");
+    trace(message, 'error');
 }
 
 // default logging function
@@ -80,23 +93,23 @@ function trace(message, prefix) {
         return;
     }
     if (prefix === undefined || prefix === null || prefix.length === 0) {
-        prefix = "info";
+        prefix = 'info';
     }
     let print;
     switch (prefix) {
-        case "error":
+        case 'error':
             print = console.error;
             break;
-        case "debug":
+        case 'debug':
             print = console.debug;
             break;
-        case "warning":
+        case 'warning':
             print = console.warn;
             break;
         default:
             print = console.log;
     }
-    message = moment().format(config.server.timestamp) + " | " + prefix + " > " + message;
+    message = moment().format(config.server.timestamp) + ' | ' + prefix + ' > ' + message;
     print(message);
 }
 
@@ -106,5 +119,5 @@ module.exports = {
     warn,
     debug,
     error,
-    request
+    http
 };

libs/server.js

@@ -21,24 +21,28 @@ function start() {
 
 function handleRequests() {
     server.on('request', function (request, response) {
-        logger.request(request);
+        request.timestamp = new Date().getTime();
         if (request.url.endsWith('/')) {
             request.url = request.url.substring(0, request.url.length - 1);
         }
         var endpoint = api.getEndpoints().get(request.url);
         if (!endpoint) {
-            var msg = 'endpoint \'' + request.url + '\' not defined';
+            endRequest(
-            response.writeHead(501);
+                request,
-            response.end(msg);
+                response,
-            logger.debug(msg);
+                'endpoint \'' + request.url + '\' not defined',
+                501
+            );
             return;
         }
         endpoint = endpoint[request.method];
         if (endpoint == undefined || endpoint.method == undefined) {
-            var msg = 'error: endpoint \'' + request.url + '\' does not have any handlers for ' + request.method + ' requests';
+            endRequest(
-            response.writeHead(405);
+                request,
-            response.end(msg);
+                response,
-            logger.debug(msg);
+                'error: endpoint \'' + request.url + '\' does not have any handlers for ' + request.method + ' requests',
+                405
+            );
             return;
         }
         getRequestParams(request)
@@ -46,24 +50,37 @@ function handleRequests() {
                 return endpoint.method(endpoint.id, params);
             })
             .then(function (result) {
-                response.writeHead(200);
+                endRequest(request, response, result);
-                try {
-                    response.end(JSON.stringify(result));
-                } catch (err) {
-                    response.end(result);
-                }
             })
             .catch(function (err, code) {
-                logger.error(err);
                 if (code == undefined) {
                     code = 500;
                 }
-                response.writeHead(500);
+                endRequest(request, response, code, err);
-                response.end(err);
             });
     });
 }
 
+function endRequest(request, response, msg, code) {
+    if (code == undefined) {
+        code = 200;
+    }
+    var object = {
+        request: request,
+        code: code
+    }
+    if (msg != undefined) {
+        try {
+            object.data = JSON.stringify(msg);
+        } catch {
+            object.data = msg;
+        }
+    }
+    response.writeHead(object.code);
+    response.end(object.data);
+    logger.http(object);
+}
+
 function getRequestParams(request) {
     return new Promise(function (resolve, reject) {
         var params = "";