From ce8b6b06b97fd3892ba75445c5a6563265b5bce0 Mon Sep 17 00:00:00 2001
From: Gareth Jones <gareth.jones@sensis.com.au>
Date: Mon, 5 Aug 2013 07:21:12 +1000
Subject: [PATCH 1/8] trying out a shutdown function

---
 lib/appenders/file.js | 19 ++++++++++++++++++-
 lib/log4js.js         | 20 ++++++++++++++++++++
 2 files changed, 38 insertions(+), 1 deletion(-)

diff --git a/lib/appenders/file.js b/lib/appenders/file.js
index da0e80b..b5b3fc8 100644
--- a/lib/appenders/file.js
+++ b/lib/appenders/file.js
@@ -1,5 +1,6 @@
 "use strict";
 var layouts = require('../layouts')
+, async = require('async')
 , path = require('path')
 , fs = require('fs')
 , streams = require('../streams')
@@ -61,7 +62,12 @@ function fileAppender (file, layout, logSize, numBackups) {
   openFiles.push(logFile);
   
   return function(loggingEvent) {
-    logFile.write(layout(loggingEvent) + eol, "utf8");
+    logFile.write(layout(loggingEvent) + eol, "utf8", 
+                  function() { 
+                    // just here to keep the event loop
+                    // open  - doesn't work.
+                    return; 
+                  });
   };
 }
 
@@ -78,5 +84,16 @@ function configure(config, options) {
   return fileAppender(config.filename, layout, config.maxLogSize, config.backups);
 }
 
+function shutdown(cb) {
+  async.forEach(openFiles, function(file, done) {
+    if (!file.write(eol, "utf-8")) {
+      file.once('drain', function() {
+        file.end(done);
+      });
+    }
+  }, cb);
+}  
+
 exports.appender = fileAppender;
 exports.configure = configure;
+exports.shutdown = shutdown;
diff --git a/lib/log4js.js b/lib/log4js.js
index fc3baca..c61272e 100644
--- a/lib/log4js.js
+++ b/lib/log4js.js
@@ -44,6 +44,7 @@
  * Website: http://log4js.berlios.de
  */
 var events = require('events')
+, async = require('async')
 , fs = require('fs')
 , path = require('path')
 , util = require('util')
@@ -301,6 +302,24 @@ function loadAppender(appender) {
   appenderMakers[appender] = appenderModule.configure.bind(appenderModule);
 }
 
