simplified the reload config code a little, moved the tests into their own file, improved coverage

lib/log4js.js

@@ -188,14 +188,7 @@ function getDefaultLogger () {
 var configState = {};
 
 function loadConfigurationFile(filename) {
-  if (filename && 
+  if (filename) {
-      (!configState.lastFilename || 
-       filename !== configState.lastFilename ||
-       !configState.lastMTime || 
-       fs.statSync(filename).mtime !== configState.lastMTime)
-     ) {
-    configState.lastFilename = filename;
-    configState.lastMTime = fs.statSync(filename).mtime;
     return JSON.parse(fs.readFileSync(filename, "utf8"));
   }
   return undefined;
@@ -222,21 +215,23 @@ function configureOnceOff(config, options) {
 }
 
 function reloadConfiguration() {
-  var filename = configState.filename,
+  var mtime = getMTime(configState.filename);
-  mtime;
+  if (!mtime) return;
+
+  if (configState.lastMTime && (mtime.getTime() > configState.lastMTime.getTime())) {
+    configureOnceOff(loadConfigurationFile(configState.filename));
+  }
+  configState.lastMTime = mtime;
+}
+
+function getMTime(filename) {
+  var mtime;
   try {
-    mtime = fs.statSync(filename).mtime;
+    mtime = fs.statSync(configState.filename).mtime;
   } catch (e) {
     getLogger('log4js').warn('Failed to load configuration file ' + filename);
-    return;
-  }
-  if (configState.lastFilename && configState.lastFilename === filename) {
-    if (mtime.getTime() > configState.lastMTime.getTime()) {
-      configureOnceOff(loadConfigurationFile(filename));
-    }
-  } else {
-    configureOnceOff(loadConfigurationFile(filename));
   }
+  return mtime;
 }
 
 function initReloadConfiguration(filename, options) {
@@ -245,6 +240,7 @@ function initReloadConfiguration(filename, options) {
     delete configState.timerId;
   }
   configState.filename = filename;
+  configState.lastMTime = getMTime(filename);
   configState.timerId = setInterval(reloadConfiguration, options.reloadSecs*1000);
 }
 

test/logging-test.js

@@ -498,237 +498,6 @@ vows.describe('log4js').addBatch({
       assert.equal(logEvent.data[0], "This should go to the appender defined in firstLog4js");
     }
   },
-  'configuration reload with configuration changing' : {
-    topic: function() {
-      var pathsChecked = [],
-      logEvents = [],
-      logger,
-      modulePath = 'path/to/log4js.json',
-      fakeFS = {
-        lastMtime: Date.now(),
-        config: { 
-          appenders: [ 
-            { type: 'console', layout: { type: 'messagePassThrough' } } 
-          ],
-          levels: { 'a-test' : 'INFO' } 
-        },
-        readdirSync: function(dir) {
-          return require('fs').readdirSync(dir);
-        },
-        readFileSync: function (file, encoding) {
-          assert.equal(file, modulePath);
-          assert.equal(encoding, 'utf8');
-          return JSON.stringify(fakeFS.config);
-        },
-        statSync: function (path) {
-          pathsChecked.push(path);
-          if (path === modulePath) {
-            fakeFS.lastMtime += 1;
-            return { mtime: new Date(fakeFS.lastMtime) };
-          } else {
-            throw new Error("no such file");
-          }
-        }
-      },
-      fakeConsole = {
-        'name': 'console',
-        'appender': function () {
-          return function(evt) { logEvents.push(evt); };
-        },
-        'configure': function (config) {
-          return fakeConsole.appender();
-        }
-      },
-      setIntervalCallback,
-      fakeSetInterval = function(cb, timeout) {
-        setIntervalCallback = cb;
-      },
-      log4js = sandbox.require(
-        '../lib/log4js',
-        {
-          requires: {
-            'fs': fakeFS,
-            './appenders/console': fakeConsole
-          },
-          globals: {
-            'console': fakeConsole,
-            'setInterval' : fakeSetInterval,
-          }
-        }
-      );
-      
-      log4js.configure('path/to/log4js.json', { reloadSecs: 30 });
-      logger = log4js.getLogger('a-test');
-      logger.info("info1");
-      logger.debug("debug2 - should be ignored");
-      fakeFS.config.levels['a-test'] = "DEBUG";
-      setIntervalCallback();
-      logger.info("info3");
-      logger.debug("debug4");
-      
-      return logEvents;
-    },
-    'should configure log4js from first log4js.json found': function(logEvents) {
-      assert.equal(logEvents[0].data[0], 'info1');
-      assert.equal(logEvents[1].data[0], 'info3');
-      assert.equal(logEvents[2].data[0], 'debug4');
-      assert.equal(logEvents.length, 3);
-    }
-  },
-  
-  'configuration reload with configuration staying the same' : {
-    topic: function() {
-      var pathsChecked = [],
-      fileRead = 0,
-      logEvents = [],
-      logger,
-      modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
-      mtime = new Date(),
-      fakeFS = {
-        config: { 
-          appenders: [ 
-            { type: 'console', layout: { type: 'messagePassThrough' } } 
-          ],
-          levels: { 'a-test' : 'INFO' } 
-        },
-        readdirSync: function(dir) {
-          return require('fs').readdirSync(dir);
-        },
-        readFileSync: function (file, encoding) {
-          fileRead += 1;
-          assert.isString(file);
-          assert.equal(file, modulePath);
-          assert.equal(encoding, 'utf8');
-          return JSON.stringify(fakeFS.config);
-        },
-        statSync: function (path) {
-          pathsChecked.push(path);
-          if (path === modulePath) {
-            return { mtime: mtime };
-          } else {
-            throw new Error("no such file");
-          }
-        }
-      },
-      fakeConsole = {
-        'name': 'console',
-        'appender': function () {
-          return function(evt) { logEvents.push(evt); };
-        },
-        'configure': function (config) {
-          return fakeConsole.appender();
-        }
-      },
-      setIntervalCallback,
-      fakeSetInterval = function(cb, timeout) {
-        setIntervalCallback = cb;
-      },
-      log4js = sandbox.require(
-        '../lib/log4js',
-        {
-          requires: {
-            'fs': fakeFS,
-            './appenders/console': fakeConsole
-          },
-          globals: {
-            'console': fakeConsole,
-            'setInterval' : fakeSetInterval,
-          }
-        }
-      );
-      
-      log4js.configure(modulePath, { reloadSecs: 3 });
-      logger = log4js.getLogger('a-test');
-      logger.info("info1");
-      logger.debug("debug2 - should be ignored");
-      setIntervalCallback();
-      logger.info("info3");
-      logger.debug("debug4");
-      
-      return [ pathsChecked, logEvents, modulePath, fileRead ];
-    },
-    'should only read the configuration file once': function(args) {
-      var fileRead = args[3];
-      assert.equal(fileRead, 1);
-    },
-    'should configure log4js from first log4js.json found': function(args) {
-      var logEvents = args[1];
-      assert.equal(logEvents.length, 2);
-      assert.equal(logEvents[0].data[0], 'info1');
-      assert.equal(logEvents[1].data[0], 'info3');
-    }
-  },
-
-  'reload config when passed an object': {
-    topic: function() {
-      var test = setupConsoleTest();
-      test.log4js.configure({}, { reloadSecs: 30 });
-      return test.logEvents;
-    },
-    'should log a warning': function(events) {
-      assert.equal(events[0].level.toString(), 'WARN');
-      assert.equal(
-        events[0].data[0], 
-        'Ignoring configuration reload parameter for "object" configuration.'
-      );
-    }
-  },
-
-  'configure called twice with reload options': {
-    topic: function() {
-      var modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
-      fakeFS = {
-        readFileSync: function (file, encoding) {
-          return JSON.stringify({});
-        },
-        statSync: function (path) {
-          return { mtime: new Date() };
-        }
-      },
-      fakeConsole = {
-        'name': 'console',
-        'appender': function () {
-          return function(evt) { };
-        },
-        'configure': function (config) {
-          return fakeConsole.appender();
-        }
-      },
-      setIntervalCallback,
-      intervalCleared = false,
-      clearedId,
-      fakeSetInterval = function(cb, timeout) {
-        setIntervalCallback = cb;
-        return 1234;
-      },
-      log4js = sandbox.require(
-        '../lib/log4js',
-        {
-          requires: {
-            'fs': fakeFS,
-            './appenders/console': fakeConsole
-          },
-          globals: {
-            'console': fakeConsole,
-            'setInterval' : fakeSetInterval,
-            'clearInterval': function(interval) {
-              intervalCleared = true;
-              clearedId = interval;
-            }
-          }
-        }
-      );
-      
-      log4js.configure(modulePath, { reloadSecs: 3 });
-      log4js.configure(modulePath, { reloadSecs: 15 });
-      
-      return { cleared: intervalCleared, id: clearedId };
-    },
-    'should clear the previous interval': function(result) {
-      assert.isTrue(result.cleared);
-      assert.equal(result.id, 1234);
-    }
-  },
 
   'getDefaultLogger': {
     topic: function() {

test/reloadConfiguration-test.js

@@ -0,0 +1,340 @@
+"use strict";
+var vows = require('vows')
+, assert = require('assert')
+, sandbox = require('sandboxed-module');
+
+function setupConsoleTest() {
+  var fakeConsole = {}
+  , logEvents = []
+  , log4js;
+  
+  ['trace','debug','log','info','warn','error'].forEach(function(fn) {
+    fakeConsole[fn] = function() {
+      throw new Error("this should not be called.");
+    };
+  });
+
+  log4js = sandbox.require(
+    '../lib/log4js', 
+    {
+      globals: {
+        console: fakeConsole
+      }
+    }
+  );
+
+  log4js.clearAppenders();
+  log4js.addAppender(function(evt) {
+    logEvents.push(evt);
+  });
+
+  return { log4js: log4js, logEvents: logEvents, fakeConsole: fakeConsole };
+}
+
+vows.describe('reload configuration').addBatch({
+  'with config file changing' : {
+    topic: function() {
+      var pathsChecked = [],
+      logEvents = [],
+      logger,
+      modulePath = 'path/to/log4js.json',
+      fakeFS = {
+        lastMtime: Date.now(),
+        config: { 
+          appenders: [ 
+            { type: 'console', layout: { type: 'messagePassThrough' } } 
+          ],
+          levels: { 'a-test' : 'INFO' } 
+        },
+        readFileSync: function (file, encoding) {
+          assert.equal(file, modulePath);
+          assert.equal(encoding, 'utf8');
+          return JSON.stringify(fakeFS.config);
+        },
+        statSync: function (path) {
+          pathsChecked.push(path);
+          if (path === modulePath) {
+            fakeFS.lastMtime += 1;
+            return { mtime: new Date(fakeFS.lastMtime) };
+          } else {
+            throw new Error("no such file");
+          }
+        }
+      },
+      fakeConsole = {
+        'name': 'console',
+        'appender': function () {
+          return function(evt) { logEvents.push(evt); };
+        },
+        'configure': function (config) {
+          return fakeConsole.appender();
+        }
+      },
+      setIntervalCallback,
+      fakeSetInterval = function(cb, timeout) {
+        setIntervalCallback = cb;
+      },
+      log4js = sandbox.require(
+        '../lib/log4js',
+        {
+          requires: {
+            'fs': fakeFS,
+            './appenders/console': fakeConsole
+          },
+          globals: {
+            'console': fakeConsole,
+            'setInterval' : fakeSetInterval,
+          }
+        }
+      );
+      
+      log4js.configure('path/to/log4js.json', { reloadSecs: 30 });
+      logger = log4js.getLogger('a-test');
+      logger.info("info1");
+      logger.debug("debug2 - should be ignored");
+      fakeFS.config.levels['a-test'] = "DEBUG";
+      setIntervalCallback();
+      logger.info("info3");
+      logger.debug("debug4");
+      
+      return logEvents;
+    },
+    'should configure log4js from first log4js.json found': function(logEvents) {
+      assert.equal(logEvents[0].data[0], 'info1');
+      assert.equal(logEvents[1].data[0], 'info3');
+      assert.equal(logEvents[2].data[0], 'debug4');
+      assert.equal(logEvents.length, 3);
+    }
+  },
+  
+  'with config file staying the same' : {
+    topic: function() {
+      var pathsChecked = [],
+      fileRead = 0,
+      logEvents = [],
+      logger,
+      modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
+      mtime = new Date(),
+      fakeFS = {
+        config: { 
+          appenders: [ 
+            { type: 'console', layout: { type: 'messagePassThrough' } } 
+          ],
+          levels: { 'a-test' : 'INFO' } 
+        },
+        readFileSync: function (file, encoding) {
+          fileRead += 1;
+          assert.isString(file);
+          assert.equal(file, modulePath);
+          assert.equal(encoding, 'utf8');
+          return JSON.stringify(fakeFS.config);
+        },
+        statSync: function (path) {
+          pathsChecked.push(path);
+          if (path === modulePath) {
+            return { mtime: mtime };
+          } else {
+            throw new Error("no such file");
+          }
+        }
+      },
+      fakeConsole = {
+        'name': 'console',
+        'appender': function () {
+          return function(evt) { logEvents.push(evt); };
+        },
+        'configure': function (config) {
+          return fakeConsole.appender();
+        }
+      },
+      setIntervalCallback,
+      fakeSetInterval = function(cb, timeout) {
+        setIntervalCallback = cb;
+      },
+      log4js = sandbox.require(
+        '../lib/log4js',
+        {
+          requires: {
+            'fs': fakeFS,
+            './appenders/console': fakeConsole
+          },
+          globals: {
+            'console': fakeConsole,
+            'setInterval' : fakeSetInterval,
+          }
+        }
+      );
+      
+      log4js.configure(modulePath, { reloadSecs: 3 });
+      logger = log4js.getLogger('a-test');
+      logger.info("info1");
+      logger.debug("debug2 - should be ignored");
+      setIntervalCallback();
+      logger.info("info3");
+      logger.debug("debug4");
+      
+      return [ pathsChecked, logEvents, modulePath, fileRead ];
+    },
+    'should only read the configuration file once': function(args) {
+      var fileRead = args[3];
+      assert.equal(fileRead, 1);
+    },
+    'should configure log4js from first log4js.json found': function(args) {
+      var logEvents = args[1];
+      assert.equal(logEvents.length, 2);
+      assert.equal(logEvents[0].data[0], 'info1');
+      assert.equal(logEvents[1].data[0], 'info3');
+    }
+  },
+
+  'when config file is removed': {
+    topic: function() {
+      var pathsChecked = [],
+      fileRead = 0,
+      logEvents = [],
+      logger,
+      modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
+      mtime = new Date(),
+      fakeFS = {
+        config: { 
+          appenders: [ 
+            { type: 'console', layout: { type: 'messagePassThrough' } } 
+          ],
+          levels: { 'a-test' : 'INFO' } 
+        },
+        readFileSync: function (file, encoding) {
+          fileRead += 1;
+          assert.isString(file);
+          assert.equal(file, modulePath);
+          assert.equal(encoding, 'utf8');
+          return JSON.stringify(fakeFS.config);
+        },
+        statSync: function (path) {
+          this.statSync = function() {
+            throw new Error("no such file");
+          };
+          return { mtime: new Date() };
+        }
+      },
+      fakeConsole = {
+        'name': 'console',
+        'appender': function () {
+          return function(evt) { logEvents.push(evt); };
+        },
+        'configure': function (config) {
+          return fakeConsole.appender();
+        }
+      },
+      setIntervalCallback,
+      fakeSetInterval = function(cb, timeout) {
+        setIntervalCallback = cb;
+      },
+      log4js = sandbox.require(
+        '../lib/log4js',
+        {
+          requires: {
+            'fs': fakeFS,
+            './appenders/console': fakeConsole
+          },
+          globals: {
+            'console': fakeConsole,
+            'setInterval' : fakeSetInterval,
+          }
+        }
+      );
+      
+      log4js.configure(modulePath, { reloadSecs: 3 });
+      logger = log4js.getLogger('a-test');
+      logger.info("info1");
+      logger.debug("debug2 - should be ignored");
+      setIntervalCallback();
+      logger.info("info3");
+      logger.debug("debug4");
+      
+      return [ pathsChecked, logEvents, modulePath, fileRead ];
+    },
+    'should only read the configuration file once': function(args) {
+      var fileRead = args[3];
+      assert.equal(fileRead, 1);
+    },
+    'should not clear configuration when config file not found': function(args) {
+      var logEvents = args[1];
+      assert.equal(logEvents.length, 3);
+      assert.equal(logEvents[0].data[0], 'info1');
+      assert.equal(logEvents[1].level.toString(), 'WARN');
+      assert.include(logEvents[1].data[0], 'Failed to load configuration file');
+      assert.equal(logEvents[2].data[0], 'info3');
+    }
+  },
+
+  'when passed an object': {
+    topic: function() {
+      var test = setupConsoleTest();
+      test.log4js.configure({}, { reloadSecs: 30 });
+      return test.logEvents;
+    },
+    'should log a warning': function(events) {
+      assert.equal(events[0].level.toString(), 'WARN');
+      assert.equal(
+        events[0].data[0], 
+        'Ignoring configuration reload parameter for "object" configuration.'
+      );
+    }
+  },
+
+  'when called twice with reload options': {
+    topic: function() {
+      var modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
+      fakeFS = {
+        readFileSync: function (file, encoding) {
+          return JSON.stringify({});
+        },
+        statSync: function (path) {
+          return { mtime: new Date() };
+        }
+      },
+      fakeConsole = {
+        'name': 'console',
+        'appender': function () {
+          return function(evt) { };
+        },
+        'configure': function (config) {
+          return fakeConsole.appender();
+        }
+      },
+      setIntervalCallback,
+      intervalCleared = false,
+      clearedId,
+      fakeSetInterval = function(cb, timeout) {
+        setIntervalCallback = cb;
+        return 1234;
+      },
+      log4js = sandbox.require(
+        '../lib/log4js',
+        {
+          requires: {
+            'fs': fakeFS,
+            './appenders/console': fakeConsole
+          },
+          globals: {
+            'console': fakeConsole,
+            'setInterval' : fakeSetInterval,
+            'clearInterval': function(interval) {
+              intervalCleared = true;
+              clearedId = interval;
+            }
+          }
+        }
+      );
+      
+      log4js.configure(modulePath, { reloadSecs: 3 });
+      log4js.configure(modulePath, { reloadSecs: 15 });
+      
+      return { cleared: intervalCleared, id: clearedId };
+    },
+    'should clear the previous interval': function(result) {
+      assert.isTrue(result.cleared);
+      assert.equal(result.id, 1234);
+    }
+  }
+}).exportTo(module);