add logging and timeouts

config/logger.js

@@ -12,7 +12,7 @@ exports.default = {
             logger.transports.push(function (api, winston) {
                 return new (winston.transports.Console)({
                     colorize: true,
-                    level: 'info',
+                    level: 'debug',
                     timestamp: api.utils.sqlDateTime,
                     json: false
                 });
@@ -31,7 +31,7 @@ exports.default = {
         logger.transports.push(function (api, winston) {
             return new (winston.transports.File)({
                 filename: api.config.general.paths.log[0] + '/actionhero-worker.log',
-                level: 'info',
+                level: 'debug',
                 colorize: true,
                 timestamp: api.utils.sqlDateTime,
                 json: false

initializers/dataAccess.js

@@ -178,7 +178,10 @@ exports.dataAccess = function (api, next) {
             var error, dbServerPrefix = api.config.tcConfig.databaseMapping[databaseName],
                 user, password, hostname, server, port, settings;
             error = helper.checkDefined(dbServerPrefix, "database server prefix");
+
+            api.log('Creating a new db connection at dataAccess','debug');      
             if (error) {
+                api.log('Error : ' + error, 'error');
                 throw error;
             }
 

initializers/transaction.js

@@ -8,14 +8,18 @@
 
 /*jslint unparam: true */
 
+var CONN_TIMEOUT = process.env.CONN_TIMEOUT || 5000;
+var DISCONNECT_ON_CONN_TIMEOUT = process.env.DISCONNECT_ON_CONN_TIMEOUT !== "false" ? true : false;
+var DISCONN_TIMEOUT = process.env.DISCONN_TIMEOUT || 5000;
+
 var handleConnectionFailure = function (api, connection, actionTemplate, error, next) {
     api.log("Close all opened connections", "debug");
     var connectionClosedCount = 0;
     actionTemplate.databases.forEach(function (databaseName) {
         var callback;
         callback = function (err, result) {
             connection.dbConnectionMap[databaseName].disconnect();
-            api.log("Connection is closed", "debug");
+            api.log("Connection is closed for " + databaseName, "debug");
             if (err) {
                 connection.error = err;
                 next(connection, false);
@@ -57,6 +61,15 @@ exports.transaction = function (api, next) {
     transactionPreProcessor = function (connection, actionTemplate, next) {
         if (actionTemplate.transaction === "read" || actionTemplate.transaction === "write") {
             var dbConnectionMap = {}, dbConnection, callback, connectionOpenedCount = 0;
+
+            var connectTimeout = function() {
+                api.log("Timed out without obtaining all DB connections", "error");
+                if (DISCONNECT_ON_CONN_TIMEOUT) {
+                    handleConnectionFailure(api, connection, actionTemplate, "Open Timeout", next);
+                }
+            }
+
+            var clearMe = setTimeout(connectTimeout, CONN_TIMEOUT);
 
             actionTemplate.databases.forEach(function (databaseName) {
                 dbConnection = api.dataAccess.createConnection(databaseName);
@@ -68,12 +81,14 @@ exports.transaction = function (api, next) {
                 callback = function (err, result) {
                     connection.dbConnectionMap = dbConnectionMap;
                     if (err) {
+                        clearTimeout(clearMe);
                         handleConnectionFailure(api, connection, actionTemplate, err, next);
                         return;
                     }
 
                     connectionOpenedCount += 1;
                     if (connectionOpenedCount === actionTemplate.databases.length) {
+                        clearTimeout(clearMe);
                         api.log("All connections are opened", "debug");
                         next(connection, true);
                     }
@@ -121,6 +136,14 @@ exports.transaction = function (api, next) {
      * @param {Function} next - The callback function
      */
     transactionPostProcessor = function (connection, actionTemplate, toRender, next) {
+
+        var disconnectTimeout = function() {
+            api.error("Timed out without closing all DB connections", "error");
+            // I dont want to call next(connection); here because I want to allow the execution to to continue in case connection can be closed after timeout
+        }
+
+        var clearMe = setTimeout(disconnectTimeout, DISCONN_TIMEOUT);
+
         var connectionClosedCount = 0;
         if (connection.dbConnectionMap !== null && connection.dbConnectionMap !== undefined && actionTemplate.transaction !== null && actionTemplate.transaction !== undefined) {
             actionTemplate.databases.forEach(function (databaseName) {
@@ -129,13 +152,15 @@ exports.transaction = function (api, next) {
                     connection.dbConnectionMap[databaseName].disconnect();
                     api.log("Connection is closed", "debug");
                     if (err) {
+                        clearTimeout(clearMe);
                         connection.error = err;
                         next(connection);
                         return;
                     }
 
                     connectionClosedCount += 1;
                     if (connectionClosedCount === actionTemplate.databases.length) {
+                        clearTimeout(clearMe);
                         api.log("All connections are closed", "debug");
                         next(connection);
                     }

package.json

@@ -27,9 +27,9 @@
     "forums-wrapper": "git://github.com/cloudspokes/forums-wrapper.git#12b57be495c2e10431173522bc9eff60e0575959",
     "heapdump": "^0.3.6",
     "highlight.js": ">= 8.3.0",
-    "informix-wrapper": "git://github.com/cloudspokes/informix-wrapper.git#46d1c91c3a8e164f888e88627b8da712e9ceb855",
+    "informix-wrapper": "git://github.com/cloudspokes/informix-wrapper.git",
     "java": "0.3.x",
-    "jsonwebtoken": "0.4.x",
+    "jsonwebtoken": "5.0.5",
     "ldapjs": "0.7.x",
     "mime": "~1.2.11",
     "mkdirp": "0.3.x",