+function shutdown(cb) {
+  var allAppenders = Object.keys(appenders).reduce(
+    function(accum, category) {
+      return accum.concat(appenders[category]);
+    }, []);
+  async.forEach(
+    allAppenders,
+    function(appender, done) {
+      if (appender.shutdown) {
+        appender.shutdown(done);
+      } else {
+        done();
+      }
+    },
+    cb
+  );
+}
+
 module.exports = {
   getLogger: getLogger,
   getDefaultLogger: getDefaultLogger,
@@ -309,6 +328,7 @@ module.exports = {
   loadAppender: loadAppender,
   clearAppenders: clearAppenders,
   configure: configure,
+  shutdown: shutdown,
   
   replaceConsole: replaceConsole,
   restoreConsole: restoreConsole,

From 9f77734f74f5519e31d83ffb17ee1cd526e93828 Mon Sep 17 00:00:00 2001
From: Gareth Jones <gareth.jones@sensis.com.au>
Date: Mon, 5 Aug 2013 07:55:07 +1000
Subject: [PATCH 2/8] test case for flush on exit

---
 examples/flush-on-exit.js | 27 +++++++++++++++++++++++++++
 1 file changed, 27 insertions(+)
 create mode 100644 examples/flush-on-exit.js

diff --git a/examples/flush-on-exit.js b/examples/flush-on-exit.js
new file mode 100644
index 0000000..19c661c
--- /dev/null
+++ b/examples/flush-on-exit.js
@@ -0,0 +1,27 @@
+/**
+ * run this, then "ab -c 10 -n 100 localhost:4444/" to test (in
+ * another shell)
+ */
+var log4js = require('../lib/log4js');
+log4js.configure({
+      appenders: [
+        { type: 'file', filename: 'cheese.log', category: 'cheese' },
+        { type: 'console'}
+  ]
+});
+
+var logger = log4js.getLogger('cheese');
+logger.setLevel('INFO');
+
+var http=require('http');
+
+var server = http.createServer(function(request, response){
+    response.writeHead(200, {'Content-Type': 'text/plain'});
+    var rd = Math.random() * 50;
+    logger.info("hello " + rd);
+    response.write('hello ');
+    if (Math.floor(rd) == 30){
+        log4js.shutdown(function() { process.exit(1); });
+    }
+    response.end();
+}).listen(4444);

From 2a38f460dc1103b23f9080bf816a90e180a9ffe3 Mon Sep 17 00:00:00 2001
From: Gareth Jones <gareth.jones@sensis.com.au>
Date: Mon, 5 Aug 2013 07:56:02 +1000
Subject: [PATCH 3/8] tried adding process.nexttick - didn't help

---
 lib/log4js.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/log4js.js b/lib/log4js.js
index c61272e..f89369c 100644
--- a/lib/log4js.js
+++ b/lib/log4js.js
@@ -316,7 +316,7 @@ function shutdown(cb) {
         done();
       }
     },
-    cb
+    function() { process.nextTick(cb); }
   );
 }
 

From 3ec9811b5edd22816e46adf477f36dc5b62794af Mon Sep 17 00:00:00 2001
From: John Engler <jengler@box.com>
Date: Sat, 5 Apr 2014 15:12:45 -0700
Subject: [PATCH 4/8] Update log4js module to expose a shutdown function.
 loadAppender will check for a shutdown function exposed by a loaded appender.
 If present, it will be cached so that the shutdown function can execute it.

The intent here is that a Node application would not invoked
process.exit until after the log4js shutdown callback returns.
---
 lib/log4js.js | 20 ++++++++++----------
 1 file changed, 10 insertions(+), 10 deletions(-)

diff --git a/lib/log4js.js b/lib/log4js.js
index f89369c..f2677ee 100644
--- a/lib/log4js.js
+++ b/lib/log4js.js
@@ -56,6 +56,7 @@ var events = require('events')
 , appenders = {}
 , loggers = {}
 , appenderMakers = {}
+, appenderShutdowns = {}
 , defaultConfig =   {
   appenders: [
     { type: "console" }
@@ -299,24 +300,23 @@ function loadAppender(appender) {
     appenderModule = require(appender);
   }
   module.exports.appenders[appender] = appenderModule.appender.bind(appenderModule);
+  if (appenderModule.shutdown) {
+    appenderShutdowns[appender] = appenderModule.shutdown.bind(appenderModule);
+  }
   appenderMakers[appender] = appenderModule.configure.bind(appenderModule);
 }
 
 function shutdown(cb) {
-  var allAppenders = Object.keys(appenders).reduce(
+  var shutdownFunctions = Object.keys(appenderShutdowns).reduce(
     function(accum, category) {
-      return accum.concat(appenders[category]);
+      return accum.concat(appenderShutdowns[category]);
     }, []);
   async.forEach(
-    allAppenders,
-    function(appender, done) {
-      if (appender.shutdown) {
-        appender.shutdown(done);
-      } else {
-        done();
-      }
+    shutdownFunctions,
+    function(shutdownFn, done) {
+      shutdownFn(done);
     },
-    function() { process.nextTick(cb); }
+		cb
   );
 }
 

From 8ca092cdb9fce0b4d22bf5e5a4f42b7a6ca67ff4 Mon Sep 17 00:00:00 2001
From: John Engler <jengler@box.com>
Date: Sat, 5 Apr 2014 16:14:56 -0700
Subject: [PATCH 5/8] Removed callback to write, as it is not needed.

---
 lib/appenders/file.js | 7 +------
 1 file changed, 1 insertion(+), 6 deletions(-)

diff --git a/lib/appenders/file.js b/lib/appenders/file.js
index b5b3fc8..a0c2869 100644
--- a/lib/appenders/file.js
+++ b/lib/appenders/file.js
@@ -62,12 +62,7 @@ function fileAppender (file, layout, logSize, numBackups) {
   openFiles.push(logFile);
   
   return function(loggingEvent) {
-    logFile.write(layout(loggingEvent) + eol, "utf8", 
-                  function() { 
-                    // just here to keep the event loop
-                    // open  - doesn't work.
-                    return; 
-                  });
+    logFile.write(layout(loggingEvent) + eol, "utf8");
   };
 }
 

From 633ed3cddbaef3809cab46ce3c2a15a7a92c01a3 Mon Sep 17 00:00:00 2001
From: John Engler <jengler@box.com>
Date: Mon, 7 Apr 2014 19:06:29 -0700
Subject: [PATCH 6/8] Support for disabling log writes on shutdown.

Updated logger.js to support disabling all log writes.
Updated log4js.js shutdown function to disable log writes.
Added tests.
Update gitignore to ignore rolling date stream's test output.
---
 .gitignore           |  1 +
 lib/log4js.js        | 21 ++++++++++++++--
 lib/logger.js        | 21 +++++++++++++++-
 test/logger-test.js  | 26 +++++++++++++++++++-
 test/logging-test.js | 58 +++++++++++++++++++++++++++++++++++++++++---
 5 files changed, 120 insertions(+), 7 deletions(-)

diff --git a/.gitignore b/.gitignore
index 279bc30..268c88d 100644
--- a/.gitignore
+++ b/.gitignore
@@ -4,3 +4,4 @@ build
 node_modules
 .bob/
 test/streams/test-rolling-file-stream*
+test/streams/test-rolling-stream-with-existing-files*
diff --git a/lib/log4js.js b/lib/log4js.js
index f2677ee..be5e2c4 100644
--- a/lib/log4js.js
+++ b/lib/log4js.js
@@ -50,8 +50,9 @@ var events = require('events')
 , util = require('util')
 , layouts = require('./layouts')
 , levels = require('./levels')
-, LoggingEvent = require('./logger').LoggingEvent
-, Logger = require('./logger').Logger
+, loggerModule = require('./logger')
+, LoggingEvent = loggerModule.LoggingEvent
+, Logger = loggerModule.Logger
 , ALL_CATEGORIES = '[all]'
 , appenders = {}
 , loggers = {}
@@ -306,11 +307,27 @@ function loadAppender(appender) {
   appenderMakers[appender] = appenderModule.configure.bind(appenderModule);
 }
 
+/**
+ * Shutdown all log appenders. This will first disable all writing to appenders
+ * and then call the shutdown function each appender.
+ *
+ * @params {Function} cb - The callback to be invoked once all appenders have
+ *  shutdown. If an error occurs, the callback will be given the error object
+ *  as the first argument.
+ * @returns {void}
+ */
 function shutdown(cb) {
+  // First, disable all writing to appenders. This prevents appenders from
+  // not being able to be drained because of run-away log writes.
+  loggerModule.disableAllLogWrites();
+
+  // Next, get all the shutdown functions for appenders as an array.
   var shutdownFunctions = Object.keys(appenderShutdowns).reduce(
     function(accum, category) {
       return accum.concat(appenderShutdowns[category]);
     }, []);
+
+  // Call each of the shutdown functions.
   async.forEach(
     shutdownFunctions,
     function(shutdownFn, done) {
diff --git a/lib/logger.js b/lib/logger.js
index 4da0daf..de2b41f 100644
--- a/lib/logger.js
+++ b/lib/logger.js
@@ -4,6 +4,8 @@ var levels = require('./levels')
 , events = require('events')
 , DEFAULT_CATEGORY = '[default]';
 
+var logWritesEnabled = true;
+
 /**
  * Models a logging event.
  * @constructor
@@ -66,7 +68,7 @@ Logger.prototype.isLevelEnabled = function(otherLevel) {
     };
     
     Logger.prototype[levelString.toLowerCase()] = function () {
-      if (this.isLevelEnabled(level)) {
+      if (logWritesEnabled && this.isLevelEnabled(level)) {
         var args = Array.prototype.slice.call(arguments);
         args.unshift(level);
         Logger.prototype.log.apply(this, args);
@@ -75,6 +77,23 @@ Logger.prototype.isLevelEnabled = function(otherLevel) {
   }
 );
 
+/**
+ * Disable all log writes.
+ * @returns {void}
+ */
+function disableAllLogWrites() {
+  logWritesEnabled = false;
+}
+
+/**
+ * Enable log writes.
+ * @returns {void}
+ */
+function enableAllLogWrites() {
+  logWritesEnabled = true;
+}
 
 exports.LoggingEvent = LoggingEvent;
 exports.Logger = Logger;
+exports.disableAllLogWrites = disableAllLogWrites;
+exports.enableAllLogWrites = enableAllLogWrites;
diff --git a/test/logger-test.js b/test/logger-test.js
index 55899f2..0bd29e1 100644
--- a/test/logger-test.js
+++ b/test/logger-test.js
@@ -2,7 +2,8 @@
 var vows = require('vows')
 , assert = require('assert')
 , levels = require('../lib/levels')
-, Logger = require('../lib/logger').Logger;
+, loggerModule = require('../lib/logger')
+, Logger = loggerModule.Logger;
 
 vows.describe('../lib/logger').addBatch({
   'constructor with no parameters': {
@@ -53,5 +54,28 @@ vows.describe('../lib/logger').addBatch({
       assert.isTrue(logger.isErrorEnabled());
       assert.isTrue(logger.isFatalEnabled());
     }
+  },
+
+  'should emit log events': {
+    topic: function() {
+      var events = [],
+          logger = new Logger();
+      logger.addListener('log', function (logEvent) { events.push(logEvent); });
+      logger.debug('Event 1');
+      loggerModule.disableAllLogWrites();
+      logger.debug('Event 2');
+      loggerModule.enableAllLogWrites();
+      logger.debug('Event 3');
+      return events;
+    },
+
+    'when log writes are enabled': function(events) {
+      assert.equal(events[0].data[0], 'Event 1');
+    },
+
+    'but not when log writes are disabled': function(events) {
+      assert.equal(events.length, 2);
+      assert.equal(events[1].data[0], 'Event 3');
+    }
   }
 }).exportTo(module);
diff --git a/test/logging-test.js b/test/logging-test.js
index 32ff099..a62de31 100644
--- a/test/logging-test.js
+++ b/test/logging-test.js
@@ -75,13 +75,65 @@ vows.describe('log4js').addBatch({
         assert.equal(events[1].level.toString(), 'WARN');
       },
       
-      'should include the error if passed in': function (events) {
+      'should include the error if passed in': function(events) {
         assert.instanceOf(events[2].data[1], Error);
         assert.equal(events[2].data[1].message, 'Pants are on fire!');
       }
-      
+    }
+  },
+
+  'when shutdown is called': {
+    topic: function() {
+      var events = {
+       appenderShutdownCalled: false,
+       shutdownCallbackCalled: false
+      },
+      log4js = sandbox.require(
+        '../lib/log4js',
+        {
+          requires: {
+            './appenders/file':
+            {
+              name: "file",
+              appender: function() {},
+              configure: function(configuration) {
+                return function() {};
+              },
+              shutdown: function(cb) {
+                events.appenderShutdownCalled = true;
+                cb();
+              }
+            }
+          }
+        }
+      ),
+      shutdownCallback = function() {
+        events.shutdownCallbackCalled = true;
+      },
+      config = { appenders:
+                 [ { "type" : "file",
+                     "filename" : "cheesy-wotsits.log",
+                     "maxLogSize" : 1024,
+                     "backups" : 3
+                   }
+                 ]
+               };
+
+      log4js.configure(config);
+      log4js.shutdown(shutdownCallback);
+      // Re-enable log writing so other tests that use logger are not
+      // affected.
+      require('../lib/logger').enableAllLogWrites();
+      return events;
     },
-    
+
+    'should invoke appender shutdowns': function(events) {
+      assert.ok(events.appenderShutdownCalled);
+    },
+
+    'should call callback': function(events) {
+      assert.ok(events.shutdownCallbackCalled);
+    }
   },
   
   'invalid configuration': {

From 3b5eb28115606cbcc3199f678ef45c64ae4d9ed9 Mon Sep 17 00:00:00 2001
From: John Engler <jengler@box.com>
Date: Tue, 8 Apr 2014 10:47:18 -0700
Subject: [PATCH 7/8] Update dateFile EOL usage to be consistent with appender.

From the looks of the Travis CI failure, this could be the issue
causing failures. Not sure as I can't reproduce locally. However,
it is still an inconsistency and worth fixing.
---
 test/dateFileAppender-test.js | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/test/dateFileAppender-test.js b/test/dateFileAppender-test.js
index 59355e2..3c61c70 100644
--- a/test/dateFileAppender-test.js
+++ b/test/dateFileAppender-test.js
@@ -4,7 +4,8 @@ var vows = require('vows')
 , path = require('path')
 , fs = require('fs')
 , sandbox = require('sandboxed-module')
-, log4js = require('../lib/log4js');
+, log4js = require('../lib/log4js')
+, EOL = require('os').EOL || '\n';
 
 function removeFile(filename) {
   return function() {
@@ -134,7 +135,7 @@ vows.describe('../lib/appenders/dateFile').addBatch({
       teardown: removeFile('date-file-test.log'),
       
       'should load appender configuration from a json file': function(err, contents) {
-        assert.include(contents, 'this should be written to the file' + require('os').EOL);
+        assert.include(contents, 'this should be written to the file' + EOL);
         assert.equal(contents.indexOf('this should not be written to the file'), -1);
       }
     },
@@ -161,7 +162,7 @@ vows.describe('../lib/appenders/dateFile').addBatch({
         , thisTime = format.asString(options.appenders[0].pattern, new Date());
         fs.writeFileSync(
           path.join(__dirname, 'date-file-test' + thisTime), 
-          "this is existing data" + require('os').EOL, 
+          "this is existing data" + EOL,
           'utf8'
         );
         log4js.clearAppenders();

From 6e3da6f44ba07fbf29339c365d46d39154a88c30 Mon Sep 17 00:00:00 2001
From: John Engler <jengler@box.com>
Date: Tue, 8 Apr 2014 12:40:27 -0700
Subject: [PATCH 8/8] Added error throwing when error loading test file.

This will hopefully give us better visibility into our Travis CI
build failures.
---
 test/dateFileAppender-test.js | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/test/dateFileAppender-test.js b/test/dateFileAppender-test.js
index 3c61c70..e64619d 100644
--- a/test/dateFileAppender-test.js
+++ b/test/dateFileAppender-test.js
@@ -135,6 +135,9 @@ vows.describe('../lib/appenders/dateFile').addBatch({
       teardown: removeFile('date-file-test.log'),
       
       'should load appender configuration from a json file': function(err, contents) {
+        if (err) {
+          throw err;
+        }
         assert.include(contents, 'this should be written to the file' + EOL);
         assert.equal(contents.indexOf('this should not be written to the file'), -1);
       }