x-forwarded-for

Remove GELF flag when capturing custom fields

.bob.json

@@ -0,0 +1,12 @@
+{
+  "build": "clean lint coverage test",
+  "lint": {
+    "type": "jshint"
+  },
+  "coverage": {
+    "type": "vows"
+  },
+  "test": {
+    "type": "vows"
+  }
+}

.gitignore

@@ -2,4 +2,7 @@
 *.log??
 build
 node_modules
-
+.bob/
+test/streams/test-rolling-file-stream*
+test/streams/test-rolling-stream-with-existing-files*
+.idea

.jshintrc

@@ -0,0 +1,15 @@
+{ 
+  "node": true,
+  "laxcomma": true,
+  "indent": 2,
+  "globalstrict": true,
+  "maxparams": 5,
+  "maxdepth": 3,
+  "maxstatements": 20,
+  "maxcomplexity": 5,
+  "maxlen": 100,
+  "globals": {
+    "describe": true,
+    "it": true
+  } 
+}

.travis.yml

@@ -1,4 +1,6 @@
 language: node_js
 node_js:
-  - 0.6
+  - "0.12"
-  - 0.8
+  - "0.10"
+  - "0.8"
+

README.md

@@ -1,7 +1,7 @@
 # log4js-node [![Build Status](https://secure.travis-ci.org/nomiddlename/log4js-node.png?branch=master)](http://travis-ci.org/nomiddlename/log4js-node)
 
 
-This is a conversion of the [log4js](http://log4js.berlios.de/index.html)
+This is a conversion of the [log4js](https://github.com/stritti/log4js)
 framework to work with [node](http://nodejs.org). I've mainly stripped out the browser-specific code and tidied up some of the javascript. 
 
 Out of the box it supports the following features:
@@ -12,6 +12,8 @@ Out of the box it supports the following features:
 * SMTP appender
 * GELF appender
 * hook.io appender
+* Loggly appender
+* Logstash UDP appender
 * multiprocess appender (useful when you've got worker processes)
 * a logger for connect/express servers
 * configurable log message layout/patterns
@@ -106,8 +108,9 @@ For FileAppender you can also pass the path to the log directory as an option wh
 log4js.configure('my_log4js_configuration.json', { cwd: '/absolute/path/to/log/dir' });
 ```
 If you have already defined an absolute path for one of the FileAppenders in the configuration file, you could add a "absolute": true to the particular FileAppender to override the cwd option passed. Here is an example configuration file:
-```json
+
 #### my_log4js_configuration.json ####
+```json
 {
   "appenders": [
     {
@@ -128,13 +131,15 @@ If you have already defined an absolute path for one of the FileAppenders in the
   ]
 }
 ```    
-Documentation for most of the core appenders can be found on the [wiki](log4js-node/wiki/Appenders), otherwise take a look at the tests and the examples.
+Documentation for most of the core appenders can be found on the [wiki](https://github.com/nomiddlename/log4js-node/wiki/Appenders), otherwise take a look at the tests and the examples.
 
 ## Documentation
-See the [wiki](log4js-node/wiki). Improve the [wiki](log4js-node/wiki), please.
+See the [wiki](https://github.com/nomiddlename/log4js-node/wiki). Improve the [wiki](https://github.com/nomiddlename/log4js-node/wiki), please.
+
+There's also [an example application](https://github.com/nomiddlename/log4js-example).
 
 ## Contributing
-Contributions welcome, but take a look at the [rules](log4js-node/wiki/Contributing) first.
+Contributions welcome, but take a look at the [rules](https://github.com/nomiddlename/log4js-node/wiki/Contributing) first.
 
 ## License
 

examples/example-connect-logger.js

@@ -1,14 +1,46 @@
-var log4js = require('./lib/log4js');
+//The connect/express logger was added to log4js by danbell. This allows connect/express servers to log using log4js.
-log4js.addAppender(log4js.fileAppender('cheese.log'), 'cheese');
+//https://github.com/nomiddlename/log4js-node/wiki/Connect-Logger
 
-var logger = log4js.getLogger('cheese');
+// load modules
-logger.setLevel('INFO');
+var log4js = require('log4js');
+var express = require("express");
+var app = express();
 
-var app = require('express').createServer();
+//config
+log4js.configure({
+	appenders: [
+		{ type: 'console' },
+		{ type: 'file', filename: 'logs/log4jsconnect.log', category: 'log4jslog' }
+	]
+});
+
+//define logger
+var logger = log4js.getLogger('log4jslog');
+
+// set at which time msg is logged print like: only on error & above
+// logger.setLevel('ERROR');
+
+//express app
 app.configure(function() {
-    app.use(log4js.connectLogger(logger, { level: log4js.levels.INFO }));
+	app.use(express.favicon(''));
+	// app.use(log4js.connectLogger(logger, { level: log4js.levels.INFO }));
+	// app.use(log4js.connectLogger(logger, { level: 'auto', format: ':method :url :status' }));
+
+	//### AUTO LEVEL DETECTION
+	//http responses 3xx, level = WARN
+	//http responses 4xx & 5xx, level = ERROR
+	//else.level = INFO
+	app.use(log4js.connectLogger(logger, { level: 'auto' }));
 });
-app.get('*', function(req,res) {
+
-    res.send('hello world\n <a href="/cheese">cheese</a>\n');
+//route
+app.get('/', function(req,res) {
+	res.send('hello world');
 });
+
+//start app
 app.listen(5000);
+
+console.log('server runing at localhost:5000');
+console.log('Simulation of normal response: goto localhost:5000');
+console.log('Simulation of error response: goto localhost:5000/xxx');

examples/example.js

@@ -1,4 +1,4 @@
-var log4js = require('./lib/log4js');
+var log4js = require('../lib/log4js');
 //log the cheese logger messages to a file, and the console ones as well.
 log4js.configure({
     appenders: [
@@ -35,11 +35,13 @@ logger.setLevel('ERROR');
 //console logging methods have been replaced with log4js ones.
 //so this will get coloured output on console, and appear in cheese.log
 console.error("AAArgh! Something went wrong", { some: "otherObject", useful_for: "debug purposes" });
+console.log("This should appear as info output");
 
 //these will not appear (logging level beneath error)
 logger.trace('Entering cheese testing');
 logger.debug('Got cheese.');
 logger.info('Cheese is Gouda.');
+logger.log('Something funny about cheese.');
 logger.warn('Cheese is quite smelly.');
 //these end up on the console and in cheese.log
 logger.error('Cheese %s is too ripe!', "gouda");

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);

examples/log-rolling.js

@@ -1,4 +1,4 @@
-var log4js = require('./lib/log4js')
+var log4js = require('../lib/log4js')
 , log
 , i = 0;
 log4js.configure({

examples/loggly-appender.js

@@ -0,0 +1,24 @@
+//Note that loggly appender needs node-loggly to work.
+//If you haven't got node-loggly installed, you'll get cryptic
+//"cannot find module" errors when using the loggly appender
+var log4js = require('../lib/log4js');
+
+log4js.configure({
+  "appenders": [
+    {
+      type: "console",
+      category: "test"
+    },
+    {
+      "type"     : "loggly",
+      "token"    : "12345678901234567890",
+      "subdomain": "your-subdomain",
+      "tags"     : ["test"],
+      "category" : "loggly"
+    }
+  ]
+});
+
+var logger = log4js.getLogger("loggly");
+logger.info("Test log message");
+//logger.debug("Test log message");

examples/logstashUDP.js

@@ -0,0 +1,39 @@
+var log4js = require('../lib/log4js');
+
+/*
+ Sample logstash config:
+   udp {
+    codec => json
+    port => 10001
+    queue_size => 2
+    workers => 2
+    type => myAppType
+  }
+*/
+
+log4js.configure({
+  "appenders": [
+    {
+      type: "console",
+      category: "myLogger"
+    },
+    {
+      "host": "127.0.0.1",
+      "port": 10001,
+      "type": "logstashUDP",
+      "logType": "myAppType", // Optional, defaults to 'category'
+      "fields": {             // Optional, will be added to the 'fields' object in logstash
+        "field1": "value1",
+        "field2": "value2"
+      },
+      "layout": {
+        "type": "pattern",
+        "pattern": "%m"
+      },
+      "category": "myLogger"
+    }
+  ]
+});
+
+var logger = log4js.getLogger("myLogger");
+logger.info("Test log message %s", "arg1", "arg2");

examples/smtp-appender.js

@@ -0,0 +1,43 @@
+//Note that smtp appender needs nodemailer to work.
+//If you haven't got nodemailer installed, you'll get cryptic
+//"cannot find module" errors when using the smtp appender
+var log4js = require('../lib/log4js')
+, log
+, logmailer
+, i = 0;
+log4js.configure({
+  "appenders": [
+    {
+      type: "console",
+      category: "test"
+    },
+    {
+      "type": "smtp",
+      "recipients": "logfilerecipient@logging.com",
+      "sendInterval": 5,
+      "transport": "SMTP",
+      "SMTP": {
+        "host": "smtp.gmail.com",
+        "secureConnection": true,
+        "port": 465,
+        "auth": {
+          "user": "someone@gmail",
+          "pass": "********************"
+        },
+        "debug": true
+      },
+      "category": "mailer"
+    }
+  ]
+});
+log = log4js.getLogger("test");
+logmailer = log4js.getLogger("mailer");
+
+function doTheLogging(x) {
+    log.info("Logging something %d", x);
+    logmailer.info("Logging something %d", x);
+}
+
+for ( ; i < 500; i++) {
+    doTheLogging(i);
+}

lib/appenders/categoryFilter.js

@@ -0,0 +1,20 @@
+"use strict";
+var log4js = require('../log4js');
+
+function categoryFilter (excludes, appender) {
+  if (typeof(excludes) === 'string') excludes = [excludes];
+  return function(logEvent) {
+    if (excludes.indexOf(logEvent.categoryName) === -1) {
+      appender(logEvent);
+    }
+  };
+}
+
+function configure(config) {
+  log4js.loadAppender(config.appender.type);
+  var appender = log4js.appenderMakers[config.appender.type](config.appender);
+  return categoryFilter(config.exclude, appender);
+}
+
+exports.appender = categoryFilter;
+exports.configure = configure;

lib/appenders/clustered.js

@@ -0,0 +1,138 @@
+"use strict";
+
+var cluster = require('cluster');
+var log4js = require('../log4js');
+
+/**
+ * Takes a loggingEvent object, returns string representation of it.
+ */
+function serializeLoggingEvent(loggingEvent) {
+	// JSON.stringify(new Error('test')) returns {}, which is not really useful for us.
+	// The following allows us to serialize errors correctly.
+	for (var i = 0; i < loggingEvent.data.length; i++) {
+		var item = loggingEvent.data[i];
+		if (item && item.stack && JSON.stringify(item) === '{}') { // Validate that we really are in this case
+			loggingEvent.data[i] = {stack : item.stack};
+		}
+	}
+	return JSON.stringify(loggingEvent);
+}
+
+/**
+ * Takes a string, returns an object with
+ * the correct log properties.
+ *
+ * This method has been "borrowed" from the `multiprocess` appender 
+ * by `nomiddlename` (https://github.com/nomiddlename/log4js-node/blob/master/lib/appenders/multiprocess.js)
+ *
+ * Apparently, node.js serializes everything to strings when using `process.send()`, 
+ * so we need smart deserialization that will recreate log date and level for further processing by log4js internals.
+ */
+function deserializeLoggingEvent(loggingEventString) {
+
+	var loggingEvent;
+	
+	try {
+	
+		loggingEvent = JSON.parse(loggingEventString);
+		loggingEvent.startTime = new Date(loggingEvent.startTime);
+		loggingEvent.level = log4js.levels.toLevel(loggingEvent.level.levelStr);
+		
+	} catch (e) {
+		
+		// JSON.parse failed, just log the contents probably a naughty.
+		loggingEvent = {
+			startTime: new Date(),
+			categoryName: 'log4js',
+			level: log4js.levels.ERROR,
+			data: [ 'Unable to parse log:', loggingEventString ]
+		};
+	}
+	return loggingEvent;
+} 
+
+/**
+ * Creates an appender. 
+ *
+ * If the current process is a master (`cluster.isMaster`), then this will be a "master appender".
+ * Otherwise this will be a worker appender, that just sends loggingEvents to the master process.
+ *
+ * If you are using this method directly, make sure to provide it with `config.actualAppenders` array 
+ * of actual appender instances.
+ *
+ * Or better use `configure(config, options)`
+ */
+function createAppender(config) {
+
+	if (cluster.isMaster) {
+
+		var masterAppender = function(loggingEvent) {
+	
+			if (config.actualAppenders) {
+				var size = config.actualAppenders.length;
+				for(var i = 0; i < size; i++) {
+			                if (!config.appenders[i].category || config.appenders[i].category === loggingEvent.categoryName) {
+						// Relying on the index is not a good practice but otherwise the change would have been bigger.
+						config.actualAppenders[i](loggingEvent);
+                    			}
+				}
+			}
+		}
+		
+		// Listen on new workers
+		cluster.on('fork', function(worker) {
+		
+			worker.on('message', function(message) {
+				if (message.type && message.type === '::log-message') {
+					// console.log("master : " + cluster.isMaster + " received message: " + JSON.stringify(message.event));
+					
+					var loggingEvent = deserializeLoggingEvent(message.event);
+					
+					// Adding PID metadata
+					loggingEvent.pid = worker.process.pid;
+					loggingEvent.cluster = {
+						master: process.pid,
+						worker: worker.process.pid,
+						workerId: worker.id
+					};
+					
+					masterAppender(loggingEvent);
+				}
+			});
+		
+		});
+		
+		return masterAppender;
+		
+	} else {
+
+		return function(loggingEvent) {
+			// If inside the worker process, then send the logger event to master.
+			if (cluster.isWorker) {
+				// console.log("worker " + cluster.worker.id + " is sending message");
+				process.send({ type: '::log-message', event: serializeLoggingEvent(loggingEvent)});
+			}
+		}
+	}
+}
+
+function configure(config, options) {
+
+	if (config.appenders && cluster.isMaster) {
+	
+		var size = config.appenders.length;
+		config.actualAppenders = new Array(size);
+	
+		for(var i = 0; i < size; i++) {
+		
+			log4js.loadAppender(config.appenders[i].type);
+			config.actualAppenders[i] = log4js.appenderMakers[config.appenders[i].type](config.appenders[i], options);
+		
+		}
+	}
+	
+	return createAppender(config);
+}
+
+exports.appender = createAppender;
+exports.configure = configure; 

lib/appenders/console.js

@@ -1,10 +1,11 @@
-var layouts = require('../layouts'),
+"use strict";
-    consoleLog = console.log;
+var layouts = require('../layouts')
+, consoleLog = console.log.bind(console);
 
-function consoleAppender (layout) {
+function consoleAppender (layout, timezoneOffset) {
   layout = layout || layouts.colouredLayout;
   return function(loggingEvent) {
-	consoleLog(layout(loggingEvent));
+    consoleLog(layout(loggingEvent, timezoneOffset));
   };
 }
 
@@ -13,7 +14,7 @@ function configure(config) {
   if (config.layout) {
     layout = layouts.layout(config.layout.type, config.layout);
   }
-    return consoleAppender(layout);
+  return consoleAppender(layout, config.timezoneOffset);
 }
 
 exports.appender = consoleAppender;

lib/appenders/dateFile.js

@@ -1,9 +1,11 @@
-var streams = require('../streams'),
+"use strict";
-    layouts = require('../layouts'),
+var streams = require('../streams')
-    path = require('path'),
+, layouts = require('../layouts')
-    os = require('os'),
+, async = require('async')
-    eol = os.EOL || '\n',
+, path = require('path')
-    openFiles = [];
+, os = require('os')
+, eol = os.EOL || '\n'
+, openFiles = [];
 
 //close open files on process exit.
 process.on('exit', function() {
@@ -18,15 +20,20 @@ process.on('exit', function() {
  * @pattern the format that will be added to the end of filename when rolling,
  *          also used to check when to roll files - defaults to '.yyyy-MM-dd'
  * @layout layout function for log messages - defaults to basicLayout
+ * @timezoneOffset optional timezone offset in minutes - defaults to system local
  */
-function appender(filename, pattern, layout) {
+function appender(filename, pattern, alwaysIncludePattern, layout, timezoneOffset) {
   layout = layout || layouts.basicLayout;
 
-    var logFile = new streams.BufferedWriteStream(new streams.DateRollingFileStream(filename, pattern));
+  var logFile = new streams.DateRollingFileStream(
+    filename,
+    pattern,
+    { alwaysIncludePattern: alwaysIncludePattern }
+  );
   openFiles.push(logFile);
 
   return function(logEvent) {
-        logFile.write(layout(logEvent) + eol, "utf8");
+    logFile.write(layout(logEvent, timezoneOffset) + eol, "utf8");
   };
 
 }
@@ -38,12 +45,29 @@ function configure(config, options) {
     layout = layouts.layout(config.layout.type, config.layout);
   }
 
+  if (!config.alwaysIncludePattern) {
+    config.alwaysIncludePattern = false;
+  }
+
   if (options && options.cwd && !config.absolute) {
     config.filename = path.join(options.cwd, config.filename);
   }
 
-    return appender(config.filename, config.pattern, layout);
+  return appender(config.filename, config.pattern, config.alwaysIncludePattern, layout, config.timezoneOffset);
+}
+
+function shutdown(cb) {
+  async.each(openFiles, function(file, done) {
+    if (!file.write(eol, "utf-8")) {
+      file.once('drain', function() {
+        file.end(done);
+      });
+    } else {
+      file.end(done);
+    }
+  }, cb);
 }
 
 exports.appender = appender;
 exports.configure = configure;
+exports.shutdown = shutdown;

lib/appenders/file.js

@@ -1,10 +1,13 @@
+"use strict";
 var layouts = require('../layouts')
-  , path = require('path')
+, async = require('async')
-  , fs = require('fs')
+, path = require('path')
-  , streams = require('../streams')
+, fs = require('fs')
-  , os = require('os')
+, streams = require('../streams')
-  , eol = os.EOL || '\n'
+, os = require('os')
-  , openFiles = [];
+, eol = os.EOL || '\n'
+, openFiles = []
+, levels = require('../levels');
 
 //close open files on process exit.
 process.on('exit', function() {
@@ -17,11 +20,16 @@ process.on('exit', function() {
  * File Appender writing the logs to a text file. Supports rolling of logs by size.
  *
  * @param file file log messages will be written to
- * @param layout a function that takes a logevent and returns a string (defaults to basicLayout).
+ * @param layout a function that takes a logevent and returns a string 
- * @param logSize - the maximum size (in bytes) for a log file, if not provided then logs won't be rotated.
+ *   (defaults to basicLayout).
- * @param numBackups - the number of log files to keep after logSize has been reached (default 5)
+ * @param logSize - the maximum size (in bytes) for a log file, 
+ *   if not provided then logs won't be rotated.
+ * @param numBackups - the number of log files to keep after logSize 
+ *   has been reached (default 5)
+ * @param compress - flag that controls log file compression
+ * @param timezoneOffset - optional timezone offset in minutes (default system local)
  */
-function fileAppender (file, layout, logSize, numBackups) {
+function fileAppender (file, layout, logSize, numBackups, compress, timezoneOffset) {
   var bytesWritten = 0;
   file = path.normalize(file);
   layout = layout || layouts.basicLayout;
@@ -32,15 +40,19 @@ function fileAppender (file, layout, logSize, numBackups) {
   function openTheStream(file, fileSize, numFiles) {
     var stream;
     if (fileSize) {
-            stream = new streams.BufferedWriteStream(
+      stream = new streams.RollingFileStream(
-                new streams.RollingFileStream(
         file,
         fileSize,
-                    numFiles
+        numFiles,
-                )
+        { "compress": compress }
       );
     } else {
-            stream = new streams.BufferedWriteStream(fs.createWriteStream(file, { encoding: "utf8", mode: 0644, flags: 'a' }));
+      stream = fs.createWriteStream(
+        file, 
+        { encoding: "utf8", 
+          mode: parseInt('0644', 8), 
+          flags: 'a' }
+      );
     }
     stream.on("error", function (err) {
       console.error("log4js.fileAppender - Writing to file %s, error happened ", file, err);
@@ -54,8 +66,9 @@ function fileAppender (file, layout, logSize, numBackups) {
   openFiles.push(logFile);
 
   return function(loggingEvent) {
-        logFile.write(layout(loggingEvent) + eol, "utf8");
+    logFile.write(layout(loggingEvent, timezoneOffset) + eol, "utf8");
   };
+
 }
 
 function configure(config, options) {
@@ -68,8 +81,21 @@ function configure(config, options) {
     config.filename = path.join(options.cwd, config.filename);
   }
 
-    return fileAppender(config.filename, layout, config.maxLogSize, config.backups);
+  return fileAppender(config.filename, layout, config.maxLogSize, config.backups, config.compress, config.timezoneOffset);
+}
+
+function shutdown(cb) {
+  async.each(openFiles, function(file, done) {
+    if (!file.write(eol, "utf-8")) {
+      file.once('drain', function() {
+        file.end(done);
+      });
+    } else {
+      file.end(done);
+    }
+  }, cb);
 }  
 
 exports.appender = fileAppender;
 exports.configure = configure;
+exports.shutdown = shutdown;

lib/appenders/fileSync.js

@@ -0,0 +1,189 @@
+"use strict";
+var debug = require('../debug')('fileSync')
+, layouts = require('../layouts')
+, path = require('path')
+, fs = require('fs')
+, streams = require('../streams')
+, os = require('os')
+, eol = os.EOL || '\n'
+;
+
+function RollingFileSync (filename, size, backups, options) {
+  debug("In RollingFileStream");
+
+  function throwErrorIfArgumentsAreNotValid() {
+    if (!filename || !size || size <= 0) {
+      throw new Error("You must specify a filename and file size");
+    }
+  }
+  
+  throwErrorIfArgumentsAreNotValid();
+  
+  this.filename = filename;
+  this.size = size;
+  this.backups = backups || 1;
+  this.options = options || { encoding: 'utf8', mode: parseInt('0644', 8), flags: 'a' };
+  this.currentSize = 0;
+  
+  function currentFileSize(file) {
+    var fileSize = 0;
+    try {
+      fileSize = fs.statSync(file).size;
+    } catch (e) {
+      // file does not exist
+      fs.appendFileSync(filename, '');
+    }
+    return fileSize;
+  }
+
+  this.currentSize = currentFileSize(this.filename);
+}
+
+RollingFileSync.prototype.shouldRoll = function() {
+  debug("should roll with current size %d, and max size %d", this.currentSize, this.size);
+  return this.currentSize >= this.size;
+};
+
+RollingFileSync.prototype.roll = function(filename) {
+  var that = this,
+  nameMatcher = new RegExp('^' + path.basename(filename));
+  
+  function justTheseFiles (item) {
+    return nameMatcher.test(item);
+  }
+  
+  function index(filename_) {
+    return parseInt(filename_.substring((path.basename(filename) + '.').length), 10) || 0;
+  }
+  
+  function byIndex(a, b) {
+    if (index(a) > index(b)) {
+      return 1;
+    } else if (index(a) < index(b) ) {
+      return -1;
+    } else {
+      return 0;
+    }
+  }
+
+  function increaseFileIndex (fileToRename) {
+    var idx = index(fileToRename);
+    debug('Index of ' + fileToRename + ' is ' + idx);
+    if (idx < that.backups) {
+      //on windows, you can get a EEXIST error if you rename a file to an existing file
+      //so, we'll try to delete the file we're renaming to first
+      try {
+        fs.unlinkSync(filename + '.' + (idx+1));
+      } catch(e) {
+        //ignore err: if we could not delete, it's most likely that it doesn't exist
+      }
+      
+      debug('Renaming ' + fileToRename + ' -> ' + filename + '.' + (idx+1));
+      fs.renameSync(path.join(path.dirname(filename), fileToRename), filename + '.' + (idx + 1));
+    }
+  }
+
+  function renameTheFiles() {
+    //roll the backups (rename file.n to file.n+1, where n <= numBackups)
+    debug("Renaming the old files");
+    
+    var files = fs.readdirSync(path.dirname(filename));
+    files.filter(justTheseFiles).sort(byIndex).reverse().forEach(increaseFileIndex);
+  }
+
+  debug("Rolling, rolling, rolling");
+  renameTheFiles();
+};
+
+RollingFileSync.prototype.write = function(chunk, encoding) {
+  var that = this;
+  
+  
+  function writeTheChunk() {
+    debug("writing the chunk to the file");
+    that.currentSize += chunk.length;
+    fs.appendFileSync(that.filename, chunk);
+  }
+
+  debug("in write");
+  
+
+  if (this.shouldRoll()) {
+    this.currentSize = 0;
+    this.roll(this.filename);
+  }
+  
+  writeTheChunk();
+};
+
+
+/**
+ * File Appender writing the logs to a text file. Supports rolling of logs by size.
+ *
+ * @param file file log messages will be written to
+ * @param layout a function that takes a logevent and returns a string 
+ *   (defaults to basicLayout).
+ * @param logSize - the maximum size (in bytes) for a log file, 
+ *   if not provided then logs won't be rotated.
+ * @param numBackups - the number of log files to keep after logSize 
+ *   has been reached (default 5)
+ * @param timezoneOffset - optional timezone offset in minutes
+ *   (default system local)
+ */
+function fileAppender (file, layout, logSize, numBackups, timezoneOffset) {
+  debug("fileSync appender created");
+  var bytesWritten = 0;
+  file = path.normalize(file);
+  layout = layout || layouts.basicLayout;
+  numBackups = numBackups === undefined ? 5 : numBackups;
+  //there has to be at least one backup if logSize has been specified
+  numBackups = numBackups === 0 ? 1 : numBackups;
+
+  function openTheStream(file, fileSize, numFiles) {
+    var stream;
+    
+    if (fileSize) {
+      stream = new RollingFileSync(
+        file,
+        fileSize,
+        numFiles
+      );
+    } else {
+      stream = (function(f) {
+        // create file if it doesn't exist
+        if (!fs.existsSync(f))
+            fs.appendFileSync(f, '');
+        
+        return {
+            write: function(data) {
+                fs.appendFileSync(f, data);
+            }
+        };
+      })(file);
+    }
+
+    return stream;
+  }
+
+  var logFile = openTheStream(file, logSize, numBackups);
+  
+  return function(loggingEvent) {
+    logFile.write(layout(loggingEvent, timezoneOffset) + eol);
+  };
+}
+
+function configure(config, options) {
+  var layout;
+  if (config.layout) {
+    layout = layouts.layout(config.layout.type, config.layout);
+  }
+
+  if (options && options.cwd && !config.absolute) {
+    config.filename = path.join(options.cwd, config.filename);
+  }
+
+  return fileAppender(config.filename, layout, config.maxLogSize, config.backups, config.timezoneOffset);
+}
+
+exports.appender = fileAppender;
+exports.configure = configure;

lib/appenders/gelf.js

@@ -1,8 +1,10 @@
+"use strict";
 var zlib = require('zlib');
 var layouts = require('../layouts');
 var levels = require('../levels');
 var dgram = require('dgram');
 var util = require('util');
+var debug = require('../debug')('GELF Appender');
 
 var LOG_EMERG=0;    // system is unusable
 var LOG_ALERT=1;    // action must be taken immediately
@@ -33,29 +35,78 @@ levelMapping[levels.FATAL] = LOG_CRIT;
  * @param facility - facility to log to (default:nodejs-server)
  */
 function gelfAppender (layout, host, port, hostname, facility) {
+  var config, customFields;
+  if (typeof(host) === 'object') {
+    config = host;
+    host = config.host;
+    port = config.port;
+    hostname = config.hostname;
+    facility = config.facility;
+    customFields = config.customFields;
+  }
   
   host = host || 'localhost';
   port = port || 12201;
   hostname = hostname || require('os').hostname();
-    facility = facility || 'nodejs-server';
   layout = layout || layouts.messagePassThroughLayout;
 
+  var defaultCustomFields = customFields || {};
+
+  if(facility) {
+    defaultCustomFields['_facility'] = facility;
+  }
+
   var client = dgram.createSocket("udp4");
   
   process.on('exit', function() {
     if (client) client.close();
   });
 
+  /**
+   * Add custom fields (start with underscore ) 
+   * - if the first object passed to the logger contains 'GELF' field, 
+   *   copy the underscore fields to the message
+   * @param loggingEvent
+   * @param msg
+   */
+  function addCustomFields(loggingEvent, msg){
+
+    /* append defaultCustomFields firsts */
+    Object.keys(defaultCustomFields).forEach(function(key) {
+      // skip _id field for graylog2, skip keys not starts with UNDERSCORE
+      if (key.match(/^_/) && key !== "_id") { 
+        msg[key] = defaultCustomFields[key];
+      }
+    });
+
+    /* append custom fields per message */
+    var data = loggingEvent.data;
+    if (!Array.isArray(data) || data.length === 0) return;
+    var firstData = data[0];
+    
+    if (!firstData.GELF) return; // identify with GELF field defined
+    // Remove the GELF key, some gelf supported logging systems drop the message with it
+    delete firstData.GELF;
+    Object.keys(firstData).forEach(function(key) {
+      // skip _id field for graylog2, skip keys not starts with UNDERSCORE
+      if (key.match(/^_/) || key !== "_id") { 
+        msg[key] = firstData[key];
+      }
+    });
+    
+    /* the custom field object should be removed, so it will not be looged by the later appenders */
+    loggingEvent.data.shift(); 
+  }
+ 
   function preparePacket(loggingEvent) {
     var msg = {};
-        msg.full_message = layout(loggingEvent);
+    addCustomFields(loggingEvent, msg);
-        msg.short_message = msg.full_message;
+    msg.short_message = layout(loggingEvent);
     
-        msg.version="1.0";
+    msg.version="1.1";
-        msg.timestamp = msg.timestamp || new Date().getTime() / 1000 >> 0;
+    msg.timestamp = msg.timestamp || new Date().getTime() / 1000; // log should use millisecond 
     msg.host = hostname;
     msg.level = levelMapping[loggingEvent.level || levels.DEBUG];
-        msg.facility = facility;
     return msg;
   }
   
@@ -72,7 +123,7 @@ function gelfAppender (layout, host, port, hostname, facility) {
         console.error(err.stack);
       } else {
         if (packet.length > 8192) {
-                    util.debug("Message packet length (" + packet.length + ") is larger than 8k. Not sending");
+          debug("Message packet length (" + packet.length + ") is larger than 8k. Not sending");
         } else {
           sendPacket(packet);
         }
@@ -86,7 +137,7 @@ function configure(config) {
   if (config.layout) {
     layout = layouts.layout(config.layout.type, config.layout);
   }
-    return gelfAppender(layout, config.host, config.port, config.hostname, config.facility);
+  return gelfAppender(layout, config);
 }
 
 exports.appender = gelfAppender;

lib/appenders/hookio.js

@@ -1,75 +0,0 @@
-var log4js = require('../log4js');
-var layouts = require('../layouts');
-var Hook = require('hook.io').Hook;
-var util = require('util');
-
-var Logger = function createLogger(options) {
-  var self = this;
-  var actualAppender = options.actualAppender;
-  Hook.call(self, options);
-  self.on('hook::ready', function hookReady() {
-    self.on('*::' + options.name + '::log', function log(loggingEvent) {
-      deserializeLoggingEvent(loggingEvent);
-      actualAppender(loggingEvent);
-    });
-  });
-}
-util.inherits(Logger, Hook);
-
-function deserializeLoggingEvent(loggingEvent) {
-  loggingEvent.startTime = new Date(loggingEvent.startTime);
-  loggingEvent.level.toString = function levelToString() {
-    return loggingEvent.level.levelStr;
-  };
-}
-
-function initHook(hookioOptions) {
-  var loggerHook;
-  if (hookioOptions.mode === 'master') {
-    // Start the master hook, handling the actual logging
-    loggerHook = new Logger(hookioOptions);
-  } else {
-    // Start a worker, just emitting events for a master
-    loggerHook = new Hook(hookioOptions);
-  }
-  loggerHook.start();
-  return loggerHook;
-}
-
-function getBufferedHook(hook, eventName) {
-  var hookBuffer = [];
-  var hookReady = false;
-  hook.on('hook::ready', function emptyBuffer() {
-    hookBuffer.forEach(function logBufferItem(loggingEvent) {
-      hook.emit(eventName, loggingEvent);
-    })
-    hookReady = true;
-  });
-
-  return function log(loggingEvent) {
-    if (hookReady) {
-      hook.emit(eventName, loggingEvent);
-    } else {
-      hookBuffer.push(loggingEvent);
-    }
-  }
-}
-
-function createAppender(hookioOptions) {
-  var loggerHook = initHook(hookioOptions);
-  var loggerEvent = hookioOptions.name + '::log';
-  return getBufferedHook(loggerHook, loggerEvent);
-}
-
-function configure(config) {
-  var actualAppender;
-  if (config.appender && config.mode === 'master') {
-    log4js.loadAppender(config.appender.type);
-    actualAppender = log4js.appenderMakers[config.appender.type](config.appender);
-    config.actualAppender = actualAppender;
-  }
-  return createAppender(config);
-}
-
-exports.appender = createAppender;
-exports.configure = configure;

lib/appenders/logLevelFilter.js

@@ -1,19 +1,22 @@
-var levels = require('../levels');
+"use strict";
-var log4js = require('../log4js');
+var levels = require('../levels')
+, log4js = require('../log4js');
 
-function logLevelFilter (levelString, appender) {
+function logLevelFilter (minLevelString, maxLevelString, appender) {
-    var level = levels.toLevel(levelString);
+  var minLevel = levels.toLevel(minLevelString);
+  var maxLevel = levels.toLevel(maxLevelString, levels.FATAL);
   return function(logEvent) {
-	if (logEvent.level.isGreaterThanOrEqualTo(level)) {
+      var eventLevel = logEvent.level;
+      if (eventLevel.isGreaterThanOrEqualTo(minLevel) && eventLevel.isLessThanOrEqualTo(maxLevel)) {
       appender(logEvent);
     }
-    }
+  };
 }
 
-function configure(config) {
+function configure(config, options) {
   log4js.loadAppender(config.appender.type);
-    var appender = log4js.appenderMakers[config.appender.type](config.appender);
+  var appender = log4js.appenderMakers[config.appender.type](config.appender, options);
-    return logLevelFilter(config.level, appender);
+  return logLevelFilter(config.level, config.maxLevel, appender);
 }
 
 exports.appender = logLevelFilter;

lib/appenders/loggly.js

@@ -0,0 +1,44 @@
+'use strict';
+var layouts = require('../layouts')
+, loggly = require('loggly')
+, os = require('os')
+, passThrough = layouts.messagePassThroughLayout;
+
+
+/**
+ * Loggly Appender. Sends logging events to Loggly using node-loggly 
+ *
+ * @param config object with loggly configuration data
+ * {
+ *   token: 'your-really-long-input-token',
+ *   subdomain: 'your-subdomain',
+ *   tags: ['loggly-tag1', 'loggly-tag2', .., 'loggly-tagn'] 
+ * }
+ * @param layout a function that takes a logevent and returns a string (defaults to objectLayout).
+ */
+function logglyAppender(config, layout) {
+	var client = loggly.createClient(config);
+  if(!layout) layout = passThrough;
+
+  return function(loggingEvent) {
+		var msg = layout(loggingEvent);
+		client.log({
+			msg: msg,
+			level: loggingEvent.level.levelStr,
+			category: loggingEvent.categoryName,
+			hostname: os.hostname().toString(),
+		});
+  }
+}
+
+function configure(config) {
+	var layout;
+	if (config.layout) {
+		layout = layouts.layout(config.layout.type, config.layout);
+	}
+	return logglyAppender(config, layout);
+}
+
+exports.name      = 'loggly';
+exports.appender  = logglyAppender;
+exports.configure = configure;

lib/appenders/logstashUDP.js

@@ -0,0 +1,50 @@
+"use strict";
+var layouts = require('../layouts')
+, dgram = require('dgram')
+, util = require('util');
+
+function logstashUDP (config, layout) {
+  var udp = dgram.createSocket('udp4');
+  var type = config.logType ? config.logType : config.category;
+  layout = layout || layouts.colouredLayout;
+  if(!config.fields) {
+    config.fields = {};
+  }
+  return function(loggingEvent) {
+    var logMessage = layout(loggingEvent);
+    var fields = {};
+    for(var i in config.fields) {
+      fields[i] = config.fields[i];
+    }
+    fields['level'] = loggingEvent.level.levelStr;
+    var logObject = {
+      '@timestamp': (new Date(loggingEvent.startTime)).toISOString(),
+      type: type,
+      message: logMessage,
+      fields: fields
+    };
+    sendLog(udp, config.host, config.port, logObject);
+  };
+}
+
+function sendLog(udp, host, port, logObject) {
+  var buffer = new Buffer(JSON.stringify(logObject));
+  udp.send(buffer, 0, buffer.length, port, host, function(err, bytes) {
+    if(err) {
+      console.error(
+        "log4js.logstashUDP - %s:%p Error: %s", host, port, util.inspect(err)
+      );
+    }
+  });
+}
+
+function configure(config) {
+  var layout;
+  if (config.layout) {
+    layout = layouts.layout(config.layout.type, config.layout);
+  }
+  return logstashUDP(config, layout);
+}
+
+exports.appender = logstashUDP;
+exports.configure = configure;

lib/appenders/multiprocess.js

@@ -1,6 +1,7 @@
-var log4js = require('../log4js'),
+"use strict";
-    net = require('net'),
+var log4js = require('../log4js')
-    END_MSG = '__LOG4JS__';
+, net = require('net')
+, END_MSG = '__LOG4JS__';
 
 /**
  * Creates a server, listening on config.loggerPort, config.loggerHost.
@@ -38,7 +39,6 @@ function logServer(config) {
   var actualAppender = config.actualAppender,
   server = net.createServer(function serverCreated(clientSocket) {
     clientSocket.setEncoding('utf8');
-            clientSocket.on('connect', function clientConnected() {
     var logMessage = '';
     
     function logTheMessage(msg) {
@@ -62,7 +62,7 @@ function logServer(config) {
     clientSocket.on('data', chunkReceived);
     clientSocket.on('end', chunkReceived);
   });
-        });
+  
   server.listen(config.loggerPort || 5000, config.loggerHost || 'localhost');
   
   return actualAppender;
@@ -94,6 +94,11 @@ function workerAppender(config) {
   }
   
   function write(loggingEvent) {
+	// JSON.stringify(new Error('test')) returns {}, which is not really useful for us.
+	// The following allows us to serialize errors correctly.
+	if (loggingEvent && loggingEvent.stack && JSON.stringify(loggingEvent) === '{}') { // Validate that we really are in this case
+		loggingEvent = {stack : loggingEvent.stack};
+	}
     socket.write(JSON.stringify(loggingEvent), 'utf8');
     socket.write(END_MSG, 'utf8');
   }

lib/appenders/smtp.js

@@ -1,14 +1,21 @@
-var layouts = require("../layouts"),
+"use strict";
-	mailer = require("nodemailer"),
+var layouts = require("../layouts")
-	os = require('os');
+, mailer = require("nodemailer")
+, os = require('os')
+, async = require('async')
+, unsentCount = 0
+, shutdownTimeout;
 
 /**
 * SMTP Appender. Sends logging events using SMTP protocol. 
-* It can either send an email on each event or group several logging events gathered during specified interval.
+* It can either send an email on each event or group several 
+* logging events gathered during specified interval.
 *
 * @param config appender configuration data
+*    config.sendInterval time between log emails (in seconds), if 0
+*    then every event sends an email
+*    config.shutdownTimeout time to give up remaining emails (in seconds; defaults to 5).
 * @param layout a function that takes a logevent and returns a string (defaults to basicLayout).
-* all events are buffered and sent in one email during this time; if 0 than every event sends an email
 */
 function smtpAppender(config, layout) {
 	layout = layout || layouts.basicLayout;
@@ -17,47 +24,62 @@ function smtpAppender(config, layout) {
 	
 	var logEventBuffer = [];
 	var sendTimer;
-	var transport = mailer.createTransport(config.transport, config[config.transport]);
+	
+	shutdownTimeout = ('shutdownTimeout' in config ? config.shutdownTimeout : 5) * 1000;
 	
 	function sendBuffer() {
-		if (logEventBuffer.length == 0)
+    if (logEventBuffer.length > 0) {
-			return;
 		
+      var transport = mailer.createTransport(config.SMTP);
       var firstEvent = logEventBuffer[0];
       var body = "";
+      var count = logEventBuffer.length;
       while (logEventBuffer.length > 0) {
-			body += layout(logEventBuffer.shift()) + "\n";
+        body += layout(logEventBuffer.shift(), config.timezoneOffset) + "\n";
       }
 
       var msg = {
         to: config.recipients,
         subject: config.subject || subjectLayout(firstEvent),
-				text: body,
+        headers: { "Hostname": os.hostname() }
-				headers: {"Hostname": os.hostname()}
       };
-		if (config.sender)
+	  
+      if (!config.html) {
+	msg.text = body;
+      } else {
+    	msg.html = body;
+      }
+      
+      if (config.sender) {
         msg.from = config.sender;
+      }
       transport.sendMail(msg, function(error, success) {
         if (error) {
-				console.error("log4js.smtpAppender - Error happened ", error);
+          console.error("log4js.smtpAppender - Error happened", error);
         }
+        transport.close();
+        unsentCount -= count;
       });
+    }
 	}
 	
 	function scheduleSend() {
-		if (!sendTimer)
+		if (!sendTimer) {
 			sendTimer = setTimeout(function() {
 				sendTimer = null; 
 				sendBuffer();
 			}, sendInterval);
+    }
 	}
 	
 	return function(loggingEvent) {
+		unsentCount++;
 		logEventBuffer.push(loggingEvent);
-		if (sendInterval > 0)
+		if (sendInterval > 0) {
 			scheduleSend();
-		else
+		} else {
 			sendBuffer();
+    }
 	};
 }
 
@@ -69,7 +91,19 @@ function configure(config) {
 	return smtpAppender(config, layout);
 }
 
+function shutdown(cb) {
+	if (shutdownTimeout > 0) {
+		setTimeout(function() { unsentCount = 0; }, shutdownTimeout);
+	}
+	async.whilst(function() {
+		return unsentCount > 0;
+	}, function(done) {
+		setTimeout(done, 100);
+	}, cb);
+}
+
 exports.name = "smtp";
 exports.appender = smtpAppender;
 exports.configure = configure;
+exports.shutdown = shutdown;
 

lib/connect-logger.js

@@ -1,11 +1,17 @@
+"use strict";
 var levels = require("./levels");
+var _ = require('underscore');
+var DEFAULT_FORMAT = ':remote-addr - -' +
+  ' ":method :url HTTP/:http-version"' +
+  ' :status :content-length ":referrer"' +
+  ' ":user-agent"';
 /**
  * Log requests with the given `options` or a `format` string.
  *
  * Options:
  *
  *   - `format`        Format string, see below for tokens
- *   - `level`         A log4js levels instance.
+ *   - `level`         A log4js levels instance. Supports also 'auto'
  *
  * Tokens:
  *
@@ -37,23 +43,20 @@ function getLogger(logger4js, options) {
 
 	var thislogger = logger4js
   , level = levels.toLevel(options.level, levels.INFO)
-  , fmt = options.format || ':remote-addr - - ":method :url HTTP/:http-version" :status :content-length ":referrer" ":user-agent"'
+  , fmt = options.format || DEFAULT_FORMAT
   , nolog = options.nolog ? createNoLogCondition(options.nolog) : null;
 
   return function (req, res, next) {
-
     // mount safety
     if (req._logging) return next();
 
 		// nologs
 		if (nolog && nolog.test(req.originalUrl)) return next();
+		if (thislogger.isLevelEnabled(level) || options.level === 'auto') {
 
-	if (thislogger.isLevelEnabled(level)) {
+			var start = new Date()
-
-	    var start = +new Date
 			, statusCode
 			, writeHead = res.writeHead
-	  , end = res.end
 			, url = req.originalUrl;
 
 			// flag as logging
@@ -65,20 +68,36 @@ function getLogger(logger4js, options) {
 				res.writeHead(code, headers);
 				res.__statusCode = statusCode = code;
 				res.__headers = headers || {};
-	    };
 
-	    // proxy end to output a line to the provided logger.
+				//status code response level handling
-	    res.end = function(chunk, encoding) {
+				if(options.level === 'auto'){
-		res.end = end;
+					level = levels.INFO;
-		res.end(chunk, encoding);
+					if(code >= 300) level = levels.WARN;
-		res.responseTime = +new Date - start;
+					if(code >= 400) level = levels.ERROR;
-		if ('function' == typeof fmt) {
-		    var line = fmt(req, res, function(str){ return format(str, req, res); });
-		    if (line) thislogger.log(level, line);
 				} else {
-		    thislogger.log(level, format(fmt, req, res));
+					level = levels.toLevel(options.level, levels.INFO);
 				}
 			};
+
+			//hook on end request to emit the log entry of the HTTP request.
+			res.on('finish', function() {
+				res.responseTime = new Date() - start;
+				//status code response level handling
+				if(res.statusCode && options.level === 'auto'){
+					level = levels.INFO;
+					if(res.statusCode >= 300) level = levels.WARN;
+					if(res.statusCode >= 400) level = levels.ERROR;
+				}
+				if (thislogger.isLevelEnabled(level)) {
+          var combined_tokens = assemble_tokens(req, res, options.tokens || []);
+					if (typeof fmt === 'function') {
+						var line = fmt(req, res, function(str){ return format(str, combined_tokens); });
+						if (line) thislogger.log(level, line);
+					} else {
+						thislogger.log(level, format(fmt, combined_tokens));
+					}
+				}
+			});
 		}
 
     //ensure next gets always called
@@ -86,6 +105,52 @@ function getLogger(logger4js, options) {
   };
 }
 
+/**
+ * Adds custom {token, replacement} objects to defaults, overwriting the defaults if any tokens clash
+ *
+ * @param  {IncomingMessage} req
+ * @param  {ServerResponse} res
+ * @param  {Array} custom_tokens [{ token: string-or-regexp, replacement: string-or-replace-function }]
+ * @return {Array}
+ */
+function assemble_tokens(req, res, custom_tokens) {
+  var array_unique_tokens = function(array) {
+    var a = array.concat();
+    for(var i=0; i<a.length; ++i) {
+      for(var j=i+1; j<a.length; ++j) {
+        if(a[i].token == a[j].token) { // not === because token can be regexp object
+          a.splice(j--, 1);
+        }
+      }
+    }
+    return a;
+  };
+
+  var default_tokens = [];
+  default_tokens.push({ token: ':url', replacement: req.originalUrl });
+  default_tokens.push({ token: ':method', replacement: req.method });
+  default_tokens.push({ token: ':status', replacement: res.__statusCode || res.statusCode });
+  default_tokens.push({ token: ':response-time', replacement: res.responseTime });
+  default_tokens.push({ token: ':date', replacement: new Date().toUTCString() });
+  default_tokens.push({ token: ':referrer', replacement: req.headers.referer || req.headers.referrer || '' });
+  default_tokens.push({ token: ':http-version', replacement: req.httpVersionMajor + '.' + req.httpVersionMinor });
+  default_tokens.push({ token: ':remote-addr', replacement: req.headers['x-forwarded-for'] || req.ip || req._remoteAddress ||
+    (req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress))) });
+  default_tokens.push({ token: ':user-agent', replacement: req.headers['user-agent'] });
+  default_tokens.push({ token: ':content-length', replacement: (res._headers && res._headers['content-length']) ||
+      (res.__headers && res.__headers['Content-Length']) || '-' });
+  default_tokens.push({ token: /:req\[([^\]]+)\]/g, replacement: function(_, field) {
+    return req.headers[field.toLowerCase()];
+  } });
+  default_tokens.push({ token: /:res\[([^\]]+)\]/g, replacement: function(_, field) {
+    return res._headers ?
+      (res._headers[field.toLowerCase()] || res.__headers[field])
+      : (res.__headers && res.__headers[field]);
+  } });
+
+  return array_unique_tokens(custom_tokens.concat(default_tokens));
+};
+
 /**
  * Return formatted log line.
  *
@@ -96,24 +161,10 @@ function getLogger(logger4js, options) {
  * @api private
  */
 
-function format(str, req, res) {
+function format(str, tokens) {
-    return str
+  return _.reduce(tokens, function(current_string, token) {
-      .replace(':url', req.originalUrl)
+    return current_string.replace(token.token, token.replacement);
-	.replace(':method', req.method)
+  }, str);
-	  .replace(':status', res.__statusCode || res.statusCode)
-	    .replace(':response-time', res.responseTime)
-	      .replace(':date', new Date().toUTCString())
-		.replace(':referrer', req.headers['referer'] || req.headers['referrer'] || '')
-		  .replace(':http-version', req.httpVersionMajor + '.' + req.httpVersionMinor)
-		    .replace(':remote-addr', req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress)))
-		      .replace(':user-agent', req.headers['user-agent'] || '')
-                        .replace(':content-length', (res._headers && res._headers['content-length']) || (res.__headers && res.__headers['Content-Length']) || '-')
-		          .replace(/:req\[([^\]]+)\]/g, function(_, field){ return req.headers[field.toLowerCase()]; })
-		            .replace(/:res\[([^\]]+)\]/g, function(_, field){
-		                return res._headers
-			      ? (res._headers[field.toLowerCase()] || res.__headers[field])
-			      : (res.__headers && res.__headers[field]);
-		            });
 }
 
 /**
@@ -122,17 +173,17 @@ function format(str, req, res) {
  * @param  {String} nolog
  * @return {RegExp}
  * @api private
- */
+ *
-
-/**
  * syntax
  *  1. String
  *   1.1 "\\.gif"
  *         NOT LOGGING http://example.com/hoge.gif and http://example.com/hoge.gif?fuga
  *         LOGGING http://example.com/hoge.agif
  *   1.2 in "\\.gif|\\.jpg$"
- *         NOT LOGGING http://example.com/hoge.gif and http://example.com/hoge.gif?fuga and http://example.com/hoge.jpg?fuga
+ *         NOT LOGGING http://example.com/hoge.gif and
- *         LOGGING http://example.com/hoge.agif, http://example.com/hoge.ajpg and http://example.com/hoge.jpg?hoge
+ *           http://example.com/hoge.gif?fuga and http://example.com/hoge.jpg?fuga
+ *         LOGGING http://example.com/hoge.agif,
+ *           http://example.com/hoge.ajpg and http://example.com/hoge.jpg?hoge
  *   1.3 in "\\.(gif|jpe?g|png)$"
  *         NOT LOGGING http://example.com/hoge.gif and http://example.com/hoge.jpeg
  *         LOGGING http://example.com/hoge.gif?uid=2 and http://example.com/hoge.jpg?pid=3
@@ -143,26 +194,29 @@ function format(str, req, res) {
  *   3.1 ["\\.jpg$", "\\.png", "\\.gif"]
  *         SAME AS "\\.jpg|\\.png|\\.gif"
  */
-function createNoLogCondition(nolog, type) {
+function createNoLogCondition(nolog) {
-  if(!nolog) return null;
+  var regexp = null;
-  type = type || '';
 
-  if(nolog instanceof RegExp){
+	if (nolog) {
-    if(type === 'string')
+    if (nolog instanceof RegExp) {
-      return nolog.source;
+      regexp = nolog;
-    return nolog;
-  } else if(typeof nolog === 'string'){
-    if(type === 'string')
-      return nolog;
-    try{
-      return new RegExp(nolog);
-    } catch (ex) {
-      return null;
     }
-  } else if(nolog instanceof Array){
+
-    var regexps = nolog.map(function(o){ return createNoLogCondition(o, 'string')});
+    if (typeof nolog === 'string') {
-    return new RegExp(regexps.join('|'));
+      regexp = new RegExp(nolog);
     }
+
+    if (Array.isArray(nolog)) {
+      var regexpsAsStrings = nolog.map(
+        function convertToStrings(o) {
+          return o.source ? o.source : o;
+        }
+      );
+      regexp = new RegExp(regexpsAsStrings.join('|'));
+    }
+  }
+
+  return regexp;
 }
 
 exports.connectLogger = getLogger;

lib/date_format.js

@@ -1,25 +1,63 @@
+"use strict";
 exports.ISO8601_FORMAT = "yyyy-MM-dd hh:mm:ss.SSS";
 exports.ISO8601_WITH_TZ_OFFSET_FORMAT = "yyyy-MM-ddThh:mm:ssO";
 exports.DATETIME_FORMAT = "dd MM yyyy hh:mm:ss.SSS";
 exports.ABSOLUTETIME_FORMAT = "hh:mm:ss.SSS";
 
-exports.asString = function(/*format,*/ date) {
+function padWithZeros(vNumber, width) {
+  var numAsString = vNumber + "";
+  while (numAsString.length < width) {
+    numAsString = "0" + numAsString;
+  }
+  return numAsString;
+}
+  
+function addZero(vNumber) {
+  return padWithZeros(vNumber, 2);
+}
+
+/**
+ * Formats the TimeOffest
+ * Thanks to http://www.svendtofte.com/code/date_format/
+ * @private
+ */
+function offset(timezoneOffset) {
+  // Difference to Greenwich time (GMT) in hours
+  var os = Math.abs(timezoneOffset);
+  var h = String(Math.floor(os/60));
+  var m = String(os%60);
+  if (h.length == 1) {
+    h = "0" + h;
+  }
+  if (m.length == 1) {
+    m = "0" + m;
+  }
+  return timezoneOffset < 0 ? "+"+h+m : "-"+h+m;
+}
+
+exports.asString = function(/*format,*/ date, timezoneOffset) {
   var format = exports.ISO8601_FORMAT;
   if (typeof(date) === "string") {
     format = arguments[0];
     date = arguments[1];
+    timezoneOffset = arguments[2];
   }
-
+  // make the date independent of the system timezone by working with UTC
-    var vDay = addZero(date.getDate());
+  if (timezoneOffset === undefined) {
-    var vMonth = addZero(date.getMonth()+1);
+    timezoneOffset = date.getTimezoneOffset();
-    var vYearLong = addZero(date.getFullYear());
+  }
-    var vYearShort = addZero(date.getFullYear().toString().substring(3,4));
+  date.setUTCMinutes(date.getUTCMinutes() - timezoneOffset);
+  var vDay = addZero(date.getUTCDate());
+  var vMonth = addZero(date.getUTCMonth()+1);
+  var vYearLong = addZero(date.getUTCFullYear());
+  var vYearShort = addZero(date.getUTCFullYear().toString().substring(2,4));
   var vYear = (format.indexOf("yyyy") > -1 ? vYearLong : vYearShort);
-    var vHour  = addZero(date.getHours());
+  var vHour  = addZero(date.getUTCHours());
-    var vMinute = addZero(date.getMinutes());
+  var vMinute = addZero(date.getUTCMinutes());
-    var vSecond = addZero(date.getSeconds());
+  var vSecond = addZero(date.getUTCSeconds());
-    var vMillisecond = padWithZeros(date.getMilliseconds(), 3);
+  var vMillisecond = padWithZeros(date.getUTCMilliseconds(), 3);
-    var vTimeZone = offset(date);
+  var vTimeZone = offset(timezoneOffset);
+  date.setUTCMinutes(date.getUTCMinutes() + timezoneOffset);
   var formatted = format
     .replace(/dd/g, vDay)
     .replace(/MM/g, vMonth)
@@ -31,30 +69,4 @@ exports.asString = function(/*format,*/ date) {
     .replace(/O/g, vTimeZone);
   return formatted;
 
-    function padWithZeros(vNumber, width) {
-	var numAsString = vNumber + "";
-	while (numAsString.length < width) {
-	    numAsString = "0" + numAsString;
-	}
-	return numAsString;
-    }
-
-    function addZero(vNumber) {
-	return padWithZeros(vNumber, 2);
-    }
-
-    /**
-     * Formats the TimeOffest
-     * Thanks to http://www.svendtofte.com/code/date_format/
-     * @private
-     */
-    function offset(date) {
-	// Difference to Greenwich time (GMT) in hours
-	var os = Math.abs(date.getTimezoneOffset());
-	var h = String(Math.floor(os/60));
-	var m = String(os%60);
-	h.length == 1? h = "0"+h:1;
-	m.length == 1? m = "0"+m:1;
-	return date.getTimezoneOffset() < 0 ? "+"+h+m : "-"+h+m;
-    }
 };

lib/debug.js

@@ -0,0 +1,15 @@
+"use strict";
+
+module.exports = function(label) {
+  var debug;
+
+  if (process.env.NODE_DEBUG && /\blog4js\b/.test(process.env.NODE_DEBUG)) {
+    debug = function(message) { 
+      console.error('LOG4JS: (%s) %s', label, message); 
+    };
+  } else {
+    debug = function() { };
+  }
+
+  return debug;
+};

lib/layouts.js

@@ -1,61 +1,42 @@
+"use strict";
 var dateFormat = require('./date_format')
-  , os = require('os')
+, os = require('os')
-  , eol = os.EOL || '\n'
+, eol = os.EOL || '\n'
-  , util = require('util')
+, util = require('util')
-  , replacementRegExp = /%[sdj]/g
+, replacementRegExp = /%[sdj]/g
-  , layoutMakers = {
+, layoutMakers = {
-      "messagePassThrough": function() { return messagePassThroughLayout; }
+  "messagePassThrough": function() { return messagePassThroughLayout; }, 
-    , "basic": function() { return basicLayout; }
+  "basic": function() { return basicLayout; }, 
-    , "colored": function() { return colouredLayout; }
+  "colored": function() { return colouredLayout; }, 
-    , "coloured": function() { return colouredLayout; }
+  "coloured": function() { return colouredLayout; }, 
-    , "pattern": function (config) {
+  "pattern": function (config) {
-	  var pattern = config.pattern || undefined;
+    return patternLayout(config && config.pattern, config && config.tokens);
-	  var tokens = config.tokens || undefined;
-	  return patternLayout(pattern, tokens);
 	}
+}
+, colours = {
+  ALL: "grey", 
+  TRACE: "blue", 
+  DEBUG: "cyan", 
+  INFO: "green", 
+  WARN: "yellow", 
+  ERROR: "red", 
+  FATAL: "magenta", 
+  OFF: "grey"
+};
+
+function wrapErrorsWithInspect(items) {
+  return items.map(function(item) {
+    if ((item instanceof Error) && item.stack) {
+      return { inspect: function() { return util.format(item) + '\n' + item.stack; } };
+    } else {
+      return item;
     }
-  , colours = {
+  });
-      ALL: "grey"
+}
-    , TRACE: "blue"
-    , DEBUG: "cyan"
-    , INFO: "green"
-    , WARN: "yellow"
-    , ERROR: "red"
-    , FATAL: "magenta"
-    , OFF: "grey"
-  };
 
 function formatLogData(logData) {
-    var output = ""
+  var data = Array.isArray(logData) ? logData : Array.prototype.slice.call(arguments);
-      , data = Array.isArray(logData) ? logData.slice() : Array.prototype.slice.call(arguments)
+  return util.format.apply(util, wrapErrorsWithInspect(data));
-      , format = data.shift();
-
-    if (typeof format  === "string") {
-        output = format.replace(replacementRegExp, function(match) {
-            switch (match) {
-            case "%s": return new String(data.shift());
-            case "%d": return new Number(data.shift());
-            case "%j": return JSON.stringify(data.shift());
-            default:
-                return match;
-            };
-        });
-    } else {
-        //put it back, it's not a format string
-        data.unshift(format);
-    }
-
-    data.forEach(function (item) {
-        if (output) {
-            output += ' ';
-        }
-        output += util.inspect(item);
-        if (item && item.stack) {
-            output += "\n" + item.stack;
-        }
-    });
-
-    return output;
 }
 
 var styles = {
@@ -78,10 +59,10 @@ var styles = {
 };
 
 function colorizeStart(style) {
-  return style ? '\033[' + styles[style][0] + 'm' : '';
+  return style ? '\x1B[' + styles[style][0] + 'm' : '';
 }
 function colorizeEnd(style) {
-  return style ? '\033[' + styles[style][1] + 'm' : '';
+  return style ? '\x1B[' + styles[style][1] + 'm' : '';
 }
 /**
  * Taken from masylum's fork (https://github.com/masylum/log4js-node)
@@ -90,11 +71,11 @@ function colorize (str, style) {
   return colorizeStart(style) + str + colorizeEnd(style);
 }
 
-function timestampLevelAndCategory(loggingEvent, colour) {
+function timestampLevelAndCategory(loggingEvent, colour, timezoneOffest) {
   var output = colorize(
     formatLogData(
       '[%s] [%s] %s - '
-          , dateFormat.asString(loggingEvent.startTime)
+      , dateFormat.asString(loggingEvent.startTime, timezoneOffest)
       , loggingEvent.level
       , loggingEvent.categoryName
     )
@@ -112,16 +93,20 @@ function timestampLevelAndCategory(loggingEvent, colour) {
  *
  * @author Stephan Strittmatter
  */
-function basicLayout (loggingEvent) {
+function basicLayout (loggingEvent, timezoneOffset) {
-    return timestampLevelAndCategory(loggingEvent) + formatLogData(loggingEvent.data);
+  return timestampLevelAndCategory(loggingEvent, undefined, timezoneOffset) + formatLogData(loggingEvent.data);
 }
 
 /**
  * colouredLayout - taken from masylum's fork.
  * same as basicLayout, but with colours.
  */
-function colouredLayout (loggingEvent) {
+function colouredLayout (loggingEvent, timezoneOffset) {
-    return timestampLevelAndCategory(loggingEvent, colours[loggingEvent.level.toString()]) + formatLogData(loggingEvent.data);
+  return timestampLevelAndCategory(
+    loggingEvent,
+    colours[loggingEvent.level.toString()],
+    timezoneOffset
+  ) + formatLogData(loggingEvent.data);
 }
 
 function messagePassThroughLayout (loggingEvent) {
@@ -136,10 +121,12 @@ function messagePassThroughLayout (loggingEvent) {
  *  - %r time in toLocaleTimeString format
  *  - %p log level
  *  - %c log category
+ *  - %h hostname
  *  - %m log data
  *  - %d date in various formats
  *  - %% %
  *  - %n newline
+ *  - %z pid
  *  - %x{<tokenname>} add dynamic tokens to your log. Tokens are specified in the tokens parameter
  * You can use %[ and %] to define a colored block.
  *
@@ -153,16 +140,162 @@ function messagePassThroughLayout (loggingEvent) {
  * Takes a pattern string, array of tokens and returns a layout function.
  * @param {String} Log format pattern String
  * @param {object} map object of different tokens
+ * @param {number} timezone offset in minutes
  * @return {Function}
  * @author Stephan Strittmatter
  * @author Jan Schmidle
  */
-function patternLayout (pattern, tokens) {
+function patternLayout (pattern, tokens, timezoneOffset) {
   var TTCC_CONVERSION_PATTERN  = "%r %p %c - %m%n";
-    var regex = /%(-?[0-9]+)?(\.?[0-9]+)?([\[\]cdmnprx%])(\{([^\}]+)\})?|([^%]+)/;
+  var regex = /%(-?[0-9]+)?(\.?[0-9]+)?([\[\]cdhmnprzxy%])(\{([^\}]+)\})?|([^%]+)/;
   
   pattern = pattern || TTCC_CONVERSION_PATTERN;
 
+  function categoryName(loggingEvent, specifier) {
+    var loggerName = loggingEvent.categoryName;
+    if (specifier) {
+      var precision = parseInt(specifier, 10);
+      var loggerNameBits = loggerName.split(".");
+      if (precision < loggerNameBits.length) {
+        loggerName = loggerNameBits.slice(loggerNameBits.length - precision).join(".");
+      }
+    }
+    return loggerName;
+  }
+
+  function formatAsDate(loggingEvent, specifier) {
+    var format = dateFormat.ISO8601_FORMAT;
+    if (specifier) {
+      format = specifier;
+      // Pick up special cases
+      if (format == "ISO8601") {
+        format = dateFormat.ISO8601_FORMAT;
+      } else if (format == "ISO8601_WITH_TZ_OFFSET") {
+        format = dateFormat.ISO8601_WITH_TZ_OFFSET_FORMAT; 
+      } else if (format == "ABSOLUTE") {
+        format = dateFormat.ABSOLUTETIME_FORMAT;
+      } else if (format == "DATE") {
+        format = dateFormat.DATETIME_FORMAT;
+      }
+    }
+    // Format the date
+    return dateFormat.asString(format, loggingEvent.startTime, timezoneOffset);
+  }
+  
+  function hostname() {
+    return os.hostname().toString();
+  }
+
+  function formatMessage(loggingEvent) {
+    return formatLogData(loggingEvent.data);
+  }
+  
+  function endOfLine() {
+    return eol;
+  }
+
+  function logLevel(loggingEvent) {
+    return loggingEvent.level.toString();
+  }
+
+  function startTime(loggingEvent) {
+    return dateFormat.asString('hh:mm:ss', loggingEvent.startTime, timezoneOffset);
+  }
+
+  function startColour(loggingEvent) {
+    return colorizeStart(colours[loggingEvent.level.toString()]);
+  }
+
+  function endColour(loggingEvent) {
+    return colorizeEnd(colours[loggingEvent.level.toString()]);
+  }
+
+  function percent() {
+    return '%';
+  }
+
+  function pid(loggingEvent) {
+    if (loggingEvent && loggingEvent.pid) {
+      return loggingEvent.pid;
+    } else {
+      return process.pid;
+    }
+  }
+  
+  function clusterInfo(loggingEvent, specifier) {
+    if (loggingEvent.cluster && specifier) {
+      return specifier
+        .replace('%m', loggingEvent.cluster.master)
+        .replace('%w', loggingEvent.cluster.worker)
+        .replace('%i', loggingEvent.cluster.workerId);
+    } else if (loggingEvent.cluster) {
+      return loggingEvent.cluster.worker+'@'+loggingEvent.cluster.master;
+    } else {
+      return pid();
+    }
+  }
+
+  function userDefined(loggingEvent, specifier) {
+    if (typeof(tokens[specifier]) !== 'undefined') {
+      if (typeof(tokens[specifier]) === 'function') {
+        return tokens[specifier](loggingEvent);
+      } else {
+        return tokens[specifier];
+      }
+    }
+    return null;
+  }
+
+  var replacers = {
+    'c': categoryName,
+    'd': formatAsDate,
+    'h': hostname,
+    'm': formatMessage,
+    'n': endOfLine,
+    'p': logLevel,
+    'r': startTime,
+    '[': startColour,
+    ']': endColour,
+    'y': clusterInfo,
+    'z': pid,
+    '%': percent,
+    'x': userDefined
+  };
+
+  function replaceToken(conversionCharacter, loggingEvent, specifier) {
+    return replacers[conversionCharacter](loggingEvent, specifier);
+  }
+
+  function truncate(truncation, toTruncate) {
+    var len;
+    if (truncation) {
+      len = parseInt(truncation.substr(1), 10);
+      return toTruncate.substring(0, len);
+    }
+
+    return toTruncate;
+  }
+
+  function pad(padding, toPad) {
+    var len;
+    if (padding) {
+      if (padding.charAt(0) == "-") {
+        len = parseInt(padding.substr(1), 10);
+        // Right pad with spaces
+        while (toPad.length < len) {
+          toPad += " ";
+        }
+      } else {
+        len = parseInt(padding, 10);
+        // Left pad with spaces
+        while (toPad.length < len) {
+          toPad = " " + toPad;
+        }
+      }
+    }
+    return toPad;
+  }
+  
   return function(loggingEvent) {
     var formattedString = "";
     var result;
@@ -182,100 +315,12 @@ function patternLayout (pattern, tokens) {
       } else {
         // Create a raw replacement string based on the conversion
         // character and specifier
-		var replacement = "";
+        var replacement = replaceToken(conversionCharacter, loggingEvent, specifier);
-		switch(conversionCharacter) {
+
-		case "c":
-		    var loggerName = loggingEvent.categoryName;
-		    if (specifier) {
-			var precision = parseInt(specifier, 10);
-			var loggerNameBits = loggingEvent.categoryName.split(".");
-			if (precision >= loggerNameBits.length) {
-			    replacement = loggerName;
-			} else {
-			    replacement = loggerNameBits.slice(loggerNameBits.length - precision).join(".");
-			}
-		    } else {
-			replacement = loggerName;
-		    }
-		    break;
-		case "d":
-		    var format = dateFormat.ISO8601_FORMAT;
-		    if (specifier) {
-			format = specifier;
-			// Pick up special cases
-			if (format == "ISO8601") {
-			    format = dateFormat.ISO8601_FORMAT;
-			} else if (format == "ABSOLUTE") {
-			    format = dateFormat.ABSOLUTETIME_FORMAT;
-			} else if (format == "DATE") {
-			    format = dateFormat.DATETIME_FORMAT;
-			}
-		    }
-		    // Format the date
-		    replacement = dateFormat.asString(format, loggingEvent.startTime);
-		    break;
-		case "m":
-		    replacement = formatLogData(loggingEvent.data);
-		    break;
-		case "n":
-		    replacement = eol;
-		    break;
-		case "p":
-		    replacement = loggingEvent.level.toString();
-		    break;
-		case "r":
-		    replacement = "" + loggingEvent.startTime.toLocaleTimeString();
-		    break;
-		case "[":
-		    replacement = colorizeStart(colours[loggingEvent.level.toString()]);
-		    break;
-		case "]":
-		    replacement = colorizeEnd(colours[loggingEvent.level.toString()]);
-		    break;
-		case "%":
-		    replacement = "%";
-		    break;
-		case "x":
-			if(typeof(tokens[specifier]) !== 'undefined') {
-				if(typeof(tokens[specifier]) === 'function') {
-					replacement = tokens[specifier]();
-				} else {
-					replacement = tokens[specifier];
-				}
-			} else {
-				replacement = matchedString;
-			}
-			break;
-		default:
-		    replacement = matchedString;
-		    break;
-		}
         // Format the replacement according to any padding or
         // truncation specified
-
+        replacement = truncate(truncation, replacement);
-		var len;
+        replacement = pad(padding, replacement);
-
-		// First, truncation
-		if (truncation) {
-		    len = parseInt(truncation.substr(1), 10);
-		    replacement = replacement.substring(0, len);
-		}
-		// Next, padding
-		if (padding) {
-		    if (padding.charAt(0) == "-") {
-			len = parseInt(padding.substr(1), 10);
-			// Right pad with spaces
-			while (replacement.length < len) {
-			    replacement += " ";
-			}
-		    } else {
-			len = parseInt(padding, 10);
-			// Left pad with spaces
-			while (replacement.length < len) {
-			    replacement = " " + replacement;
-			}
-		    }
-		}
         formattedString += replacement;
       }
       searchString = searchString.substr(result.index + result[0].length);
@@ -283,15 +328,15 @@ function patternLayout (pattern, tokens) {
     return formattedString;
   };
 
-};
+}
 
 module.exports = {
-    basicLayout: basicLayout
+  basicLayout: basicLayout, 
-  , messagePassThroughLayout: messagePassThroughLayout
+  messagePassThroughLayout: messagePassThroughLayout, 
-  , patternLayout: patternLayout
+  patternLayout: patternLayout, 
-  , colouredLayout: colouredLayout
+  colouredLayout: colouredLayout, 
-  , coloredLayout: colouredLayout
+  coloredLayout: colouredLayout, 
-  , layout: function(name, config) {
+  layout: function(name, config) {
     return layoutMakers[name] && layoutMakers[name](config);
   }
 };

lib/levels.js

@@ -1,3 +1,5 @@
+"use strict";
+
 function Level(level, levelStr) {
   this.level = level;
   this.levelStr = levelStr;
@@ -26,8 +28,7 @@ function toLevel(sArg, defaultLevel) {
   }
 
   return toLevel(sArg.toString());
-
+}
-};
 
 Level.prototype.toString = function() {
   return this.levelStr;
@@ -52,16 +53,17 @@ Level.prototype.isEqualTo = function(otherLevel) {
     otherLevel = toLevel(otherLevel);
   }
   return this.level === otherLevel.level;
-}
+};
 
 module.exports = {
-    ALL: new Level(Number.MIN_VALUE, "ALL")
+  ALL: new Level(Number.MIN_VALUE, "ALL"), 
-  , TRACE: new Level(5000, "TRACE")
+  TRACE: new Level(5000, "TRACE"), 
-  , DEBUG: new Level(10000, "DEBUG")
+  DEBUG: new Level(10000, "DEBUG"), 
-  , INFO: new Level(20000, "INFO")
+  INFO: new Level(20000, "INFO"), 
-  , WARN: new Level(30000, "WARN")
+  WARN: new Level(30000, "WARN"), 
-  , ERROR: new Level(40000, "ERROR")
+  ERROR: new Level(40000, "ERROR"), 
-  , FATAL: new Level(50000, "FATAL")
+  FATAL: new Level(50000, "FATAL"), 
-  , OFF: new Level(Number.MAX_VALUE, "OFF")
+  MARK: new Level(9007199254740992, "MARK"), // 2^53
-  , toLevel: toLevel
+  OFF: new Level(Number.MAX_VALUE, "OFF"), 
+  toLevel: toLevel
 };

lib/log4js.js

@@ -1,3 +1,4 @@
+"use strict";
 /*
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
@@ -12,8 +13,6 @@
  * limitations under the License.
  */
 
-/*jsl:option explicit*/
-
 /**
  * @fileoverview log4js is a library to log in JavaScript in similar manner
  * than in log4j for Java. The API should be nearly the same.
@@ -45,17 +44,20 @@
  * Website: http://log4js.berlios.de
  */
 var events = require('events')
+, async = require('async')
 , fs = require('fs')
 , path = require('path')
 , util = require('util')
 , layouts = require('./layouts')
 , levels = require('./levels')
-, LoggingEvent = require('./logger').LoggingEvent
+, loggerModule = require('./logger')
-, Logger = require('./logger').Logger
+, LoggingEvent = loggerModule.LoggingEvent
+, Logger = loggerModule.Logger
 , ALL_CATEGORIES = '[all]'
 , appenders = {}
 , loggers = {}
 , appenderMakers = {}
+, appenderShutdowns = {}
 , defaultConfig =   {
   appenders: [
     { type: "console" }
@@ -63,38 +65,103 @@ var events = require('events')
   replaceConsole: false
 };
 
+require('./appenders/console');
+
+function hasLogger(logger) {
+  return loggers.hasOwnProperty(logger);
+}
+
+
+function getBufferedLogger(categoryName) {
+    var base_logger = getLogger(categoryName);
+    var logger = {};
+    logger.temp = [];
+    logger.target = base_logger;
+    logger.flush = function () {
+        for (var i = 0; i < logger.temp.length; i++) {
+            var log = logger.temp[i];
+            logger.target[log.level](log.message);
+            delete logger.temp[i];
+        }
+    };
+    logger.trace = function (message) { logger.temp.push({level: 'trace', message: message}); };
+    logger.debug = function (message) { logger.temp.push({level: 'debug', message: message}); };
+    logger.info = function (message) { logger.temp.push({level: 'info', message: message}); };
+    logger.warn = function (message) { logger.temp.push({level: 'warn', message: message}); };
+    logger.error = function (message) { logger.temp.push({level: 'error', message: message}); };
+    logger.fatal = function (message) { logger.temp.push({level: 'fatal', message: message}); };
+
+    return logger;
+}
+
+function normalizeCategory (category) {
+  return  category + '.';
+}
+
+function doesLevelEntryContainsLogger (levelCategory, loggerCategory) {  
+  var normalizedLevelCategory = normalizeCategory(levelCategory);
+  var normalizedLoggerCategory = normalizeCategory(loggerCategory);
+  return normalizedLoggerCategory.substring(0, normalizedLevelCategory.length) == normalizedLevelCategory;
+}
+
+function doesAppenderContainsLogger (appenderCategory, loggerCategory) {
+  var normalizedAppenderCategory = normalizeCategory(appenderCategory);
+  var normalizedLoggerCategory = normalizeCategory(loggerCategory);
+  return normalizedLoggerCategory.substring(0, normalizedAppenderCategory.length) == normalizedAppenderCategory;
+}
+
+
 /**
  * Get a logger instance. Instance is cached on categoryName level.
  * @param  {String} categoryName name of category to log to.
  * @return {Logger} instance of logger for the category
  * @static
  */
-function getLogger (categoryName) {
+function getLogger (loggerCategoryName) {
 
   // Use default logger if categoryName is not specified or invalid
-    if (!(typeof categoryName == "string")) {
+  if (typeof loggerCategoryName !== "string") {
-        categoryName = Logger.DEFAULT_CATEGORY;
+    loggerCategoryName = Logger.DEFAULT_CATEGORY;
+  }
+
+  if (!hasLogger(loggerCategoryName)) {
+
+    var level = undefined;
+
+    // If there's a "levels" entry in the configuration
+    if (levels.config) {
+      // Goes through the categories in the levels configuration entry, starting by the "higher" ones.
+      var keys = Object.keys(levels.config).sort();
+      for (var idx = 0; idx < keys.length; idx++) {
+        var levelCategory = keys[idx];
+        if (doesLevelEntryContainsLogger(levelCategory, loggerCategoryName)) {
+          // level for the logger
+          level = levels.config[levelCategory];
+        }
+      }
     }
   
-    var appenderList;
-    if (!loggers[categoryName]) {
     // Create the logger for this name if it doesn't already exist
-        loggers[categoryName] = new Logger(categoryName);
+    loggers[loggerCategoryName] = new Logger(loggerCategoryName, level);
-        if (appenders[categoryName]) {
+
-            appenderList = appenders[categoryName];
+    var appenderList;
+    for(var appenderCategory in appenders) {
+      if (doesAppenderContainsLogger(appenderCategory, loggerCategoryName)) {
+        appenderList = appenders[appenderCategory];
         appenderList.forEach(function(appender) {
-                loggers[categoryName].addListener("log", appender);
+          loggers[loggerCategoryName].addListener("log", appender);
         });
       }
+    }
     if (appenders[ALL_CATEGORIES]) {
       appenderList = appenders[ALL_CATEGORIES];
       appenderList.forEach(function(appender) {
-                loggers[categoryName].addListener("log", appender);
+        loggers[loggerCategoryName].addListener("log", appender);
       });
     }
   }
   
-    return loggers[categoryName];
+  return loggers[loggerCategoryName];
 }
 
 /**
@@ -103,7 +170,7 @@ function getLogger (categoryName) {
 function addAppender () {
   var args = Array.prototype.slice.call(arguments);
   var appender = args.shift();
-    if (args.length == 0 || args[0] === undefined) {
+  if (args.length === 0 || args[0] === undefined) {
     args = [ ALL_CATEGORIES ];
   }
   //argument may already be an array
@@ -111,28 +178,42 @@ function addAppender () {
     args = args[0];
   }
   
-    args.forEach(function(category) {
+  args.forEach(function(appenderCategory) {
+    addAppenderToCategory(appender, appenderCategory);
+    
+    if (appenderCategory === ALL_CATEGORIES) {
+      addAppenderToAllLoggers(appender);
+    } else {
+
+      for(var loggerCategory in loggers) {
+        if (doesAppenderContainsLogger(appenderCategory,loggerCategory)) {
+          loggers[loggerCategory].addListener("log", appender);
+        }
+      }
+      
+    }
+  });
+}
+
+function addAppenderToAllLoggers(appender) {
+  for (var logger in loggers) {
+    if (hasLogger(logger)) {
+      loggers[logger].addListener("log", appender);
+    }
+  }
+}
+
+function addAppenderToCategory(appender, category) {
   if (!appenders[category]) {
     appenders[category] = [];
   }
   appenders[category].push(appender);
-
-        if (category === ALL_CATEGORIES) {
-            for (var logger in loggers) {
-                if (loggers.hasOwnProperty(logger)) {
-                    loggers[logger].addListener("log", appender);
-                }
-            }
-        } else if (loggers[category]) {
-            loggers[category].addListener("log", appender);
-        }
-    });
 }
 
 function clearAppenders () {
   appenders = {};
   for (var logger in loggers) {
-        if (loggers.hasOwnProperty(logger)) {
+    if (hasLogger(logger)) {
       loggers[logger].removeAllListeners("log");
     }
   }
@@ -145,21 +226,29 @@ function configureAppenders(appenderList, options) {
       loadAppender(appenderConfig.type);
       var appender;
       appenderConfig.makers = appenderMakers;
+      try {
         appender = appenderMakers[appenderConfig.type](appenderConfig, options);
-            if (appender) {
         addAppender(appender, appenderConfig.category);
-            } else {
+      } catch(e) {
-                throw new Error("log4js configuration problem for "+util.inspect(appenderConfig));
+        throw new Error("log4js configuration problem for " + util.inspect(appenderConfig), e);
       }
     });
   }
 }
 
-function configureLevels(levels) {
+function configureLevels(_levels) {
-    if (levels) {
+  levels.config = _levels; // Keep it so we can create loggers later using this cfg
-        for (var category in levels) {
+  if (_levels) {
-            if (levels.hasOwnProperty(category)) {
+    var keys = Object.keys(levels.config).sort();
-                getLogger(category).setLevel(levels[category]);
+    for (var idx in keys) {
+      var category = keys[idx];
+      if(category === ALL_CATEGORIES) {
+        setGlobalLogLevel(_levels[category]);
+      }        
+      for(var loggerCategory in loggers) {
+        if (doesLevelEntryContainsLogger(category, loggerCategory)) {
+          loggers[loggerCategory].setLevel(_levels[category]);
+        }
       }
     }
   }
@@ -181,10 +270,7 @@ function getDefaultLogger () {
 var configState = {};
 
 function loadConfigurationFile(filename) {
-    if (filename && (!configState.lastFilename || filename !== configState.lastFilename ||
+  if (filename) {
-                     !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;
@@ -193,8 +279,8 @@ function loadConfigurationFile(filename) {
 function configureOnceOff(config, options) {
   if (config) {
     try {
-            configureAppenders(config.appenders, options);
       configureLevels(config.levels);
+      configureAppenders(config.appenders, options);
       
       if (config.replaceConsole) {
         replaceConsole();
@@ -202,31 +288,32 @@ function configureOnceOff(config, options) {
         restoreConsole();
       }
     } catch (e) {
-            throw new Error("Problem reading log4js config " + util.inspect(config) + ". Error was \"" + e.message + "\" ("+e.stack+")");
+      throw new Error(
+        "Problem reading log4js config " + util.inspect(config) + 
+          ". Error was \"" + e.message + "\" (" + e.stack + ")"
+      );
     }
   }
 }
 
-function reloadConfiguration() {
+function reloadConfiguration(options) {
-    var filename = configState.filename,
+  var mtime = getMTime(configState.filename);
-    mtime;
+  if (!mtime) return;
-    if (!filename) {
+  
-        // can't find anything to reload
+  if (configState.lastMTime && (mtime.getTime() > configState.lastMTime.getTime())) {
-        return;
+    configureOnceOff(loadConfigurationFile(configState.filename), options);
   }
+  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) {
@@ -235,7 +322,8 @@ function initReloadConfiguration(filename, options) {
     delete configState.timerId;
   }
   configState.filename = filename;
-    configState.timerId = setInterval(reloadConfiguration, options.reloadSecs*1000);
+  configState.lastMTime = getMTime(filename);
+  configState.timerId = setInterval(reloadConfiguration, options.reloadSecs*1000, options);
 }
 
 function configure(configurationFileOrObject, options) {
@@ -250,7 +338,9 @@ function configure(configurationFileOrObject, options) {
     config = loadConfigurationFile(config) || defaultConfig;
   } else {
     if (options.reloadSecs) {
-            getLogger('log4js').warn('Ignoring configuration reload parameter for "object" configuration.');
+      getLogger('log4js').warn(
+        'Ignoring configuration reload parameter for "object" configuration.'
+      );
     }
   }
   configureOnceOff(config, options);
@@ -268,7 +358,7 @@ function replaceConsole(logger) {
   function replaceWith(fn) {
     return function() {
       fn.apply(logger, arguments);
-        }
+    };
   }
   logger = logger || getLogger("console");
   ['log','debug','info','warn','error'].forEach(function (item) {
@@ -282,25 +372,90 @@ function restoreConsole() {
   });
 }
 
-function loadAppender(appender) {
+/**
+ * Load an appenderModule based on the provided appender filepath. Will first
+ * check if the appender path is a subpath of the log4js "lib/appenders" directory.
+ * If not, it will attempt to load the the appender as complete path.
+ *
+ * @param {string} appender The filepath for the appender.
+ * @returns {Object|null} The required appender or null if appender could not be loaded.
+ * @private
+ */
+function requireAppender(appender) {
   var appenderModule;
   try {
     appenderModule = require('./appenders/' + appender);
   } catch (e) {
     appenderModule = require(appender);
   }
+  return appenderModule;
+}
+
+/**
+ * Load an appender. Provided the appender path to be loaded. If appenderModule is defined,
+ * it will be used in place of requiring the appender module.
+ *
+ * @param {string} appender The path to the appender module.
+ * @param {Object|void} [appenderModule] The pre-required appender module. When provided,
+ * instead of requiring the appender by its path, this object will be used.
+ * @returns {void}
+ * @private
+ */
+function loadAppender(appender, appenderModule) {
+  appenderModule = appenderModule || requireAppender(appender);
+
+  if (!appenderModule) {
+    throw new Error("Invalid log4js appender: " + util.inspect(appender));
+  }
+
   module.exports.appenders[appender] = appenderModule.appender.bind(appenderModule);
+  if (appenderModule.shutdown) {
+    appenderShutdowns[appender] = appenderModule.shutdown.bind(appenderModule);
+  }
   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.each(
+    shutdownFunctions,
+    function(shutdownFn, done) {
+      shutdownFn(done);
+    },
+		cb
+  );
+}
+
 module.exports = {
+  getBufferedLogger: getBufferedLogger,
   getLogger: getLogger,
   getDefaultLogger: getDefaultLogger,
+  hasLogger: hasLogger,
   
   addAppender: addAppender,
   loadAppender: loadAppender,
   clearAppenders: clearAppenders,
   configure: configure,
+  shutdown: shutdown,
   
   replaceConsole: replaceConsole,
   restoreConsole: restoreConsole,

lib/logger.js

@@ -1,7 +1,10 @@
-var levels = require('./levels'),
+"use strict";
-    util = require('util'),
+var levels = require('./levels')
-    events = require('events'),
+, util = require('util')
-    DEFAULT_CATEGORY = '[default]';
+, events = require('events')
+, DEFAULT_CATEGORY = '[default]';
+
+var logWritesEnabled = true;
 
 /**
  * Models a logging event.
@@ -30,12 +33,13 @@ function LoggingEvent (categoryName, level, data, logger) {
 function Logger (name, level) {
   this.category = name || DEFAULT_CATEGORY;
   
-    if (! this.level) {
+  if (level) {
-        this.__proto__.level = levels.TRACE;
+    this.setLevel(level);
   }
 }
 util.inherits(Logger, events.EventEmitter);
 Logger.DEFAULT_CATEGORY = DEFAULT_CATEGORY;
+Logger.prototype.level = levels.TRACE;
 
 Logger.prototype.setLevel = function(level) {
   this.level = levels.toLevel(level, this.level || levels.TRACE);
@@ -47,16 +51,19 @@ Logger.prototype.removeLevel = function() {
 
 Logger.prototype.log = function() {
   var args = Array.prototype.slice.call(arguments)
-  , logLevel = args.shift()
+  , logLevel = levels.toLevel(args.shift(), levels.INFO)
-  , loggingEvent = new LoggingEvent(this.category, logLevel, args, this);
+  , loggingEvent;
+  if (this.isLevelEnabled(logLevel)) {
+    loggingEvent = new LoggingEvent(this.category, logLevel, args, this);
     this.emit("log", loggingEvent);
+  }
 };
 
 Logger.prototype.isLevelEnabled = function(otherLevel) {
   return this.level.isLessThanOrEqualTo(otherLevel);
 };
 
-['Trace','Debug','Info','Warn','Error','Fatal'].forEach(
+['Trace','Debug','Info','Warn','Error','Fatal', 'Mark'].forEach(
   function(levelString) {
     var level = levels.toLevel(levelString);
     Logger.prototype['is'+levelString+'Enabled'] = function() {
@@ -64,7 +71,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);
@@ -73,6 +80,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;

lib/streams/BaseRollingFileStream.js

@@ -1,21 +1,27 @@
-var fs = require('fs'),
+"use strict";
-    util = require('util');
+var fs = require('fs')
+, stream
+, debug = require('../debug')('BaseRollingFileStream')
+, util = require('util')
+, semver = require('semver');
 
-function debug(message) {
+if (semver.satisfies(process.version, '>=0.10.0')) {
-//    console.log(message);
+  stream = require('stream');
+} else {
+  stream = require('readable-stream');
 }
 
 module.exports = BaseRollingFileStream;
 
 function BaseRollingFileStream(filename, options) {
-
+  debug("In BaseRollingFileStream");
-debug("In BaseRollingFileStream");
   this.filename = filename;
-    this.options = options || { encoding: 'utf8', mode: 0644, flags: 'a' };
+  this.options = options || {};
-    this.rolling = false;
+  this.options.encoding = this.options.encoding || 'utf8';
-    this.writesWhileRolling = [];
+  this.options.mode = this.options.mode || parseInt('0644', 8);
+  this.options.flags = this.options.flags || 'a';
+
   this.currentSize = 0;
-    this.rollBeforeWrite = false;
   
   function currentFileSize(file) {
     var fileSize = 0;
@@ -34,59 +40,48 @@ debug("In BaseRollingFileStream");
   }
 
   throwErrorIfArgumentsAreNotValid();
-debug("Calling BaseRollingFileStream.super");
+  debug("Calling BaseRollingFileStream.super");
-    BaseRollingFileStream.super_.call(this, this.filename, this.options);
+  BaseRollingFileStream.super_.call(this);
+  this.openTheStream();
   this.currentSize = currentFileSize(this.filename);
 }
-util.inherits(BaseRollingFileStream, fs.FileWriteStream);
+util.inherits(BaseRollingFileStream, stream.Writable);
 
-BaseRollingFileStream.prototype.initRolling = function() {
+BaseRollingFileStream.prototype._write = function(chunk, encoding, callback) {
   var that = this;
-
+  function writeTheChunk() {
-    function emptyRollingQueue() {
+    debug("writing the chunk to the underlying stream");
-        debug("emptying the rolling queue");
+    that.currentSize += chunk.length;
-        var toWrite;
+    try {
-        while ((toWrite = that.writesWhileRolling.shift())) {
+      that.theStream.write(chunk, encoding, callback);
-            BaseRollingFileStream.super_.prototype.write.call(that, toWrite.data, toWrite.encoding);
-            that.currentSize += toWrite.data.length;
-            if (that.shouldRoll()) {
-                that.flush();
-                return true;
     }
+    catch (err){
+      debug(err);
+      callback();
     }
-        that.flush();
-        return false;
   }
 
-    this.rolling = true;
+  debug("in _write");
-    this.roll(this.filename, function() {
+
-        that.currentSize = 0;
+  if (this.shouldRoll()) {
-        that.rolling = emptyRollingQueue();
+    this.currentSize = 0;
-        if (that.rolling) {
+    this.roll(this.filename, writeTheChunk);
-            process.nextTick(function() { that.initRolling(); });
+  } else {
+    writeTheChunk();
   }
-    });
 };
 
-BaseRollingFileStream.prototype.write = function(data, encoding) {
+BaseRollingFileStream.prototype.openTheStream = function(cb) {
-    var canWrite = false;
+  debug("opening the underlying stream");
-    if (this.rolling) {
+  this.theStream = fs.createWriteStream(this.filename, this.options);
-        this.writesWhileRolling.push({ data: data, encoding: encoding });
+  if (cb) {
-    } else {
+    this.theStream.on("open", cb);
-        if (this.rollBeforeWrite && this.shouldRoll()) {
+  }
-            this.writesWhileRolling.push({ data: data, encoding: encoding });
+};
-            this.initRolling();
-        } else {
-            canWrite = BaseRollingFileStream.super_.prototype.write.call(this, data, encoding);
-            this.currentSize += data.length;
-            debug('current size = ' + this.currentSize);
 
-            if (!this.rollBeforeWrite && this.shouldRoll()) {
+BaseRollingFileStream.prototype.closeTheStream = function(cb) {
-                this.initRolling();
+  debug("closing the underlying stream");
-            }
+  this.theStream.end(cb);
-        }
-    }
-    return canWrite;
 };
 
 BaseRollingFileStream.prototype.shouldRoll = function() {

lib/streams/BufferedWriteStream.js

@@ -1,78 +0,0 @@
-var events = require('events'),
-    Dequeue = require('dequeue'),
-    util = require('util');
-
-module.exports = BufferedWriteStream;
-
-function BufferedWriteStream(stream) {
-    var that = this;
-    this.stream = stream;
-    this.buffer = new Dequeue();
-    this.canWrite = false;
-    this.bytes = 0;
-
-    this.stream.on("open", function() {
-        that.canWrite = true;
-        that.flushBuffer();
-    });
-
-    this.stream.on("error", function (err) {
-        that.emit("error", err);
-    });
-
-    this.stream.on("drain", function() {
-        that.canWrite = true;
-        that.flushBuffer();
-    });
-}
-
-util.inherits(BufferedWriteStream, events.EventEmitter);
-
-Object.defineProperty(
-    BufferedWriteStream.prototype,
-    "fd",
-    {
-        get: function() { return this.stream.fd; },
-        set: function(newFd) {
-            this.stream.fd = newFd;
-            this.bytes = 0;
-        }
-    }
-);
-
-Object.defineProperty(
-    BufferedWriteStream.prototype,
-    "bytesWritten",
-    {
-        get: function() { return this.bytes; }
-    }
-);
-
-BufferedWriteStream.prototype.write = function(data, encoding) {
-    this.buffer.push({ data: data, encoding: encoding });
-    this.flushBuffer();
-};
-
-BufferedWriteStream.prototype.end = function(data, encoding) {
-    if (data) {
-        this.buffer.push({ data: data, encoding: encoding });
-    }
-    this.flushBufferEvenIfCannotWrite();
-};
-
-BufferedWriteStream.prototype.writeToStream = function(toWrite) {
-    this.bytes += toWrite.data.length;
-    this.canWrite = this.stream.write(toWrite.data, toWrite.encoding);
-};
-
-BufferedWriteStream.prototype.flushBufferEvenIfCannotWrite = function() {
-    while (this.buffer.length > 0) {
-        this.writeToStream(this.buffer.shift());
-    }
-};
-
-BufferedWriteStream.prototype.flushBuffer = function() {
-    while (this.buffer.length > 0 && this.canWrite) {
-        this.writeToStream(this.buffer.shift());
-    }
-};

lib/streams/DateRollingFileStream.js

@@ -1,15 +1,13 @@
-var BaseRollingFileStream = require('./BaseRollingFileStream'),
+"use strict";
-    format = require('../date_format'),
+var BaseRollingFileStream = require('./BaseRollingFileStream')
-    async = require('async'),
+, debug = require('../debug')('DateRollingFileStream')
-    fs = require('fs'),
+, format = require('../date_format')
-    util = require('util');
+, async = require('async')
+, fs = require('fs')
+, util = require('util');
 
 module.exports = DateRollingFileStream;
 
-function debug(message) {
-//    console.log(message);
-}
-
 function DateRollingFileStream(filename, pattern, options, now) {
   debug("Now is " + now);
   if (pattern && typeof(pattern) === 'object') {
@@ -19,20 +17,39 @@ function DateRollingFileStream(filename, pattern, options, now) {
   }
   this.pattern = pattern || '.yyyy-MM-dd';
   this.now = now || Date.now;
+
+  if (fs.existsSync(filename)) {
+    var stat = fs.statSync(filename);
+    this.lastTimeWeWroteSomething = format.asString(this.pattern, stat.mtime);
+  } else {
     this.lastTimeWeWroteSomething = format.asString(this.pattern, new Date(this.now()));
+  }
+
+  this.baseFilename = filename;
+  this.alwaysIncludePattern = false;
+  
+  if (options) {
+    if (options.alwaysIncludePattern) {
+      this.alwaysIncludePattern = true;
+      filename = this.baseFilename + this.lastTimeWeWroteSomething;
+    }
+    delete options.alwaysIncludePattern;
+    if (Object.keys(options).length === 0) { 
+      options = null; 
+    }
+  }
   debug("this.now is " + this.now + ", now is " + now);
   
   DateRollingFileStream.super_.call(this, filename, options);
-    this.rollBeforeWrite = true;
 }
-
 util.inherits(DateRollingFileStream, BaseRollingFileStream);
 
 DateRollingFileStream.prototype.shouldRoll = function() {
   var lastTime = this.lastTimeWeWroteSomething,
   thisTime = format.asString(this.pattern, new Date(this.now()));
   
-    debug("DateRollingFileStream.shouldRoll with now = " + this.now() + ", thisTime = " + thisTime + ", lastTime = " + lastTime);
+  debug("DateRollingFileStream.shouldRoll with now = " + 
+        this.now() + ", thisTime = " + thisTime + ", lastTime = " + lastTime);
   
   this.lastTimeWeWroteSomething = thisTime;
   this.previousTime = lastTime;
@@ -41,19 +58,25 @@ DateRollingFileStream.prototype.shouldRoll = function() {
 };
 
 DateRollingFileStream.prototype.roll = function(filename, callback) {
-    var that = this,
+  var that = this;
-        newFilename = filename + this.previousTime;
   
   debug("Starting roll");
-    debug("Queueing up data until we've finished rolling");
-    debug("Flushing underlying stream");
-    this.flush();
   
+  if (this.alwaysIncludePattern) {
+    this.filename = this.baseFilename + this.lastTimeWeWroteSomething;
     async.series([
+      this.closeTheStream.bind(this),
+      this.openTheStream.bind(this)
+    ], callback);
+  } else {
+    var newFilename = this.baseFilename + this.previousTime;
+    async.series([
+      this.closeTheStream.bind(this),
       deleteAnyExistingFile,
       renameTheCurrentFile,
-        openANewFile
+      this.openTheStream.bind(this)
     ], callback);
+  }
   
   function deleteAnyExistingFile(cb) {
     //on windows, you can get a EEXIST error if you rename a file to an existing file
@@ -69,21 +92,4 @@ DateRollingFileStream.prototype.roll = function(filename, callback) {
     fs.rename(filename, newFilename, cb);
   }
 
-    function openANewFile(cb) {
-        debug("Opening a new file");
-        fs.open(
-            filename,
-            that.options.flags,
-            that.options.mode,
-            function (err, fd) {
-                debug("opened new file");
-                var oldLogFileFD = that.fd;
-                that.fd = fd;
-                that.writable = true;
-                fs.close(oldLogFileFD, cb);
-            }
-        );
-    }
-
-
 };

lib/streams/RollingFileStream.js

@@ -1,13 +1,12 @@
-var BaseRollingFileStream = require('./BaseRollingFileStream'),
+"use strict";
-    util = require('util'),
+var BaseRollingFileStream = require('./BaseRollingFileStream')
-    path = require('path'),
+, debug = require('../debug')('RollingFileStream')
-    fs = require('fs'),
+, util = require('util')
-    async = require('async');
+, path = require('path')
-
+, child_process = require('child_process')
-function debug(message) {
+, zlib = require("zlib")
-//    util.debug(message);
+, fs = require('fs')
-//    console.log(message);
+, async = require('async');
-}
 
 module.exports = RollingFileStream;
 
@@ -28,6 +27,7 @@ function RollingFileStream (filename, size, backups, options) {
 util.inherits(RollingFileStream, BaseRollingFileStream);
 
 RollingFileStream.prototype.shouldRoll = function() {
+  debug("should roll with current size " + this.currentSize + " and max size " + this.size);
   return this.currentSize >= this.size;
 };
 
@@ -40,6 +40,7 @@ RollingFileStream.prototype.roll = function(filename, callback) {
   }
   
   function index(filename_) {
+    debug('Calculating index of '+filename_);
     return parseInt(filename_.substring((path.basename(filename) + '.').length), 10) || 0;
   }
   
@@ -53,16 +54,42 @@ RollingFileStream.prototype.roll = function(filename, callback) {
     }
   }
 
+  function compress (filename, cb) {
+
+    var gzip = zlib.createGzip();
+    var inp = fs.createReadStream(filename);
+    var out = fs.createWriteStream(filename+".gz");
+    inp.pipe(gzip).pipe(out);
+    fs.unlink(filename, cb);
+
+  }
+
   function increaseFileIndex (fileToRename, cb) {
     var idx = index(fileToRename);
     debug('Index of ' + fileToRename + ' is ' + idx);
     if (idx < that.backups) {
+
+      var ext = path.extname(fileToRename);
+      var destination = filename + '.' + (idx+1);
+      if (that.options.compress && /^gz$/.test(ext.substring(1))) {
+        destination+=ext;
+      }
       //on windows, you can get a EEXIST error if you rename a file to an existing file
       //so, we'll try to delete the file we're renaming to first
-            fs.unlink(filename + '.' + (idx+1), function (err) {
+      fs.unlink(destination, function (err) {
         //ignore err: if we could not delete, it's most likely that it doesn't exist
-                debug('Renaming ' + fileToRename + ' -> ' + filename + '.' + (idx+1));
+        debug('Renaming ' + fileToRename + ' -> ' + destination);
-                fs.rename(path.join(path.dirname(filename), fileToRename), filename + '.' + (idx + 1), cb);
+        fs.rename(path.join(path.dirname(filename), fileToRename), destination, function(err) {
+          if (err) {
+            cb(err);
+          } else {
+            if (that.options.compress && ext!=".gz") {
+              compress(destination, cb);
+            } else {
+              cb();
+            }
+          }
+        });
       });
     } else {
       cb();
@@ -73,7 +100,7 @@ RollingFileStream.prototype.roll = function(filename, callback) {
     //roll the backups (rename file.n to file.n+1, where n <= numBackups)
     debug("Renaming the old files");
     fs.readdir(path.dirname(filename), function (err, files) {
-            async.forEachSeries(
+      async.eachSeries(
         files.filter(justTheseFiles).sort(byIndex).reverse(),
         increaseFileIndex,
         cb
@@ -81,30 +108,11 @@ RollingFileStream.prototype.roll = function(filename, callback) {
     });
   }
 
-    function openANewFile(cb) {
+  debug("Rolling, rolling, rolling");
-        debug("Opening a new file");
-        fs.open(
-            filename,
-            that.options.flags,
-            that.options.mode,
-            function (err, fd) {
-                debug("opened new file");
-                var oldLogFileFD = that.fd;
-                that.fd = fd;
-                that.writable = true;
-                fs.close(oldLogFileFD, cb);
-            }
-        );
-    }
-
-    debug("Starting roll");
-    debug("Queueing up data until we've finished rolling");
-    debug("Flushing underlying stream");
-    this.flush();
-
   async.series([
+    this.closeTheStream.bind(this),
     renameTheFiles,
-        openANewFile
+    this.openTheStream.bind(this)
   ], callback);
 
 };

lib/streams/index.js

@@ -1,3 +1,2 @@
-exports.BufferedWriteStream = require('./BufferedWriteStream');
 exports.RollingFileStream = require('./RollingFileStream');
 exports.DateRollingFileStream = require('./DateRollingFileStream');

package.json

@@ -1,6 +1,6 @@
 {
   "name": "log4js",
-   "version": "0.5.6",
+  "version": "0.6.25",
   "description": "Port of Log4js to work with node.",
   "keywords": [
     "logging",
@@ -8,8 +8,9 @@
     "log4j",
     "node"
   ],
+  "license": "Apache-2.0",
   "main": "./lib/log4js",
-   "author": "Gareth Jones <gareth.jones@sensis.com.au>",
+  "author": "Gareth Jones <gareth.nomiddlename@gmail.com>",
   "repository": {
     "type": "git",
     "url": "https://github.com/nomiddlename/log4js-node.git"
@@ -17,7 +18,9 @@
   "bugs": {
     "url": "http://github.com/nomiddlename/log4js-node/issues"
   },
-   "engines": [ "node >=0.6" ],
+  "engines": {
+    "node": ">=0.8"
+  },
   "scripts": {
     "test": "vows"
   },
@@ -26,13 +29,17 @@
     "lib": "lib"
   },
   "dependencies": {
-       "async": "0.1.15",
+    "async": "~0.2.0",
-       "dequeue": "1.0.3"
+    "readable-stream": "~1.0.2",
+    "semver": "~4.3.3",
+    "underscore": "1.8.2"
   },
   "devDependencies": {
-       "vows": "0.6.2",
+    "vows": "0.7.0",
     "sandboxed-module": "0.1.3",
-       "hook.io": "0.8.10",
     "underscore": "1.2.1"
+  },
+  "browser": {
+    "os": false
   }
 }

test/categoryFilter-test.js

@@ -0,0 +1,84 @@
+'use strict';
+
+var vows = require('vows')
+, fs = require('fs')
+, assert = require('assert')
+, EOL = require('os').EOL || '\n';
+
+function remove(filename) {
+  try {
+    fs.unlinkSync(filename);
+  } catch (e) {
+    //doesn't really matter if it failed
+  }
+}
+
+vows.describe('log4js categoryFilter').addBatch({
+  'appender': {
+    topic: function() {
+
+      var log4js = require('../lib/log4js'), logEvents = [], webLogger, appLogger;
+      log4js.clearAppenders();
+      var appender = require('../lib/appenders/categoryFilter')
+        .appender(
+          ['app'],
+          function(evt) { logEvents.push(evt); }
+        );
+      log4js.addAppender(appender, ["app","web"]);
+
+      webLogger = log4js.getLogger("web");
+      appLogger = log4js.getLogger("app");
+
+      webLogger.debug('This should get logged');
+      appLogger.debug('This should not');
+      webLogger.debug('Hello again');
+      log4js.getLogger('db').debug('This shouldn\'t be included by the appender anyway');
+
+      return logEvents;
+    },
+    'should only pass matching category' : function(logEvents) {
+      assert.equal(logEvents.length, 2);
+      assert.equal(logEvents[0].data[0], 'This should get logged');
+      assert.equal(logEvents[1].data[0], 'Hello again');
+    }
+  },
+
+  'configure': {
+    topic: function() {
+      var log4js = require('../lib/log4js')
+      , logger, weblogger;
+
+      remove(__dirname + '/categoryFilter-web.log');
+      remove(__dirname + '/categoryFilter-noweb.log');
+
+      log4js.configure('test/with-categoryFilter.json');
+      logger = log4js.getLogger("app");
+      weblogger = log4js.getLogger("web");
+
+      logger.info('Loading app');
+      logger.debug('Initialising indexes');
+      weblogger.info('00:00:00 GET / 200');
+      weblogger.warn('00:00:00 GET / 500');
+      //wait for the file system to catch up
+      setTimeout(this.callback, 500);
+    },
+    'tmp-tests.log': {
+      topic: function() {
+        fs.readFile(__dirname + '/categoryFilter-noweb.log', 'utf8', this.callback);
+      },
+      'should contain all log messages': function(contents) {
+        var messages = contents.trim().split(EOL);
+        assert.deepEqual(messages, ['Loading app','Initialising indexes']);
+      }
+    },
+    'tmp-tests-web.log': {
+      topic: function() {
+        fs.readFile(__dirname + '/categoryFilter-web.log','utf8',this.callback);
+      },
+      'should contain only error and warning log messages': function(contents) {
+        var messages = contents.trim().split(EOL);
+        assert.deepEqual(messages, ['00:00:00 GET / 200','00:00:00 GET / 500']);
+      }
+    }
+  }
+}).export(module);

test/clusteredAppender-test.js

@@ -0,0 +1,128 @@
+"use strict";
+var assert = require('assert');
+var vows = require('vows');
+var layouts = require('../lib/layouts');
+var sandbox = require('sandboxed-module');
+var LoggingEvent = require('../lib/logger').LoggingEvent;
+var cluster = require('cluster');
+
+vows.describe('log4js cluster appender').addBatch({
+	'when in master mode': {
+		topic: function() {
+
+			var registeredClusterEvents = [];
+			var loggingEvents = [];
+			
+			// Fake cluster module, so no cluster listeners be really added 
+			var fakeCluster = {
+			
+				on: function(event, callback) {
+					registeredClusterEvents.push(event);
+				},
+				
+				isMaster: true,
+				isWorker: false,
+				
+			};
+		
+			var fakeActualAppender = function(loggingEvent) {
+				loggingEvents.push(loggingEvent);
+			}
+			
+			// Load appender and fake modules in it
+			var appenderModule = sandbox.require('../lib/appenders/clustered', {
+				requires: {
+					'cluster': fakeCluster,
+				}
+			});
+		
+			var masterAppender = appenderModule.appender({
+				actualAppenders: [fakeActualAppender, fakeActualAppender, fakeActualAppender],
+                                appenders: [{}, {category: "test"}, {category: "wovs"}]
+			});
+
+			// Actual test - log message using masterAppender
+			masterAppender(new LoggingEvent('wovs', 'Info', ['masterAppender test']));
+			
+			var returnValue = {
+				registeredClusterEvents: registeredClusterEvents,
+				loggingEvents: loggingEvents,
+			};
+		
+			return returnValue;
+		}, 
+		
+		"should register 'fork' event listener on 'cluster'": function(topic) { 
+			assert.equal(topic.registeredClusterEvents[0], 'fork');
+		},
+		
+		"should log using actual appender": function(topic) {
+                        assert.equal(topic.loggingEvents.length, 2)
+			assert.equal(topic.loggingEvents[0].data[0], 'masterAppender test');
+                        assert.equal(topic.loggingEvents[1].data[0], 'masterAppender test');
+		},
+		
+	},
+	
+	'when in worker mode': {
+		
+		topic: function() {
+			
+			var registeredProcessEvents = [];
+			
+			// Fake cluster module, to fake we're inside a worker process
+			var fakeCluster = {
+			
+				isMaster: false,
+				isWorker: true,
+				
+			};
+			
+			var fakeProcess = {
+			
+				send: function(data) {
+					registeredProcessEvents.push(data);
+				},
+				
+			};
+			
+			// Load appender and fake modules in it
+			var appenderModule = sandbox.require('../lib/appenders/clustered', {
+				requires: {
+					'cluster': fakeCluster,
+				},
+				globals: {
+					'process': fakeProcess,
+				}
+			});
+			
+			var workerAppender = appenderModule.appender();
+
+			// Actual test - log message using masterAppender
+			workerAppender(new LoggingEvent('wovs', 'Info', ['workerAppender test']));
+			workerAppender(new LoggingEvent('wovs', 'Info', [new Error('Error test')]));
+			
+			var returnValue = {
+				registeredProcessEvents: registeredProcessEvents,
+			};
+			
+			return returnValue;
+		
+		},
+		
+		"worker appender should call process.send" : function(topic) {
+			assert.equal(topic.registeredProcessEvents[0].type, '::log-message');
+			assert.equal(JSON.parse(topic.registeredProcessEvents[0].event).data[0], "workerAppender test");
+		},
+		
+		"worker should serialize an Error correctly" : function(topic) {
+			assert.equal(topic.registeredProcessEvents[1].type, '::log-message');
+			assert(JSON.parse(topic.registeredProcessEvents[1].event).data[0].stack);
+			var actual = JSON.parse(topic.registeredProcessEvents[1].event).data[0].stack;
+			var expectedRegex = /^Error: Error test/;
+			assert(actual.match(expectedRegex), "Expected: \n\n " + actual + "\n\n to match " + expectedRegex);
+		}
+		
+	}
+
+}).exportTo(module);

test/configuration-test.js

@@ -1,6 +1,7 @@
-var assert = require('assert'),
+"use strict";
-    vows = require('vows'),
+var assert = require('assert')
-    sandbox = require('sandboxed-module');
+, vows = require('vows')
+, sandbox = require('sandboxed-module');
 
 function makeTestAppender() {
   return {
@@ -12,7 +13,7 @@ function makeTestAppender() {
     },
     appender: function() {
       var self = this;
-            return function(logEvt) { self.logEvt = logEvt; }
+      return function(logEvt) { self.logEvt = logEvt; };
     }
   };
 }
@@ -85,6 +86,21 @@ vows.describe('log4js configure').addBatch({
         assert.isFunction(log4js.appenderMakers['some/other/external']);
       }
     },
+    'when appender object loaded via loadAppender': {
+      topic: function() {
+        var testAppender = makeTestAppender(),
+            log4js = sandbox.require('../lib/log4js');
+
+        log4js.loadAppender('some/other/external', testAppender);
+        return log4js;
+      },
+      'should load appender with provided object': function(log4js) {
+        assert.ok(log4js.appenders['some/other/external']);
+      },
+      'should add appender configure function to appenderMakers': function(log4js) {
+        assert.isFunction(log4js.appenderMakers['some/other/external']);
+      }
+    },
     'when configuration file loaded via LOG4JS_CONFIG environment variable': {
       topic: function() {
         process.env.LOG4JS_CONFIG = 'some/path/to/mylog4js.json';
@@ -114,12 +130,14 @@ vows.describe('log4js configure').addBatch({
             }
           }
         },
-            log4js = sandbox.require('../lib/log4js',
+        log4js = sandbox.require(
+          '../lib/log4js',
           {
             requires: {
               'fs': fakeFS,
             }
-                                     });
+          }
+        );
         delete process.env.LOG4JS_CONFIG;
         return fileRead;
       },

test/configureNoLevels-test.js

@@ -1,7 +1,10 @@
+"use strict";
 // This test shows unexpected behaviour for log4js.configure() in log4js-node@0.4.3 and earlier:
-// 1) log4js.configure(), log4js.configure(null), log4js.configure({}), log4js.configure(<some object with no levels prop>)
+// 1) log4js.configure(), log4js.configure(null),
+// log4js.configure({}), log4js.configure(<some object with no levels prop>)
 // all set all loggers levels to trace, even if they were previously set to something else.
-// 2) log4js.configure({levels:{}}), log4js.configure({levels: {foo: bar}}) leaves previously set logger levels intact.
+// 2) log4js.configure({levels:{}}), log4js.configure({levels: {foo:
+// bar}}) leaves previously set logger levels intact.
 //
 
 // Basic set up
@@ -28,7 +31,7 @@ var configs = {
   'has empty levels': {levels: {}},
   'has random levels': {levels: {foo: 'bar'}},
   'has some valid levels': {levels: {A: 'INFO'}}
-}
+};
 
 // Set up the basic vows batches for this test
 var batches = [];
@@ -60,13 +63,85 @@ function getTopLevelContext(nop, configToTest, name) {
       }
       return log4js;
     }
-  }
+  };
-};
+}
 
 showProgress('Populating batch object...');
 
-// Populating the batches programmatically,
+function checkForMismatch(topic) {
-// as there are (configs.length x strLevels.length x strLevels.length) = 324 possible test combinations
+  var er = topic.log4js.levels.toLevel(topic.baseLevel)
+    .isLessThanOrEqualTo(topic.log4js.levels.toLevel(topic.comparisonLevel));
+
+  assert.equal(
+    er, 
+    topic.expectedResult, 
+    'Mismatch: for setLevel(' + topic.baseLevel + 
+      ') was expecting a comparison with ' + topic.comparisonLevel + 
+      ' to be ' + topic.expectedResult
+  );
+}
+
+function checkExpectedResult(topic) {
+  var result = topic.log4js
+    .getLogger(getLoggerName(topic.baseLevel))
+    .isLevelEnabled(topic.log4js.levels.toLevel(topic.comparisonLevel));
+  
+  assert.equal(
+    result, 
+    topic.expectedResult, 
+    'Failed: ' + getLoggerName(topic.baseLevel) + 
+      '.isLevelEnabled( ' + topic.comparisonLevel + ' ) returned ' + result
+  );
+}
+
+function setupBaseLevelAndCompareToOtherLevels(baseLevel) {
+  var baseLevelSubContext = 'and checking the logger whose level was set to '+baseLevel ;
+  var subContext = { topic: baseLevel };
+  batch[context][baseLevelSubContext] = subContext;
+
+  // each logging level has strLevels sub-contexts,
+  // to exhaustively test all the combinations of 
+  // setLevel(baseLevel) and isLevelEnabled(comparisonLevel) per config
+  strLevels.forEach(compareToOtherLevels(subContext));
+}
+
+function compareToOtherLevels(subContext) {
+  var baseLevel = subContext.topic;
+
+  return function (comparisonLevel) {
+    var comparisonLevelSubContext = 'with isLevelEnabled('+comparisonLevel+')';
+
+    // calculate this independently of log4js, but we'll add a vow 
+    // later on to check that we're not mismatched with log4js
+    var expectedResult = strLevels.indexOf(baseLevel) <= strLevels.indexOf(comparisonLevel);
+
+    // the topic simply gathers all the parameters for the vow 
+    // into an object, to simplify the vow's work.
+    subContext[comparisonLevelSubContext] = {
+      topic: function(baseLevel, log4js) {
+        return {
+          comparisonLevel: comparisonLevel, 
+          baseLevel: baseLevel, 
+          log4js: log4js, 
+          expectedResult: expectedResult
+        };
+      }
+    };
+
+    var vow = 'should return '+expectedResult;
+    subContext[comparisonLevelSubContext][vow] = checkExpectedResult;
+    
+    // the extra vow to check the comparison between baseLevel and
+    // comparisonLevel we performed earlier matches log4js'
+    // comparison too
+    var subSubContext = subContext[comparisonLevelSubContext];
+    subSubContext['finally checking for comparison mismatch with log4js'] = checkForMismatch;
+  };
+}
+
+// Populating the batches programmatically, as there are 
+// (configs.length x strLevels.length x strLevels.length) = 324 
+// possible test combinations
 for (var cfg in configs) {
   var configToTest = configs[cfg];
   var nop = configToTest === 'nop';
@@ -84,43 +159,15 @@ for (var cfg in configs) {
   batch[context]= getTopLevelContext(nop, configToTest, context);
   batches.push(batch);
 
-  // each top-level context has strLevels sub-contexts, one per logger which has set to a specific level in the top-level context's topic
+  // each top-level context has strLevels sub-contexts, one per logger 
-  strLevels.forEach(function (baseLevel) {
+  // which has set to a specific level in the top-level context's topic
-    var baseLevelSubContext = 'and checking the logger whose level was set to '+baseLevel ;
+  strLevels.forEach(setupBaseLevelAndCompareToOtherLevels);
-    batch[context][baseLevelSubContext] = {topic: baseLevel};
+}
-
-    // each logging level has strLevels sub-contexts,
-    // to exhaustively test all the combinations of setLevel(baseLevel) and isLevelEnabled(comparisonLevel) per config
-    strLevels.forEach(function (comparisonLevel) {
-      var comparisonLevelSubContext = 'with isLevelEnabled('+comparisonLevel+')';
-
-      // calculate this independently of log4js, but we'll add a vow later on to check that we're not mismatched with log4js
-      var expectedResult = strLevels.indexOf(baseLevel) <= strLevels.indexOf(comparisonLevel);
-
-      // the topic simply gathers all the parameters for the vow into an object, to simplify the vow's work.
-      batch[context][baseLevelSubContext][comparisonLevelSubContext] = {topic: function(baseLevel, log4js){
-        return {comparisonLevel: comparisonLevel, baseLevel: baseLevel, log4js: log4js, expectedResult: expectedResult};
-      }};
-
-      var vow = 'should return '+expectedResult;
-      batch[context][baseLevelSubContext][comparisonLevelSubContext][vow] = function(topic){
-        var result = topic.log4js.getLogger(getLoggerName(topic.baseLevel)).isLevelEnabled(topic.log4js.levels.toLevel(topic.comparisonLevel));
-        assert.equal(result, topic.expectedResult, 'Failed: '+getLoggerName(topic.baseLevel)+'.isLevelEnabled( '+topic.comparisonLevel+' ) returned '+result);
-      };
-
-      // the extra vow to check the comparison between baseLevel and comparisonLevel we performed earlier matches log4js' comparison too
-      batch[context][baseLevelSubContext][comparisonLevelSubContext]['finally checking for comparison mismatch with log4js'] = function(topic){
-        var er = topic.log4js.levels.toLevel(topic.baseLevel).isLessThanOrEqualTo(topic.log4js.levels.toLevel(topic.comparisonLevel));
-        assert.equal(er, topic.expectedResult, 'Mismatch: for setLevel('+topic.baseLevel+') was expecting a comparison with '+topic.comparisonLevel+' to be '+topic.expectedResult);
-      };
-    });
-  });
-};
 
 showProgress('Running tests');
 var v = vows.describe('log4js.configure(), with or without a "levels" property');
 
-batches.forEach(function(batch) {v=v.addBatch(batch)});
+batches.forEach(function(batch) {v=v.addBatch(batch);});
 
 v.export(module);
 

test/connect-logger-test.js

@@ -1,5 +1,9 @@
+/* jshint maxparams:7 */
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
+, util   = require('util')
+, EE     = require('events').EventEmitter
 , levels = require('../lib/levels');
 
 function MockLogger() {
@@ -19,25 +23,41 @@ function MockLogger() {
 
 }
 
-function MockRequest(remoteAddr, method, originalUrl) {
+function MockRequest(remoteAddr, method, originalUrl, headers) {
 
   this.socket = { remoteAddress: remoteAddr };
   this.originalUrl = originalUrl;
   this.method = method;
   this.httpVersionMajor = '5';
   this.httpVersionMinor = '0';
-    this.headers = {}
+  this.headers = headers || {};
 
+  var self = this;
+  Object.keys(this.headers).forEach(function(key) {
+    self.headers[key.toLowerCase()] = self.headers[key];
+  });
 }
 
-function MockResponse(statusCode) {
+function MockResponse() {
-
+  var r = this;
-    this.statusCode = statusCode;
-
   this.end = function(chunk, encoding) {
+      r.emit('finish');
+  };
 
-    }
+  this.writeHead = function(code, headers) {
+      this.statusCode = code;
+      this._headers = headers;
+  };
+}
 
+util.inherits(MockResponse, EE);
+
+function request(cl, method, url, code, reqHeaders, resHeaders) {
+  var req = new MockRequest('my.remote.addr', method, url, reqHeaders);
+  var res = new MockResponse();
+  cl(req, res, function() {});
+  res.writeHead(code, resHeaders);
+  res.end('chunk','encoding');
 }
 
 vows.describe('log4js connect logger').addBatch({
@@ -67,11 +87,11 @@ vows.describe('log4js connect logger').addBatch({
       topic: function(clm) {
         var ml = new MockLogger();
         var cl = clm.connectLogger(ml);
-		var req = new MockRequest('my.remote.addr', 'GET', 'http://url');
+        var cb = this.callback;
-		var res = new MockResponse(200);
+        request(cl, 'GET', 'http://url', 200);
-		cl(req, res, function() { });
+        setTimeout(function() {
-        	res.end('chunk', 'encoding');
+          cb(null, ml.messages);
-        	return ml.messages;
+        },10);
       },
 
       'check message': function(messages) {
@@ -90,10 +110,7 @@ vows.describe('log4js connect logger').addBatch({
         var ml = new MockLogger();
         ml.level = levels.FATAL;
         var cl = clm.connectLogger(ml);
-		var req = new MockRequest('my.remote.addr', 'GET', 'http://url');
+        request(cl, 'GET', 'http://url', 200);
-		var res = new MockResponse(200);
-		cl(req, res, function() { });
-		res.end('chunk', 'encoding');
         return ml.messages;
       },
 
@@ -106,14 +123,13 @@ vows.describe('log4js connect logger').addBatch({
     'log events with non-default level and custom format' : {
       topic: function(clm) {
         var ml = new MockLogger();
+        var cb = this.callback;
         ml.level = levels.INFO;
         var cl = clm.connectLogger(ml, { level: levels.INFO, format: ':method :url' } );
-		var req = new MockRequest('my.remote.addr', 'GET', 'http://url');
+        request(cl, 'GET', 'http://url', 200);
-		var res = new MockResponse(200);
+        setTimeout(function() {
-		cl(req, res, function() { });
+          cb(null, ml.messages);
-		res.end('chunk', 'encoding');
+        },10);      },
-		return ml.messages;
-	    },
 
       'check message': function(messages) {
         assert.isArray(messages);
@@ -121,8 +137,159 @@ vows.describe('log4js connect logger').addBatch({
         assert.ok(levels.INFO.isEqualTo(messages[0].level));
         assert.equal(messages[0].message, 'GET http://url');
       }
-	}
+    },
 
+    'logger with options as string': {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, ':method :url');
+        request(cl, 'POST', 'http://meh', 200);
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+      'should use the passed in format': function(messages) {
+        assert.equal(messages[0].message, 'POST http://meh');
       }
+    },
 
+    'auto log levels': {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, { level: 'auto', format: ':method :url' });
+        request(cl, 'GET', 'http://meh', 200);
+        request(cl, 'GET', 'http://meh', 201);
+        request(cl, 'GET', 'http://meh', 302);
+        request(cl, 'GET', 'http://meh', 404);
+        request(cl, 'GET', 'http://meh', 500);
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+
+      'should use INFO for 2xx': function(messages) {
+        assert.ok(levels.INFO.isEqualTo(messages[0].level));
+        assert.ok(levels.INFO.isEqualTo(messages[1].level));
+      },
+
+      'should use WARN for 3xx': function(messages) {
+        assert.ok(levels.WARN.isEqualTo(messages[2].level));
+      },
+
+      'should use ERROR for 4xx': function(messages) {
+        assert.ok(levels.ERROR.isEqualTo(messages[3].level));
+      },
+
+      'should use ERROR for 5xx': function(messages) {
+        assert.ok(levels.ERROR.isEqualTo(messages[4].level));
+      }
+    },
+
+    'format using a function': {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, function(req, res, formatFn) { return "I was called"; });
+        request(cl, 'GET', 'http://blah', 200);
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+
+      'should call the format function': function(messages) {
+        assert.equal(messages[0].message, 'I was called');
+      }
+    },
+
+    'format that includes request headers': {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, ':req[Content-Type]');
+        request(
+          cl,
+          'GET', 'http://blah', 200,
+          { 'Content-Type': 'application/json' }
+        );
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+      'should output the request header': function(messages) {
+        assert.equal(messages[0].message, 'application/json');
+      }
+    },
+
+    'format that includes response headers': {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, ':res[Content-Type]');
+        request(
+          cl,
+          'GET', 'http://blah', 200,
+          null,
+          { 'Content-Type': 'application/cheese' }
+        );
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+
+      'should output the response header': function(messages) {
+        assert.equal(messages[0].message, 'application/cheese');
+      }
+    },
+
+    'log events with custom token' : {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, { level: levels.INFO, format: ':method :url :custom_string', tokens: [{
+          token: ':custom_string', replacement: 'fooBAR'
+        }] } );
+        request(cl, 'GET', 'http://url', 200);
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+
+      'check message': function(messages) {
+        assert.isArray(messages);
+        assert.equal(messages.length, 1);
+        assert.ok(levels.INFO.isEqualTo(messages[0].level));
+        assert.equal(messages[0].message, 'GET http://url fooBAR');
+      }
+    },
+
+    'log events with custom override token' : {
+      topic: function(clm) {
+        var ml = new MockLogger();
+        var cb = this.callback;
+        ml.level = levels.INFO;
+        var cl = clm.connectLogger(ml, { level: levels.INFO, format: ':method :url :date', tokens: [{
+          token: ':date', replacement: "20150310"
+        }] } );
+        request(cl, 'GET', 'http://url', 200);
+        setTimeout(function() {
+          cb(null, ml.messages);
+        },10);
+      },
+
+      'check message': function(messages) {
+        assert.isArray(messages);
+        assert.equal(messages.length, 1);
+        assert.ok(levels.INFO.isEqualTo(messages[0].level));
+        assert.equal(messages[0].message, 'GET http://url 20150310');
+      }
+    }
+  }
 }).export(module);

test/consoleAppender-test.js

@@ -0,0 +1,33 @@
+"use strict";
+var assert = require('assert')
+, vows = require('vows')
+, layouts = require('../lib/layouts')
+, sandbox = require('sandboxed-module');
+
+vows.describe('../lib/appenders/console').addBatch({
+  'appender': {
+    topic: function() {
+      var messages = []
+      , fakeConsole = {
+        log: function(msg) { messages.push(msg); }
+      }
+      , appenderModule = sandbox.require(
+        '../lib/appenders/console',
+        {
+          globals: {
+            'console': fakeConsole
+          }
+        }
+      )
+      , appender = appenderModule.appender(layouts.messagePassThroughLayout);
+
+      appender({ data: ["blah"] });
+      return messages;
+    },
+
+    'should output to console': function(messages) {
+      assert.equal(messages[0], 'blah');
+    }
+  }
+          
+}).exportTo(module);

test/dateFileAppender-test.js

@@ -1,8 +1,11 @@
-var vows = require('vows'),
+"use strict";
-    assert = require('assert'),
+var vows = require('vows')
-    path = require('path'),
+, assert = require('assert')
-    fs = require('fs'),
+, path = require('path')
-    log4js = require('../lib/log4js');
+, fs = require('fs')
+, sandbox = require('sandboxed-module')
+, log4js = require('../lib/log4js')
+, EOL = require('os').EOL || '\n';
 
 function removeFile(filename) {
   return function() {
@@ -40,6 +43,46 @@ vows.describe('../lib/appenders/dateFile').addBatch({
       
       'should only add one `exit` listener': function (initialCount) {
         assert.equal(process.listeners('exit').length, initialCount + 1);
+      },
+
+    },
+
+    'exit listener': {
+      topic: function() {
+        var exitListener
+        , openedFiles = []
+        , dateFileAppender = sandbox.require(
+          '../lib/appenders/dateFile',
+          {
+            globals: {
+              process: {
+                on: function(evt, listener) {
+                  exitListener = listener;
+                }
+              }
+            },
+            requires: {
+              '../streams': {
+                DateRollingFileStream: function(filename) {
+                  openedFiles.push(filename);
+
+                  this.end = function() {
+                    openedFiles.shift();
+                  };
+                }
+              }
+            }   
+          }
+        );
+        for (var i=0; i < 5; i += 1) {
+          dateFileAppender.appender('test' + i);
+        }
+        assert.isNotEmpty(openedFiles);
+        exitListener();
+        return openedFiles;
+      },
+      'should close all open files': function(openedFiles) {
+        assert.isEmpty(openedFiles);
       }
     },
     
@@ -66,7 +109,10 @@ vows.describe('../lib/appenders/dateFile').addBatch({
       },
       
       'should use the basic layout': function(contents) {
-                assert.match(contents, /\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] default-settings - /);
+        assert.match(
+          contents, 
+            /\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] default-settings - /
+        );
       }
     }
     
@@ -89,9 +135,88 @@ 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\n');
+        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);
       }
+    },
+    'with options.alwaysIncludePattern': {
+      topic: function() {
+        var self = this
+        , log4js = require('../lib/log4js')
+        , format = require('../lib/date_format')
+        , logger
+        , options = {
+          "appenders": [
+            {
+              "category": "tests", 
+              "type": "dateFile", 
+              "filename": "test/date-file-test",
+              "pattern": "-from-MM-dd.log",
+              "alwaysIncludePattern": true,
+              "layout": { 
+                "type": "messagePassThrough" 
+              }
+            }
+          ]
+        }
+        , thisTime = format.asString(options.appenders[0].pattern, new Date());
+        fs.writeFileSync(
+          path.join(__dirname, 'date-file-test' + thisTime), 
+          "this is existing data" + EOL,
+          'utf8'
+        );
+        log4js.clearAppenders();
+        log4js.configure(options);
+        logger = log4js.getLogger('tests');
+        logger.warn('this should be written to the file with the appended date');
+        this.teardown = removeFile('date-file-test' + thisTime);
+        //wait for filesystem to catch up
+        setTimeout(function() {
+          fs.readFile(path.join(__dirname, 'date-file-test' + thisTime), 'utf8', self.callback);
+        }, 100);
+      },
+      'should create file with the correct pattern': function(contents) {
+        assert.include(contents, 'this should be written to the file with the appended date');
+      },
+      'should not overwrite the file on open (bug found in issue #132)': function(contents) {
+        assert.include(contents, 'this is existing data');
+      }
+    },
+    'with cwd option': {
+      topic: function () {
+        var fileOpened,
+        appender = sandbox.require(
+          '../lib/appenders/dateFile',
+          { requires:
+            { '../streams':
+              { DateRollingFileStream: 
+                function(file) {
+                  fileOpened = file;
+                  return {
+                    on: function() {},
+                    end: function() {}
+                  };
+                }
+              }
+            }
+          }
+        );
+        appender.configure(
+          { 
+            filename: "whatever.log", 
+            maxLogSize: 10 
+          }, 
+          { cwd: '/absolute/path/to' }
+        );
+        return fileOpened;
+      },
+      'should prepend options.cwd to config.filename': function (fileOpened) {
+        var expected = path.sep + path.join("absolute", "path", "to", "whatever.log");
+        assert.equal(fileOpened, expected);
+      }
     }
  
   }

test/date_format-test.js

@@ -1,12 +1,15 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
 , dateFormat = require('../lib/date_format');
 
+function createFixedDate() {
+  return new Date(2010, 0, 11, 14, 31, 30, 5);
+}
+
 vows.describe('date_format').addBatch({
   'Date extensions': {
-        topic: function() {
+    topic: createFixedDate,
-            return new Date(2010, 0, 11, 14, 31, 30, 5);
-        },
     'should format a date as string using a pattern': function(date) {
       assert.equal(
         dateFormat.asString(dateFormat.DATETIME_FORMAT, date),
@@ -18,6 +21,38 @@ vows.describe('date_format').addBatch({
         dateFormat.asString(date),
         '2010-01-11 14:31:30.005'
       );
+    },
+    'should provide a ISO8601 with timezone offset format': function() {
+      var date = createFixedDate();
+      date.setMinutes(date.getMinutes() - date.getTimezoneOffset() - 660);
+      date.getTimezoneOffset = function() { return -660; };
+      assert.equal(
+        dateFormat.asString(dateFormat.ISO8601_WITH_TZ_OFFSET_FORMAT, date),
+        "2010-01-11T14:31:30+1100"
+      );
+      date = createFixedDate();
+      date.setMinutes(date.getMinutes() - date.getTimezoneOffset() + 120);
+      date.getTimezoneOffset = function() { return 120; };
+      assert.equal(
+        dateFormat.asString(dateFormat.ISO8601_WITH_TZ_OFFSET_FORMAT, date),
+        "2010-01-11T14:31:30-0200"
+      );
+
+    },
+    'should provide a just-the-time format': function(date) {
+      assert.equal(
+        dateFormat.asString(dateFormat.ABSOLUTETIME_FORMAT, date),
+        '14:31:30.005'
+      );
+    },
+    'should provide a custom format': function() {
+      var date = createFixedDate();
+      date.setMinutes(date.getMinutes() - date.getTimezoneOffset() + 120);
+      date.getTimezoneOffset = function() { return 120; };
+      assert.equal(
+        dateFormat.asString("O.SSS.ss.mm.hh.dd.MM.yy", date),
+        '-0200.005.30.31.14.11.01.10'
+      );
     }
   }
 }).export(module);

test/debug-test.js

@@ -0,0 +1,72 @@
+"use strict";
+var vows = require('vows')
+, assert = require('assert')
+, sandbox = require('sandboxed-module')
+, fakeConsole = {
+  error: function(format, label, message) {
+    this.logged = [ format, label, message ];
+  }
+}
+, globals = function(debugValue) {
+  return {
+    process: {
+      env: {
+        'NODE_DEBUG': debugValue
+      }
+    },
+    console: fakeConsole
+  };
+};
+
+vows.describe('../lib/debug').addBatch({
+  'when NODE_DEBUG is set to log4js': {
+    topic: function() {
+      var debug = sandbox.require(
+        '../lib/debug', 
+        { 'globals': globals('log4js') }
+      );
+
+      fakeConsole.logged = [];
+      debug('cheese')('biscuits');
+      return fakeConsole.logged;
+    },
+    'it should log to console.error': function(logged) {
+      assert.equal(logged[0], 'LOG4JS: (%s) %s');
+      assert.equal(logged[1], 'cheese');
+      assert.equal(logged[2], 'biscuits');
+    }
+  },
+
+  'when NODE_DEBUG is set to not log4js': {
+    topic: function() {
+      var debug = sandbox.require(
+        '../lib/debug',
+        { globals: globals('other_module') }
+      );
+
+      fakeConsole.logged = [];
+      debug('cheese')('biscuits');
+      return fakeConsole.logged;
+    },
+    'it should not log to console.error': function(logged) {
+      assert.equal(logged.length, 0);
+    }
+  },
+
+  'when NODE_DEBUG is not set': {
+    topic: function() {
+      var debug = sandbox.require(
+        '../lib/debug',
+        { globals: globals(null) }
+      );
+
+      fakeConsole.logged = [];
+      debug('cheese')('biscuits');
+      return fakeConsole.logged;
+    },
+    'it should not log to console.error': function(logged) {
+      assert.equal(logged.length, 0);
+    }
+  }
+
+}).exportTo(module);

test/fileAppender-test.js

@@ -1,8 +1,12 @@
+"use strict";
 var vows = require('vows')
 , fs = require('fs')
 , path = require('path')
+, sandbox = require('sandboxed-module')
 , log4js = require('../lib/log4js')
-, assert = require('assert');
+, assert = require('assert')
+, zlib = require('zlib')
+, EOL = require('os').EOL || '\n';
 
 log4js.clearAppenders();
 
@@ -29,18 +33,59 @@ vows.describe('log4js fileAppender').addBatch({
       return listenersCount;
     },
     
-      'does not adds more than one `exit` listeners': function (initialCount) {
+    'does not add more than one `exit` listeners': function (initialCount) {
       assert.ok(process.listeners('exit').length <= initialCount + 1);
     }
   },
 
+  'exit listener': {
+    topic: function() {
+      var exitListener
+      , openedFiles = []
+      , fileAppender = sandbox.require(
+        '../lib/appenders/file',
+        {
+          globals: {
+            process: {
+              on: function(evt, listener) {
+                exitListener = listener;
+              }
+            }
+          },
+          requires: {
+            '../streams': {
+              RollingFileStream: function(filename) {
+                openedFiles.push(filename);
+                
+                this.end = function() {
+                  openedFiles.shift();
+                };
+
+                this.on = function() {};
+              }
+            }
+          }   
+        }
+      );
+      for (var i=0; i < 5; i += 1) {
+        fileAppender.appender('test' + i, null, 100);
+      }
+      assert.isNotEmpty(openedFiles);
+      exitListener();
+      return openedFiles;
+    },
+    'should close all open files': function(openedFiles) {
+      assert.isEmpty(openedFiles);
+    }
+  },
+  
   'with default fileAppender settings': {
     topic: function() {
       var that = this
       , testFile = path.join(__dirname, '/fa-default-test.log')
       , logger = log4js.getLogger('default-settings');
       remove(testFile);
-            //log4js.configure({ appenders:[ { type: "file", filename: testFile, category: 'default-settings' } ] });
+
       log4js.clearAppenders();
       log4js.addAppender(require('../lib/appenders/file').appender(testFile), 'default-settings');
       
@@ -50,11 +95,78 @@ vows.describe('log4js fileAppender').addBatch({
         fs.readFile(testFile, "utf8", that.callback);
       }, 100);
     },
-        'should write log messages to the file': function(err, fileContents) {
+    'should write log messages to the file': function (err, fileContents) {
-            assert.include(fileContents, "This should be in the file.\n");
+      assert.include(fileContents, "This should be in the file." + EOL);
     },
     'log messages should be in the basic layout format': function(err, fileContents) {
-            assert.match(fileContents, /\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] default-settings - /);
+      assert.match(
+        fileContents, 
+          /\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] default-settings - /
+      );
+    }
+  },
+  'fileAppender subcategories': {
+    topic: function() {
+      var that = this;
+
+      log4js.clearAppenders();
+
+      function addAppender(cat) {
+        var testFile = path.join(__dirname, '/fa-subcategories-test-'+cat.join('-').replace(/\./g, "_")+'.log');
+        remove(testFile);
+        log4js.addAppender(require('../lib/appenders/file').appender(testFile), cat);
+        return testFile;
+      }
+
+      var file_sub1 = addAppender([ 'sub1']);
+      
+      var file_sub1_sub12$sub1_sub13 = addAppender([ 'sub1.sub12', 'sub1.sub13' ]);
+      
+      var file_sub1_sub12 = addAppender([ 'sub1.sub12' ]);
+
+      
+      var logger_sub1_sub12_sub123 = log4js.getLogger('sub1.sub12.sub123');
+      
+      var logger_sub1_sub13_sub133 = log4js.getLogger('sub1.sub13.sub133');
+
+      var logger_sub1_sub14 = log4js.getLogger('sub1.sub14');
+
+      var logger_sub2 = log4js.getLogger('sub2');
+      
+
+      logger_sub1_sub12_sub123.info('sub1_sub12_sub123');
+      
+      logger_sub1_sub13_sub133.info('sub1_sub13_sub133');
+
+      logger_sub1_sub14.info('sub1_sub14');
+
+      logger_sub2.info('sub2');
+           
+      
+      setTimeout(function() {
+        that.callback(null, {
+          file_sub1: fs.readFileSync(file_sub1).toString(),
+          file_sub1_sub12$sub1_sub13: fs.readFileSync(file_sub1_sub12$sub1_sub13).toString(),
+          file_sub1_sub12: fs.readFileSync(file_sub1_sub12).toString()
+        });        
+      }, 3000);
+    },
+    'check file contents': function (err, fileContents) {
+
+      // everything but category 'sub2'
+      assert.match(fileContents.file_sub1, /^(\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] (sub1.sub12.sub123 - sub1_sub12_sub123|sub1.sub13.sub133 - sub1_sub13_sub133|sub1.sub14 - sub1_sub14)[\s\S]){3}$/);
+      assert.ok(fileContents.file_sub1.match(/sub123/) && fileContents.file_sub1.match(/sub133/) && fileContents.file_sub1.match(/sub14/));
+      assert.ok(!fileContents.file_sub1.match(/sub2/));
+
+      // only catgories starting with 'sub1.sub12' and 'sub1.sub13'
+      assert.match(fileContents.file_sub1_sub12$sub1_sub13, /^(\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] (sub1.sub12.sub123 - sub1_sub12_sub123|sub1.sub13.sub133 - sub1_sub13_sub133)[\s\S]){2}$/);
+      assert.ok(fileContents.file_sub1_sub12$sub1_sub13.match(/sub123/) && fileContents.file_sub1_sub12$sub1_sub13.match(/sub133/));
+      assert.ok(!fileContents.file_sub1_sub12$sub1_sub13.match(/sub14|sub2/));
+
+      // only catgories starting with 'sub1.sub12'
+      assert.match(fileContents.file_sub1_sub12, /^(\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] (sub1.sub12.sub123 - sub1_sub12_sub123)[\s\S]){1}$/);
+      assert.ok(!fileContents.file_sub1_sub12.match(/sub14|sub2|sub13/));
+
     }
   },
   'with a max file size and no backups': {
@@ -66,7 +178,10 @@ vows.describe('log4js fileAppender').addBatch({
       remove(testFile + '.1');
       //log file of 100 bytes maximum, no backups
       log4js.clearAppenders();
-            log4js.addAppender(require('../lib/appenders/file').appender(testFile, log4js.layouts.basicLayout, 100, 0), 'max-file-size');
+      log4js.addAppender(
+        require('../lib/appenders/file').appender(testFile, log4js.layouts.basicLayout, 100, 0), 
+        'max-file-size'
+      );
       logger.info("This is the first log message.");
       logger.info("This is an intermediate log message.");
       logger.info("This is the second log message.");
@@ -76,7 +191,7 @@ vows.describe('log4js fileAppender').addBatch({
       }, 100);
     },
     'log file should only contain the second message': function(err, fileContents) {
-            assert.include(fileContents, "This is the second log message.\n");
+      assert.include(fileContents, "This is the second log message.");
       assert.equal(fileContents.indexOf("This is the first log message."), -1);
     },
     'the number of files': {
@@ -85,7 +200,9 @@ vows.describe('log4js fileAppender').addBatch({
       },
       'starting with the test file name should be two': function(err, files) {
         //there will always be one backup if you've specified a max log size
-                var logFiles = files.filter(function(file) { return file.indexOf('fa-maxFileSize-test.log') > -1; });
+        var logFiles = files.filter(
+          function(file) { return file.indexOf('fa-maxFileSize-test.log') > -1; }
+        );
         assert.equal(logFiles.length, 2);
       }
     }
@@ -100,7 +217,10 @@ vows.describe('log4js fileAppender').addBatch({
       
       //log file of 50 bytes maximum, 2 backups
       log4js.clearAppenders();
-            log4js.addAppender(require('../lib/appenders/file').appender(testFile, log4js.layouts.basicLayout, 50, 2), 'max-file-size-backups');
+      log4js.addAppender(
+        require('../lib/appenders/file').appender(testFile, log4js.layouts.basicLayout, 50, 2), 
+        'max-file-size-backups'
+      );
       logger.info("This is the first log message.");
       logger.info("This is the second log message.");
       logger.info("This is the third log message.");
@@ -108,42 +228,127 @@ vows.describe('log4js fileAppender').addBatch({
       var that = this;
       //give the system a chance to open the stream
       setTimeout(function() {
-                fs.readdir(__dirname, that.callback);
+        fs.readdir(__dirname, function(err, files) { 
+          if (files) { 
+            that.callback(null, files.sort()); 
+          } else { 
+            that.callback(err, files); 
+          }
+        });
       }, 200);
     },
     'the log files': {
       topic: function(files) {
-                var logFiles = files.filter(function(file) { return file.indexOf('fa-maxFileSize-with-backups-test.log') > -1; });
+        var logFiles = files.filter(
+          function(file) { return file.indexOf('fa-maxFileSize-with-backups-test.log') > -1; }
+        );
         return logFiles;
       },
       'should be 3': function (files) {
         assert.equal(files.length, 3);
       },
       'should be named in sequence': function (files) {
-                assert.deepEqual(files.sort(), ['fa-maxFileSize-with-backups-test.log', 'fa-maxFileSize-with-backups-test.log.1', 'fa-maxFileSize-with-backups-test.log.2']);
+        assert.deepEqual(files, [
+          'fa-maxFileSize-with-backups-test.log', 
+          'fa-maxFileSize-with-backups-test.log.1', 
+          'fa-maxFileSize-with-backups-test.log.2'
+        ]);
       },
       'and the contents of the first file': {
         topic: function(logFiles) {
           fs.readFile(path.join(__dirname, logFiles[0]), "utf8", this.callback);
         },
-                'should be empty because the last log message triggers rolling': function(contents) {
+        'should be the last log message': function(contents) {
-                    assert.isEmpty(contents);
+          assert.include(contents, 'This is the fourth log message.');
         }
       },
       'and the contents of the second file': {
         topic: function(logFiles) {
           fs.readFile(path.join(__dirname, logFiles[1]), "utf8", this.callback);
         },
-                'should be the last log message': function(contents) {
+        'should be the third log message': function(contents) {
-                    assert.include(contents, 'This is the fourth log message.');
+          assert.include(contents, 'This is the third log message.');
         }
       },
       'and the contents of the third file': {
         topic: function(logFiles) {
           fs.readFile(path.join(__dirname, logFiles[2]), "utf8", this.callback);
         },
+        'should be the second log message': function(contents) {
+          assert.include(contents, 'This is the second log message.');
+        }
+      }
+    }
+  },
+  'with a max file size and 2 compressed backups': {
+    topic: function() {
+      var testFile = path.join(__dirname, '/fa-maxFileSize-with-backups-compressed-test.log')
+      , logger = log4js.getLogger('max-file-size-backups');
+      remove(testFile);
+      remove(testFile+'.1.gz');
+      remove(testFile+'.2.gz');
+      
+      //log file of 50 bytes maximum, 2 backups
+      log4js.clearAppenders();
+      log4js.addAppender(
+        require('../lib/appenders/file').appender(testFile, log4js.layouts.basicLayout, 50, 2, true), 
+        'max-file-size-backups'
+      );
+      logger.info("This is the first log message.");
+      logger.info("This is the second log message.");
+      logger.info("This is the third log message.");
+      logger.info("This is the fourth log message.");
+      var that = this;
+      //give the system a chance to open the stream
+      setTimeout(function() {
+        fs.readdir(__dirname, function(err, files) { 
+          if (files) { 
+            that.callback(null, files.sort()); 
+          } else { 
+            that.callback(err, files); 
+          }
+        });
+      }, 1000);
+    },
+    'the log files': {
+      topic: function(files) {
+        var logFiles = files.filter(
+          function(file) { return file.indexOf('fa-maxFileSize-with-backups-compressed-test.log') > -1; }
+        );
+        return logFiles;
+      },
+      'should be 3': function (files) {
+        assert.equal(files.length, 3);
+      },
+      'should be named in sequence': function (files) {
+        assert.deepEqual(files, [
+          'fa-maxFileSize-with-backups-compressed-test.log', 
+          'fa-maxFileSize-with-backups-compressed-test.log.1.gz', 
+          'fa-maxFileSize-with-backups-compressed-test.log.2.gz'
+        ]);
+      },
+      'and the contents of the first file': {
+        topic: function(logFiles) {
+          fs.readFile(path.join(__dirname, logFiles[0]), "utf8", this.callback);
+        },
+        'should be the last log message': function(contents) {
+          assert.include(contents, 'This is the fourth log message.');
+        }
+      },
+      'and the contents of the second file': {
+        topic: function(logFiles) {
+          zlib.gunzip(fs.readFileSync(path.join(__dirname, logFiles[1])), this.callback);
+        },
         'should be the third log message': function(contents) {
-                    assert.include(contents, 'This is the third log message.');
+          assert.include(contents.toString('utf8'), 'This is the third log message.');
+        }
+      },
+      'and the contents of the third file': {
+        topic: function(logFiles) {
+          zlib.gunzip(fs.readFileSync(path.join(__dirname, logFiles[2])), this.callback);
+        },
+        'should be the second log message': function(contents) {
+          assert.include(contents.toString('utf8'), 'This is the second log message.');
         }
       }
     }
@@ -156,18 +361,59 @@ vows.describe('log4js fileAppender').addBatch({
         , logger;
         //this config file defines one file appender (to ./tmp-tests.log)
         //and sets the log level for "tests" to WARN
-                log4js.configure('test/log4js.json');
+        log4js.configure('./test/log4js.json');
         logger = log4js.getLogger('tests');
         logger.info('this should not be written to the file');
         logger.warn('this should be written to the file');
         
         fs.readFile('tmp-tests.log', 'utf8', this.callback);
       },
-	    'should load appender configuration from a json file': function(err, contents) {
+      'should load appender configuration from a json file': function (err, contents) {
-	        assert.include(contents, 'this should be written to the file\n');
+        assert.include(contents, 'this should be written to the file' + EOL);
         assert.equal(contents.indexOf('this should not be written to the file'), -1);
       }
     }
   }
+}).addBatch({
+  'when underlying stream errors': {
+    topic: function() {
+      var consoleArgs
+      , errorHandler
+      , fileAppender = sandbox.require(
+        '../lib/appenders/file',
+        {
+          globals: {
+            console: {
+              error: function() {
+                consoleArgs = Array.prototype.slice.call(arguments);
+              }
+            }
+          },
+          requires: {
+            '../streams': {
+              RollingFileStream: function(filename) {
+                
+                this.end = function() {};
+                this.on = function(evt, cb) {
+                  if (evt === 'error') {
+                    errorHandler = cb;
+                  }
+                };
+              }
+            }
+          }   
+        }
+      );
+      fileAppender.appender('test1.log', null, 100);
+      errorHandler({ error: 'aargh' });
+      return consoleArgs;
+    },
+    'should log the error to console.error': function(consoleArgs) {
+      assert.isNotEmpty(consoleArgs);
+      assert.equal(consoleArgs[0], 'log4js.fileAppender - Writing to file %s, error happened ');
+      assert.equal(consoleArgs[1], 'test1.log');
+      assert.equal(consoleArgs[2].error, 'aargh');
+    }
+  }
 
 }).export(module);

test/fileSyncAppender-test.js

@@ -0,0 +1,182 @@
+"use strict";
+var vows = require('vows')
+, fs = require('fs')
+, path = require('path')
+, sandbox = require('sandboxed-module')
+, log4js = require('../lib/log4js')
+, assert = require('assert')
+, EOL = require('os').EOL || '\n';
+
+log4js.clearAppenders();
+
+function remove(filename) {
+  try {
+    fs.unlinkSync(filename);
+  } catch (e) {
+    //doesn't really matter if it failed
+  }
+}
+
+vows.describe('log4js fileSyncAppender').addBatch({
+  'with default fileSyncAppender settings': {
+    topic: function() {
+      var that = this
+      , testFile = path.join(__dirname, '/fa-default-sync-test.log')
+      , logger = log4js.getLogger('default-settings');
+      remove(testFile);
+
+      log4js.clearAppenders();
+      log4js.addAppender(require('../lib/appenders/fileSync').appender(testFile), 'default-settings');
+      
+      logger.info("This should be in the file.");
+      
+      fs.readFile(testFile, "utf8", that.callback);
+    },
+    'should write log messages to the file': function (err, fileContents) {
+      assert.include(fileContents, "This should be in the file." + EOL);
+    },
+    'log messages should be in the basic layout format': function(err, fileContents) {
+      assert.match(
+        fileContents, 
+          /\[\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}\.\d{3}\] \[INFO\] default-settings - /
+      );
+    }
+  },
+  'with a max file size and no backups': {
+    topic: function() {
+      var testFile = path.join(__dirname, '/fa-maxFileSize-sync-test.log')
+      , logger = log4js.getLogger('max-file-size')
+      , that = this;
+      remove(testFile);
+      remove(testFile + '.1');
+      //log file of 100 bytes maximum, no backups
+      log4js.clearAppenders();
+      log4js.addAppender(
+        require('../lib/appenders/fileSync').appender(testFile, log4js.layouts.basicLayout, 100, 0), 
+        'max-file-size'
+      );
+      logger.info("This is the first log message.");
+      logger.info("This is an intermediate log message.");
+      logger.info("This is the second log message.");
+
+      fs.readFile(testFile, "utf8", that.callback);
+    },
+    'log file should only contain the second message': function (err, fileContents) {
+      assert.include(fileContents, "This is the second log message." + EOL);
+      assert.equal(fileContents.indexOf("This is the first log message."), -1);
+    },
+    'the number of files': {
+      topic: function() {
+        fs.readdir(__dirname, this.callback);
+      },
+      'starting with the test file name should be two': function(err, files) {
+        //there will always be one backup if you've specified a max log size
+        var logFiles = files.filter(
+          function(file) { return file.indexOf('fa-maxFileSize-sync-test.log') > -1; }
+        );
+        assert.equal(logFiles.length, 2);
+      }
+    }
+  },
+  'with a max file size and 2 backups': {
+    topic: function() {
+      var testFile = path.join(__dirname, '/fa-maxFileSize-with-backups-sync-test.log')
+      , logger = log4js.getLogger('max-file-size-backups');
+      remove(testFile);
+      remove(testFile+'.1');
+      remove(testFile+'.2');
+      
+      //log file of 50 bytes maximum, 2 backups
+      log4js.clearAppenders();
+      log4js.addAppender(
+        require('../lib/appenders/fileSync').appender(testFile, log4js.layouts.basicLayout, 50, 2), 
+        'max-file-size-backups'
+      );
+      logger.info("This is the first log message.");
+      logger.info("This is the second log message.");
+      logger.info("This is the third log message.");
+      logger.info("This is the fourth log message.");
+      var that = this;
+      
+      fs.readdir(__dirname, function(err, files) { 
+        if (files) { 
+          that.callback(null, files.sort()); 
+        } else { 
+          that.callback(err, files); 
+        }
+      });
+    },
+    'the log files': {
+      topic: function(files) {
+        var logFiles = files.filter(
+          function(file) { return file.indexOf('fa-maxFileSize-with-backups-sync-test.log') > -1; }
+        );
+        return logFiles;
+      },
+      'should be 3': function (files) {
+        assert.equal(files.length, 3);
+      },
+      'should be named in sequence': function (files) {
+        assert.deepEqual(files, [
+          'fa-maxFileSize-with-backups-sync-test.log', 
+          'fa-maxFileSize-with-backups-sync-test.log.1', 
+          'fa-maxFileSize-with-backups-sync-test.log.2'
+        ]);
+      },
+      'and the contents of the first file': {
+        topic: function(logFiles) {
+          fs.readFile(path.join(__dirname, logFiles[0]), "utf8", this.callback);
+        },
+        'should be the last log message': function(contents) {
+          assert.include(contents, 'This is the fourth log message.');
+        }
+      },
+      'and the contents of the second file': {
+        topic: function(logFiles) {
+          fs.readFile(path.join(__dirname, logFiles[1]), "utf8", this.callback);
+        },
+        'should be the third log message': function(contents) {
+          assert.include(contents, 'This is the third log message.');
+        }
+      },
+      'and the contents of the third file': {
+        topic: function(logFiles) {
+          fs.readFile(path.join(__dirname, logFiles[2]), "utf8", this.callback);
+        },
+        'should be the second log message': function(contents) {
+          assert.include(contents, 'This is the second log message.');
+        }
+      }
+    }
+  }
+}).addBatch({
+  'configure' : {
+    'with fileSyncAppender': {
+      topic: function() {
+        var log4js = require('../lib/log4js')
+        , logger;
+        //this config defines one file appender (to ./tmp-sync-tests.log)
+        //and sets the log level for "tests" to WARN
+        log4js.configure({
+            appenders: [{ 
+                category: "tests", 
+                type: "file", 
+                filename: "tmp-sync-tests.log", 
+                layout: { type: "messagePassThrough" } 
+            }],
+  
+            levels: { tests:  "WARN" }
+        });
+        logger = log4js.getLogger('tests');
+        logger.info('this should not be written to the file');
+        logger.warn('this should be written to the file');
+        
+        fs.readFile('tmp-sync-tests.log', 'utf8', this.callback);
+      },
+      'should load appender configuration from a json file': function(err, contents) {
+        assert.include(contents, 'this should be written to the file' + EOL);
+        assert.equal(contents.indexOf('this should not be written to the file'), -1);
+      }
+    }
+  }
+}).export(module);

test/gelfAppender-test.js

@@ -1,13 +1,17 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
 , sandbox = require('sandboxed-module')
 , log4js = require('../lib/log4js')
+, realLayouts = require('../lib/layouts')
 , setupLogging = function(options, category, compressedLength) {
   var fakeDgram = {
     sent: false,
     socket: {
       packetLength: 0,
+      closed: false,
       close: function() {
+        this.closed = true;
       },
       send: function(pkt, offset, pktLength, port, host) {
         fakeDgram.sent = true;
@@ -26,6 +30,11 @@ var vows = require('vows')
   , fakeZlib = {
     gzip: function(objectToCompress, callback) {
       fakeZlib.uncompressed = objectToCompress;
+      if (this.shouldError) {
+        callback({ stack: "oh noes" });
+        return;
+      }
+
       if (compressedLength) {
         callback(null, { length: compressedLength });
       } else {
@@ -33,10 +42,35 @@ var vows = require('vows')
       }
     }
   }
+  , exitHandler
+  , fakeConsole = {
+    error: function(message) {
+      this.message = message;
+    }
+  }
+  , fakeLayouts = {
+    layout: function(type, options) {
+      this.type = type;
+      this.options = options;
+      return realLayouts.messagePassThroughLayout;
+    },
+    messagePassThroughLayout: realLayouts.messagePassThroughLayout
+  }
   , appender = sandbox.require('../lib/appenders/gelf', {
     requires: {
       dgram: fakeDgram,
-          zlib: fakeZlib
+      zlib: fakeZlib,
+      '../layouts': fakeLayouts
+    },
+    globals: {
+      process: {
+        on: function(evt, handler) {
+          if (evt === 'exit') {
+            exitHandler = handler;
+          }
+        }
+      },
+      console: fakeConsole
     }
   });
 
@@ -45,12 +79,13 @@ var vows = require('vows')
   return {
     dgram: fakeDgram,
     compress: fakeZlib,
+    exitHandler: exitHandler,
+    console: fakeConsole,
+    layouts: fakeLayouts,
     logger: log4js.getLogger(category || "gelf-test")
   };
 };
 
-//log4js.configure({ doNotReplaceConsole: true });
-
 vows.describe('log4js gelfAppender').addBatch({
 
   'with default gelfAppender settings': {
@@ -80,12 +115,10 @@ vows.describe('log4js gelfAppender').addBatch({
         return message;
       },
       'should be in the gelf format': function(message) {
-                assert.equal(message.version, '1.0');
+        assert.equal(message.version, '1.1');
         assert.equal(message.host, require('os').hostname());
         assert.equal(message.level, 6); //INFO
-                assert.equal(message.facility, 'nodejs-server');
+        assert.equal(message.short_message, 'This is a test');
-                assert.equal(message.full_message, message.short_message);
-                assert.equal(message.full_message, 'This is a test');
       }
     }
   },
@@ -131,8 +164,94 @@ vows.describe('log4js gelfAppender').addBatch({
       },
       'should pick up the options': function(message) {
         assert.equal(message.host, 'cheese');
-                assert.equal(message.facility, 'nonsense');
+        assert.equal(message._facility, 'nonsense');
+      }
+    }
+  },
+
+  'on process.exit': {
+    topic: function() {
+      var setup = setupLogging();
+      setup.exitHandler();
+      return setup;
+    },
+    'should close open sockets': function(setup) {
+      assert.isTrue(setup.dgram.socket.closed);
+    }
+  },
+
+  'on zlib error': {
+    topic: function() {
+      var setup = setupLogging();
+      setup.compress.shouldError = true;
+      setup.logger.info('whatever');
+      return setup;
+    },
+    'should output to console.error': function(setup) {
+      assert.equal(setup.console.message, 'oh noes');
+    }
+  },
+
+  'with layout in configuration': {
+    topic: function() {
+      var setup = setupLogging({
+        layout: {
+          type: 'madeuplayout',
+          earlgrey: 'yes, please'
+        }
+      });
+      return setup;
+    },
+    'should pass options to layout': function(setup) {
+      assert.equal(setup.layouts.type, 'madeuplayout');
+      assert.equal(setup.layouts.options.earlgrey, 'yes, please');
+    }
+  },
+
+  'with custom fields options': {
+    topic: function() {
+      var setup = setupLogging({
+        host: 'somewhere',
+        port: 12345,
+        hostname: 'cheese',
+        facility: 'nonsense',
+        customFields: {
+          _every1: 'Hello every one',
+          _every2: 'Hello every two'
+        }
+      });
+      var myFields = {
+        GELF: true,
+        _every2: 'Overwritten!',
+        _myField: 'This is my field!'
+      };
+      setup.logger.debug(myFields, "Just testing.");
+      return setup;
+    },
+    'the dgram packet': {
+      topic: function(setup) {
+        return setup.dgram;
+      },
+      'should pick up the options': function(dgram) {
+        assert.equal(dgram.socket.host, 'somewhere');
+        assert.equal(dgram.socket.port, 12345);
+      }
+    },
+    'the uncompressed packet': {
+      topic: function(setup) {
+        var message = JSON.parse(setup.compress.uncompressed);
+        return message;
+      },
+      'should pick up the options': function(message) {
+        assert.equal(message.host, 'cheese');
+        assert.isUndefined(message.GELF); // make sure flag was removed
+        assert.equal(message._facility, 'nonsense');
+        assert.equal(message._every1, 'Hello every one'); // the default value
+        assert.equal(message._every2, 'Overwritten!'); // the overwritten value
+        assert.equal(message._myField, 'This is my field!'); // the value for this message only
+        assert.equal(message.short_message, 'Just testing.'); // skip the field object
       }
     }
   }
+
 }).export(module);

test/global-log-level-test.js

@@ -1,5 +1,6 @@
-var vows = require('vows'),
+"use strict";
-assert = require('assert');
+var vows = require('vows')
+, assert = require('assert');
 
 vows.describe('log4js global loglevel').addBatch({
   'global loglevel' : {
@@ -80,6 +81,41 @@ vows.describe('log4js global loglevel').addBatch({
       log2.removeLevel();
       assert.equal(log1.level.toString(), oldLevel);
       assert.equal(log2.level.toString(), oldLevel);
+    },
+
+    'set level on all categories': function(log4js) {
+      // Get 2 loggers
+      var log1 = log4js.getLogger('log1');
+      var log2 = log4js.getLogger('log2');
+
+      // First a test with 2 categories with different levels
+      var config = {
+        'levels': {
+          'log1': 'ERROR',
+          'log2': 'WARN'
+        }
+      };
+      log4js.configure(config);
+
+      // Check if the levels are set correctly
+      assert.equal('ERROR', log1.level.toString());
+      assert.equal('WARN', log2.level.toString());
+
+      log1.removeLevel();
+      log2.removeLevel();
+
+      // Almost identical test, but now we set
+      // level on all categories
+      var config2 = {
+        'levels': {
+          '[all]': 'DEBUG'
+        }
+      };
+      log4js.configure(config2);
+
+      // Check if the loggers got the DEBUG level
+      assert.equal('DEBUG', log1.level.toString());
+      assert.equal('DEBUG', log2.level.toString());
     }
   }
 }).export(module);

test/hookioAppender-test.js

@@ -1,101 +0,0 @@
-var vows = require('vows');
-var assert = require('assert');
-var sandbox = require('sandboxed-module');
-
-function fancyResultingHookioAppender(opts) {
-  var result = { ons: {}, emissions: {}, logged: [], configs: [] };
-
-  var fakeLog4Js = {
-    appenderMakers: {}
-  };
-  fakeLog4Js.loadAppender = function (appender) {
-    fakeLog4Js.appenderMakers[appender] = function (config) {
-      result.actualLoggerConfig = config;
-      return function log(logEvent) {
-        result.logged.push(logEvent);
-      }
-    };
-  };
-
-  var fakeHookIo = { Hook: function(config) { result.configs.push(config); } };
-  fakeHookIo.Hook.prototype.start = function () {
-    result.startCalled = true;
-  };
-  fakeHookIo.Hook.prototype.on = function (eventName, functionToExec) {
-    result.ons[eventName] = { functionToExec: functionToExec };
-    if (eventName === 'hook::ready') {
-      functionToExec();
-    }
-  };
-  fakeHookIo.Hook.prototype.emit = function (eventName, data) {
-    result.emissions[eventName] = result.emissions[eventName] || [];
-    result.emissions[eventName].push({data: data});
-    var on = '*::' + eventName;
-    if (eventName !== 'hook::ready' && result.ons[on]) {
-      result.ons[on].callingCount = result.ons[on].callingCount ? result.ons[on].callingCount += 1 : 1;
-      result.ons[on].functionToExec(data);
-    }
-  };
-
-  return { theResult: result,
-    theModule: sandbox.require('../lib/appenders/hookio', {
-      requires: {
-        '../log4js': fakeLog4Js,
-        'hook.io': fakeHookIo
-      }
-    })
-  };
-}
-
-
-vows.describe('log4js hookioAppender').addBatch({
-  'master': {
-    topic: function() {
-      var fancy = fancyResultingHookioAppender();
-      var logger = fancy.theModule.configure({ name: 'ohno', mode: 'master', 'hook-port': 5001, appender: { type: 'file' } });
-      logger({ level: { levelStr: 'INFO' }, data: "ALRIGHTY THEN", startTime: '2011-10-27T03:53:16.031Z' });
-      logger({ level: { levelStr: 'DEBUG' }, data: "OH WOW", startTime: '2011-10-27T04:53:16.031Z'});
-      return fancy.theResult;
-    },
-
-    'should write to the actual appender': function (result) {
-      assert.isTrue(result.startCalled);
-      assert.equal(result.configs.length, 1);
-      assert.equal(result.configs[0]['hook-port'], 5001);
-      assert.equal(result.logged.length, 2);
-      assert.equal(result.emissions['ohno::log'].length, 2);
-      assert.equal(result.ons['*::ohno::log'].callingCount, 2);
-    },
-
-    'data written should be formatted correctly': function (result) {
-      assert.equal(result.logged[0].level.toString(), 'INFO');
-      assert.equal(result.logged[0].data, 'ALRIGHTY THEN');
-      assert.isTrue(typeof(result.logged[0].startTime) === 'object');
-      assert.equal(result.logged[1].level.toString(), 'DEBUG');
-      assert.equal(result.logged[1].data, 'OH WOW');
-      assert.isTrue(typeof(result.logged[1].startTime) === 'object');
-    },
-
-    'the actual logger should get the right config': function (result) {
-      assert.equal(result.actualLoggerConfig.type, 'file');
-    }
-  },
-  'worker': {
-    'should emit logging events to the master': {
-      topic: function() {
-        var fancy = fancyResultingHookioAppender();
-        var logger = fancy.theModule.configure({ name: 'ohno', mode: 'worker', appender: { type: 'file' } });
-        logger({ level: { levelStr: 'INFO' }, data: "ALRIGHTY THEN", startTime: '2011-10-27T03:53:16.031Z' });
-        logger({ level: { levelStr: 'DEBUG' }, data: "OH WOW", startTime: '2011-10-27T04:53:16.031Z'});
-        return fancy.theResult;
-      },
-
-      'should not write to the actual appender': function (result) {
-        assert.isTrue(result.startCalled);
-        assert.equal(result.logged.length, 0);
-        assert.equal(result.emissions['ohno::log'].length, 2);
-        assert.isUndefined(result.ons['*::ohno::log']);
-      }
-    }
-  }
-}).exportTo(module);

test/layouts-test.js

@@ -1,5 +1,8 @@
-var vows = require('vows'),
+"use strict";
-assert = require('assert');
+var vows = require('vows')
+, assert = require('assert')
+, os =  require('os')
+, EOL = os.EOL || '\n';
 
 //used for patternLayout tests.
 function test(args, pattern, value) {
@@ -25,9 +28,8 @@ vows.describe('log4js layouts').addBatch({
           toString: function() { return "ERROR"; }
         }
       });
-            assert.equal(output, '\033[31m[2010-12-05 14:18:30.045] [ERROR] cheese - \033[39mnonsense');
+      assert.equal(output, '\x1B[31m[2010-12-05 14:18:30.045] [ERROR] cheese - \x1B[39mnonsense');
     },
-
     'should support the console.log format for the message': function(layout) {
       var output = layout({
         data: ["thing %d", 2],
@@ -37,7 +39,7 @@ vows.describe('log4js layouts').addBatch({
           toString: function() { return "ERROR"; }
         }
       });
-            assert.equal(output, '\033[31m[2010-12-05 14:18:30.045] [ERROR] cheese - \033[39mthing 2');
+      assert.equal(output, '\x1B[31m[2010-12-05 14:18:30.045] [ERROR] cheese - \x1B[39mthing 2');
     }
   },
 
@@ -58,51 +60,50 @@ vows.describe('log4js layouts').addBatch({
     },
     'should support the console.log format for the message' : function(layout) {
       assert.equal(layout({
-                  data: ["thing %d", 1, "cheese"]
+        data: ["thing %d", 1, "cheese"],
-                , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+        startTime: new Date(2010, 11, 5, 14, 18, 30, 45),
-                , categoryName: "cheese"
+        categoryName: "cheese",
-                , level : {
+        level : {
-                    colour: "green"
+          colour: "green",
-                  , toString: function() { return "ERROR"; }
+          toString: function() { return "ERROR"; }
         }
-              }), "thing 1 'cheese'");
+      }), "thing 1 cheese");
     },
     'should output the first item even if it is not a string': function(layout) {
       assert.equal(layout({
-                data: [ { thing: 1} ]
+        data: [ { thing: 1} ],
-              , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+        startTime: new Date(2010, 11, 5, 14, 18, 30, 45),
-              , categoryName: "cheese"
+        categoryName: "cheese",
-              , level: {
+        level: {
-                  colour: "green"
+          colour: "green",
-                , toString: function() { return "ERROR"; }
+          toString: function() { return "ERROR"; }
         }
       }), "{ thing: 1 }");
     },
     'should print the stacks of a passed error objects': function(layout) {
       assert.isArray(layout({
-                data: [ new Error() ]
+        data: [ new Error() ],
-              , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+        startTime: new Date(2010, 11, 5, 14, 18, 30, 45),
-              , categoryName: "cheese"
+        categoryName: "cheese",
-              , level: {
+        level: {
-                  colour: "green"
+          colour: "green",
-                , toString: function() { return "ERROR"; }
+          toString: function() { return "ERROR"; }
         }
       }).match(/Error\s+at Object\..*\s+\((.*)test[\\\/]layouts-test\.js\:\d+\:\d+\)\s+at runTest/)
                      , 'regexp did not return a match');
     },
-        'with passed augmented errors':
+    'with passed augmented errors': {
-        { topic:
+      topic: function(layout){
-          function(layout){
         var e = new Error("My Unique Error Message");
-              e.augmented = "My Unique attribute value"
+        e.augmented = "My Unique attribute value";
-              e.augObj = { at1: "at2" }
+        e.augObj = { at1: "at2" };
         return layout({
-                  data: [ e ]
+          data: [ e ],
-                , startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
+          startTime: new Date(2010, 11, 5, 14, 18, 30, 45),
-                , categoryName: "cheese"
+          categoryName: "cheese",
-                , level: {
+          level: {
-                    colour: "green"
+            colour: "green",
-                  , toString: function() { return "ERROR"; }
+            toString: function() { return "ERROR"; }
           }
         });
       },
@@ -150,7 +151,10 @@ vows.describe('log4js layouts').addBatch({
       lines = output.split(/\n/);
 
       assert.equal(lines.length - 1, stack.length);
-            assert.equal(lines[0], "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test [Error: Some made-up error]");
+      assert.equal(
+        lines[0],
+        "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test [Error: Some made-up error]"
+      );
 
       for (var i = 1; i < stack.length; i++) {
         assert.equal(lines[i+2], stack[i+1]);
@@ -163,7 +167,11 @@ vows.describe('log4js layouts').addBatch({
         message: 'Gorgonzola smells.'
       }];
       output = layout(event);
-            assert.equal(output, "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test { name: 'Cheese', message: 'Gorgonzola smells.' }");
+      assert.equal(
+        output,
+        "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test " +
+          "{ name: 'Cheese', message: 'Gorgonzola smells.' }"
+      );
     }
   },
 
@@ -171,7 +179,7 @@ vows.describe('log4js layouts').addBatch({
     topic: function() {
       var event = {
         data: ['this is a test'],
-                startTime: new Date(2010, 11, 5, 14, 18, 30, 45),
+        startTime: new Date('2010-12-05T14:18:30.045Z'), //new Date(2010, 11, 5, 14, 18, 30, 45),
         categoryName: "multiple.levels.of.tests",
         level: {
           toString: function() { return "DEBUG"; }
@@ -179,13 +187,17 @@ vows.describe('log4js layouts').addBatch({
       }, layout = require('../lib/layouts').patternLayout
       , tokens = {
         testString: 'testStringToken',
-                testFunction: function() { return 'testFunctionToken'; }
+        testFunction: function() { return 'testFunctionToken'; },
+        fnThatUsesLogEvent: function(logEvent) { return logEvent.level.toString(); }
       };
+
+      //override getTimezoneOffset
+      event.startTime.getTimezoneOffset = function() { return 0; };
       return [layout, event, tokens];
     },
 
     'should default to "time logLevel loggerName - message"': function(args) {
-            test(args, null, "14:18:30 DEBUG multiple.levels.of.tests - this is a test\n");
+      test(args, null, "14:18:30 DEBUG multiple.levels.of.tests - this is a test" + EOL);
     },
     '%r should output time only': function(args) {
       test(args, '%r', '14:18:30');
@@ -200,7 +212,13 @@ vows.describe('log4js layouts').addBatch({
       test(args, '%m', 'this is a test');
     },
     '%n should output a new line': function(args) {
-            test(args, '%n', '\n');
+      test(args, '%n', EOL);
+    },
+    '%h should output hostname' : function(args) {
+      test(args, '%h', os.hostname().toString());
+    },
+    '%z should output pid' : function(args) {
+      test(args, '%z', process.pid);
     },
     '%c should handle category names like java-style package names': function(args) {
       test(args, '%c{1}', 'tests');
@@ -214,9 +232,11 @@ vows.describe('log4js layouts').addBatch({
       test(args, '%d', '2010-12-05 14:18:30.045');
     },
     '%d should allow for format specification': function(args) {
+      test(args, '%d{ISO8601_WITH_TZ_OFFSET}', '2010-12-05T14:18:30-0000');
       test(args, '%d{ISO8601}', '2010-12-05 14:18:30.045');
       test(args, '%d{ABSOLUTE}', '14:18:30.045');
       test(args, '%d{DATE}', '05 12 2010 14:18:30.045');
+      test(args, '%d{yy MM dd hh mm ss}', '10 12 05 14 18 30');
       test(args, '%d{yyyy MM dd}', '2010 12 05');
       test(args, '%d{yyyy MM dd hh mm ss SSS}', '2010 12 05 14 18 30 045');
     },
@@ -226,10 +246,13 @@ vows.describe('log4js layouts').addBatch({
     'should output anything not preceded by % as literal': function(args) {
       test(args, 'blah blah blah', 'blah blah blah');
     },
+    'should output the original string if no replacer matches the token': function(args) {
+      test(args, '%a{3}', 'a{3}');
+    },
     'should handle complicated patterns': function(args) {
       test(args,
            '%m%n %c{2} at %d{ABSOLUTE} cheese %p%n',
-                 'this is a test\n of.tests at 14:18:30.045 cheese DEBUG\n'
+           'this is a test'+ EOL +' of.tests at 14:18:30.045 cheese DEBUG' + EOL
           );
     },
     'should truncate fields if specified': function(args) {
@@ -250,7 +273,7 @@ vows.describe('log4js layouts').addBatch({
       test(args, '%-10p', 'DEBUG     ');
     },
     '%[%r%] should output colored time': function(args) {
-            test(args, '%[%r%]', '\033[36m14:18:30\033[39m');
+      test(args, '%[%r%]', '\x1B[36m14:18:30\x1B[39m');
     },
     '%x{testString} should output the string stored in tokens': function(args) {
       test(args, '%x{testString}', 'testStringToken');
@@ -259,10 +282,23 @@ vows.describe('log4js layouts').addBatch({
       test(args, '%x{testFunction}', 'testFunctionToken');
     },
     '%x{doesNotExist} should output the string stored in tokens': function(args) {
-            test(args, '%x{doesNotExist}', '%x{doesNotExist}');
+      test(args, '%x{doesNotExist}', 'null');
+    },
+    '%x{fnThatUsesLogEvent} should be able to use the logEvent': function(args) {
+      test(args, '%x{fnThatUsesLogEvent}', 'DEBUG');
     },
     '%x should output the string stored in tokens': function(args) {
-            test(args, '%x', '%x');
+      test(args, '%x', 'null');
+    }
   },
+  'layout makers': {
+    topic: require('../lib/layouts'),
+    'should have a maker for each layout': function(layouts) {
+      assert.ok(layouts.layout("messagePassThrough"));
+      assert.ok(layouts.layout("basic"));
+      assert.ok(layouts.layout("colored"));
+      assert.ok(layouts.layout("coloured"));
+      assert.ok(layouts.layout("pattern"));
+    }
   }
 }).export(module);

test/levels-test.js

@@ -1,3 +1,4 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
 , levels = require('../lib/levels');
@@ -42,122 +43,367 @@ vows.describe('levels').addBatch({
       assert.isNotNull(levels.WARN);
       assert.isNotNull(levels.ERROR);
       assert.isNotNull(levels.FATAL);
+      assert.isNotNull(levels.MARK);
       assert.isNotNull(levels.OFF);
     },
     'ALL': {
       topic: levels.ALL,
       'should be less than the other levels': function(all) {
-                assertThat(all).isLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(all).isLessThanOrEqualTo(
+          [ 
+            levels.ALL, 
+            levels.TRACE, 
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL,
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       },
       'should be greater than no levels': function(all) {
-                assertThat(all).isNotGreaterThanOrEqualTo([levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(all).isNotGreaterThanOrEqualTo(
+          [
+            levels.TRACE, 
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       },
       'should only be equal to ALL': function(all) {
         assertThat(all).isEqualTo([levels.toLevel("ALL")]);
-                assertThat(all).isNotEqualTo([levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(all).isNotEqualTo(
+          [
+            levels.TRACE, 
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       }
     },
     'TRACE': {
       topic: levels.TRACE,
       'should be less than DEBUG': function(trace) {
-                assertThat(trace).isLessThanOrEqualTo([levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isLessThanOrEqualTo(
+          [
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
         assertThat(trace).isNotLessThanOrEqualTo([levels.ALL]);
       },
       'should be greater than ALL': function(trace) {
         assertThat(trace).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE]);
-                assertThat(trace).isNotGreaterThanOrEqualTo([levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotGreaterThanOrEqualTo(
+          [
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       },
       'should only be equal to TRACE': function(trace) {
         assertThat(trace).isEqualTo([levels.toLevel("TRACE")]);
-                assertThat(trace).isNotEqualTo([levels.ALL, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotEqualTo(
+          [
+            levels.ALL, 
+            levels.DEBUG, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       }
     },
     'DEBUG': {
       topic: levels.DEBUG,
       'should be less than INFO': function(debug) {
-                assertThat(debug).isLessThanOrEqualTo([levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(debug).isLessThanOrEqualTo(
+          [
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
         assertThat(debug).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE]);
       },
       'should be greater than TRACE': function(debug) {
         assertThat(debug).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE]);
-                assertThat(debug).isNotGreaterThanOrEqualTo([levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(debug).isNotGreaterThanOrEqualTo(
+          [
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       },
       'should only be equal to DEBUG': function(trace) {
         assertThat(trace).isEqualTo([levels.toLevel("DEBUG")]);
-                assertThat(trace).isNotEqualTo([levels.ALL, levels.TRACE, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotEqualTo(
+          [
+            levels.ALL, 
+            levels.TRACE, 
+            levels.INFO, 
+            levels.WARN, 
+            levels.ERROR, 
+            levels.FATAL, 
+            levels.MARK,
+            levels.OFF
+          ]
+        );
       }
     },
     'INFO': {
       topic: levels.INFO,
       'should be less than WARN': function(info) {
-                assertThat(info).isLessThanOrEqualTo([levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(info).isLessThanOrEqualTo([
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL, 
+          levels.MARK,
+          levels.OFF
+        ]);
         assertThat(info).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG]);
       },
       'should be greater than DEBUG': function(info) {
         assertThat(info).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG]);
-                assertThat(info).isNotGreaterThanOrEqualTo([levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(info).isNotGreaterThanOrEqualTo([
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL, 
+          levels.MARK,
+          levels.OFF
+        ]);
       },
       'should only be equal to INFO': function(trace) {
         assertThat(trace).isEqualTo([levels.toLevel("INFO")]);
-                assertThat(trace).isNotEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.WARN, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL, 
+          levels.MARK,
+          levels.OFF
+        ]);
       }
     },
     'WARN': {
       topic: levels.WARN,
       'should be less than ERROR': function(warn) {
-                assertThat(warn).isLessThanOrEqualTo([levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(warn).isLessThanOrEqualTo([levels.ERROR, levels.FATAL, levels.MARK, levels.OFF]);
-                assertThat(warn).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO]);
+        assertThat(warn).isNotLessThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO
+        ]);
       },
       'should be greater than INFO': function(warn) {
-                assertThat(warn).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO]);
+        assertThat(warn).isGreaterThanOrEqualTo([
-                assertThat(warn).isNotGreaterThanOrEqualTo([levels.ERROR, levels.FATAL, levels.OFF]);
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO
+        ]);
+        assertThat(warn).isNotGreaterThanOrEqualTo([levels.ERROR, levels.FATAL, levels.MARK, levels.OFF]);
       },
       'should only be equal to WARN': function(trace) {
         assertThat(trace).isEqualTo([levels.toLevel("WARN")]);
-                assertThat(trace).isNotEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.ERROR, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.ERROR, 
+          levels.FATAL, 
+          levels.OFF
+        ]);
       }
     },
     'ERROR': {
       topic: levels.ERROR,
       'should be less than FATAL': function(error) {
-                assertThat(error).isLessThanOrEqualTo([levels.FATAL, levels.OFF]);
+        assertThat(error).isLessThanOrEqualTo([levels.FATAL, levels.MARK, levels.OFF]);
-                assertThat(error).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN]);
+        assertThat(error).isNotLessThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN
+        ]);
       },
       'should be greater than WARN': function(error) {
-                assertThat(error).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN]);
+        assertThat(error).isGreaterThanOrEqualTo([
-                assertThat(error).isNotGreaterThanOrEqualTo([levels.FATAL, levels.OFF]);
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN
+        ]);
+        assertThat(error).isNotGreaterThanOrEqualTo([levels.FATAL, levels.MARK, levels.OFF]);
       },
       'should only be equal to ERROR': function(trace) {
         assertThat(trace).isEqualTo([levels.toLevel("ERROR")]);
-                assertThat(trace).isNotEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.FATAL, levels.OFF]);
+        assertThat(trace).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.FATAL, 
+          levels.MARK,
+          levels.OFF
+        ]);
       }
     },
     'FATAL': {
       topic: levels.FATAL,
       'should be less than OFF': function(fatal) {
-                assertThat(fatal).isLessThanOrEqualTo([levels.OFF]);
+        assertThat(fatal).isLessThanOrEqualTo([levels.MARK, levels.OFF]);
-                assertThat(fatal).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR]);
+        assertThat(fatal).isNotLessThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR
+        ]);
       },
       'should be greater than ERROR': function(fatal) {
-                assertThat(fatal).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR]);
+        assertThat(fatal).isGreaterThanOrEqualTo([
-                assertThat(fatal).isNotGreaterThanOrEqualTo([levels.OFF]);
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR
+       ]);
+        assertThat(fatal).isNotGreaterThanOrEqualTo([levels.MARK, levels.OFF]);
       },
       'should only be equal to FATAL': function(fatal) {
         assertThat(fatal).isEqualTo([levels.toLevel("FATAL")]);
-                assertThat(fatal).isNotEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.OFF]);
+        assertThat(fatal).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR,
+          levels.MARK, 
+          levels.OFF
+        ]);
+      }
+    },
+    'MARK': {
+      topic: levels.MARK,
+      'should be less than OFF': function(mark) {
+        assertThat(mark).isLessThanOrEqualTo([levels.OFF]);
+        assertThat(mark).isNotLessThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.FATAL, 
+          levels.ERROR
+        ]);
+      },
+      'should be greater than FATAL': function(mark) {
+        assertThat(mark).isGreaterThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR,
+          levels.FATAL
+       ]);
+        assertThat(mark).isNotGreaterThanOrEqualTo([levels.OFF]);
+      },
+      'should only be equal to MARK': function(mark) {
+        assertThat(mark).isEqualTo([levels.toLevel("MARK")]);
+        assertThat(mark).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR,
+          levels.FATAL, 
+          levels.OFF
+        ]);
       }
     },
     'OFF': {
       topic: levels.OFF,
       'should not be less than anything': function(off) {
-                assertThat(off).isNotLessThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL]);
+        assertThat(off).isNotLessThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL,
+          levels.MARK
+        ]);
       },
       'should be greater than everything': function(off) {
-                assertThat(off).isGreaterThanOrEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL]);
+        assertThat(off).isGreaterThanOrEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL,
+          levels.MARK
+        ]);
       },
       'should only be equal to OFF': function(off) {
         assertThat(off).isEqualTo([levels.toLevel("OFF")]);
-                assertThat(off).isNotEqualTo([levels.ALL, levels.TRACE, levels.DEBUG, levels.INFO, levels.WARN, levels.ERROR, levels.FATAL]);
+        assertThat(off).isNotEqualTo([
+          levels.ALL, 
+          levels.TRACE, 
+          levels.DEBUG, 
+          levels.INFO, 
+          levels.WARN, 
+          levels.ERROR, 
+          levels.FATAL,
+          levels.MARK
+        ]);
       }
     }
   },
@@ -165,14 +411,20 @@ vows.describe('levels').addBatch({
     topic: levels.INFO,
     'should handle string arguments': function(info) {
       assertThat(info).isGreaterThanOrEqualTo(["all", "trace", "debug"]);
-            assertThat(info).isNotGreaterThanOrEqualTo(['warn', 'ERROR', 'Fatal', 'off']);
+      assertThat(info).isNotGreaterThanOrEqualTo(['warn', 'ERROR', 'Fatal', 'MARK', 'off']);
     }
   },
   'isLessThanOrEqualTo': {
     topic: levels.INFO,
     'should handle string arguments': function(info) {
       assertThat(info).isNotLessThanOrEqualTo(["all", "trace", "debug"]);
-            assertThat(info).isLessThanOrEqualTo(['warn', 'ERROR', 'Fatal', 'off']);
+      assertThat(info).isLessThanOrEqualTo(['warn', 'ERROR', 'Fatal', 'MARK', 'off']);
+    }
+  },
+  'isEqualTo': {
+    topic: levels.INFO,
+    'should handle string arguments': function(info) {
+      assertThat(info).isEqualTo(["info", "INFO", "iNfO"]);
     }
   },
   'toLevel': {

test/log-abspath-test.js

@@ -1,5 +1,7 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
+, path = require('path')
 , sandbox = require('sandboxed-module');
 
 vows.describe('log4js-abspath').addBatch({
@@ -10,8 +12,7 @@ vows.describe('log4js-abspath').addBatch({
         '../lib/log4js',
         { requires:
           { './appenders/fake':
-                        {
+            { name: "fake",
-                            name: "fake",
               appender: function() {},
               configure: function(configuration, options) {
                 appenderOptions = options;
@@ -47,22 +48,30 @@ vows.describe('log4js-abspath').addBatch({
         '../lib/appenders/file',
         { requires:
           { '../streams':
-                        {
+            { RollingFileStream: 
-                            RollingFileStream: function(file) {
+              function(file) {
                 fileOpened = file;
-                            },
+                return {
-                            BufferedWriteStream: function(other) {
+                  on: function() {},
-                                return { on: function() { }, end: function() {} }
+                  end: function() {}
+                };
               }
             }
           }
         }
       );
-            fileAppender.configure({ filename: "whatever.log", maxLogSize: 10 }, { cwd: '/absolute/path/to' });
+      fileAppender.configure(
+        { 
+          filename: "whatever.log", 
+          maxLogSize: 10 
+        }, 
+        { cwd: '/absolute/path/to' }
+      );
       return fileOpened;
     },
     'should prepend options.cwd to config.filename': function(fileOpened) {
-            assert.equal(fileOpened, "/absolute/path/to/whatever.log");
+      var expected = path.sep + path.join("absolute", "path", "to", "whatever.log");
+      assert.equal(fileOpened, expected);
     }
   },
 }).export(module);

test/logLevelFilter-test.js

@@ -1,6 +1,9 @@
+"use strict";
 var vows = require('vows')
 , fs = require('fs')
-, assert = require('assert');
+, assert = require('assert')
+, os = require('os')
+, EOL = require('os').EOL || '\n';
 
 function remove(filename) {
   try {
@@ -15,7 +18,16 @@ vows.describe('log4js logLevelFilter').addBatch({
     topic: function() {
       var log4js = require('../lib/log4js'), logEvents = [], logger;
       log4js.clearAppenders();
-            log4js.addAppender(require('../lib/appenders/logLevelFilter').appender('ERROR', function(evt) { logEvents.push(evt); }), "logLevelTest");
+      log4js.addAppender(
+        require('../lib/appenders/logLevelFilter')
+          .appender(
+            'ERROR',
+            undefined,
+            function(evt) { logEvents.push(evt); }
+          ),
+        "logLevelTest"
+      );
+
       logger = log4js.getLogger("logLevelTest");
       logger.debug('this should not trigger an event');
       logger.warn('neither should this');
@@ -37,23 +49,26 @@ vows.describe('log4js logLevelFilter').addBatch({
 
       remove(__dirname + '/logLevelFilter.log');
       remove(__dirname + '/logLevelFilter-warnings.log');
+      remove(__dirname + '/logLevelFilter-debugs.log');
 
       log4js.configure('test/with-logLevelFilter.json');
       logger = log4js.getLogger("tests");
-	    logger.info('main');
+      logger.debug('debug');
-	    logger.error('both');
+      logger.info('info');
-	    logger.warn('both');
+      logger.error('error');
-	    logger.debug('main');
+      logger.warn('warn');
+      logger.debug('debug');
+      logger.trace('trace');
       //wait for the file system to catch up
-            setTimeout(this.callback, 100);
+      setTimeout(this.callback, 500);
     },
     'tmp-tests.log': {
       topic: function() {
         fs.readFile(__dirname + '/logLevelFilter.log', 'utf8', this.callback);
       },
-            'should contain all log messages': function(contents) {
+      'should contain all log messages': function (contents) {
-                var messages = contents.trim().split('\n');
+        var messages = contents.trim().split(EOL);
-	        assert.deepEqual(messages, ['main','both','both','main']);
+        assert.deepEqual(messages, ['debug','info','error','warn','debug','trace']);
       }
     },
     'tmp-tests-warnings.log': {
@@ -61,8 +76,17 @@ vows.describe('log4js logLevelFilter').addBatch({
         fs.readFile(__dirname + '/logLevelFilter-warnings.log','utf8',this.callback);
       },
       'should contain only error and warning log messages': function(contents) {
-                var messages = contents.trim().split('\n');
+        var messages = contents.trim().split(EOL);
-	        assert.deepEqual(messages, ['both','both']);
+        assert.deepEqual(messages, ['error','warn']);
+      }
+    },
+    'tmp-tests-debugs.log': {
+      topic: function() {
+        fs.readFile(__dirname + '/logLevelFilter-debugs.log','utf8',this.callback);
+      },
+      'should contain only trace and debug log messages': function(contents) {
+        var messages = contents.trim().split(EOL);
+        assert.deepEqual(messages, ['debug','debug','trace']);
       }
     }
   }

test/logger-test.js

@@ -0,0 +1,81 @@
+"use strict";
+var vows = require('vows')
+, assert = require('assert')
+, levels = require('../lib/levels')
+, loggerModule = require('../lib/logger')
+, Logger = loggerModule.Logger;
+
+vows.describe('../lib/logger').addBatch({
+  'constructor with no parameters': {
+    topic: new Logger(),
+    'should use default category': function(logger) {
+      assert.equal(logger.category, Logger.DEFAULT_CATEGORY);
+    },
+    'should use TRACE log level': function(logger) {
+      assert.equal(logger.level, levels.TRACE);
+    }
+  },
+
+  'constructor with category': {
+    topic: new Logger('cheese'),
+    'should use category': function(logger) {
+      assert.equal(logger.category, 'cheese');
+    },
+    'should use TRACE log level': function(logger) {
+      assert.equal(logger.level, levels.TRACE);
+    }
+  },
+
+  'constructor with category and level': {
+    topic: new Logger('cheese', 'debug'),
+    'should use category': function(logger) {
+      assert.equal(logger.category, 'cheese');
+    },
+    'should use level': function(logger) {
+      assert.equal(logger.level, levels.DEBUG);
+    }
+  },
+
+  'isLevelEnabled': {
+    topic: new Logger('cheese', 'info'),
+    'should provide a level enabled function for all levels': function(logger) {
+      assert.isFunction(logger.isTraceEnabled);
+      assert.isFunction(logger.isDebugEnabled);
+      assert.isFunction(logger.isInfoEnabled);
+      assert.isFunction(logger.isWarnEnabled);
+      assert.isFunction(logger.isErrorEnabled);
+      assert.isFunction(logger.isFatalEnabled);
+    },
+    'should return the right values': function(logger) {
+      assert.isFalse(logger.isTraceEnabled());
+      assert.isFalse(logger.isDebugEnabled());
+      assert.isTrue(logger.isInfoEnabled());
+      assert.isTrue(logger.isWarnEnabled());
+      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);

test/logging-test.js

@@ -1,3 +1,4 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
 , sandbox = require('sandboxed-module');
@@ -14,8 +15,8 @@ function setupConsoleTest() {
   });
 
   log4js = sandbox.require(
-        '../lib/log4js'
+    '../lib/log4js', 
-      , {
+    {
       globals: {
         console: fakeConsole
       }
@@ -31,6 +32,72 @@ function setupConsoleTest() {
 }
 
 vows.describe('log4js').addBatch({
+
+    'getBufferedLogger': {
+        topic: function () {
+            var log4js = require('../lib/log4js');
+            log4js.clearAppenders();
+            var logger = log4js.getBufferedLogger('tests');
+            return logger;
+        },
+
+        'should take a category and return a logger': function (logger) {
+            assert.equal(logger.target.category, 'tests');
+            assert.isFunction(logger.flush);
+            assert.isFunction(logger.trace);
+            assert.isFunction(logger.debug);
+            assert.isFunction(logger.info);
+            assert.isFunction(logger.warn);
+            assert.isFunction(logger.error);
+            assert.isFunction(logger.fatal);
+        },
+
+        'cache events': {
+            topic: function () {
+                var log4js = require('../lib/log4js');
+                log4js.clearAppenders();
+                var logger = log4js.getBufferedLogger('tests1');
+                var events = [];
+                logger.target.addListener("log", function (logEvent) { events.push(logEvent); });
+                logger.debug("Debug event");
+                logger.trace("Trace event 1");
+                logger.trace("Trace event 2");
+                logger.warn("Warning event");
+                logger.error("Aargh!", new Error("Pants are on fire!"));
+                logger.error("Simulated CouchDB problem", { err: 127, cause: "incendiary underwear" });
+                return events;
+            },
+
+            'should not emit log events if .flush() is not called.': function (events) {
+                assert.equal(events.length, 0);
+            }
+        },
+
+        'log events after flush() is called': {
+            topic: function () {
+                var log4js = require('../lib/log4js');
+                log4js.clearAppenders();
+                var logger = log4js.getBufferedLogger('tests2');
+                logger.target.setLevel("TRACE");
+                var events = [];
+                logger.target.addListener("log", function (logEvent) { events.push(logEvent); });
+                logger.debug("Debug event");
+                logger.trace("Trace event 1");
+                logger.trace("Trace event 2");
+                logger.warn("Warning event");
+                logger.error("Aargh!", new Error("Pants are on fire!"));
+                logger.error("Simulated CouchDB problem", { err: 127, cause: "incendiary underwear" });
+                logger.flush();
+                return events;
+            },
+
+            'should emit log events when .flush() is called.': function (events) {
+                assert.equal(events.length, 6);
+            }
+        }
+    }, 
+    
+   
   'getLogger': {
     topic: function() {
       var log4js = require('../lib/log4js');
@@ -74,13 +141,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': {
@@ -93,26 +212,25 @@ vows.describe('log4js').addBatch({
   
   'configuration when passed as object': {
     topic: function() {
-            var appenderConfig
+      var appenderConfig, 
-          , log4js = sandbox.require(
+      log4js = sandbox.require(
-              '../lib/log4js'
+        '../lib/log4js', 
-            , { requires:
-                { './appenders/file':
         { 
-                      name: "file"
+          requires: { 
-                    , appender: function() {}
+            './appenders/file': 
-                    , configure: function(configuration) {
+            {
+              name: "file",
+              appender: function() {},
+              configure: function(configuration) {
                 appenderConfig = configuration;
                 return function() {};
               }
             }
           }
         }
-          )
+      ), 
-          , config = {
+      config = { appenders: 
-                "appenders": [
+                 [ { "type" : "file",
-                    {
-                        "type" : "file",
                      "filename" : "cheesy-wotsits.log",
                      "maxLogSize" : 1024,
                      "backups" : 3
@@ -127,19 +245,56 @@ vows.describe('log4js').addBatch({
     }
   },
 
+  'configuration that causes an error': {
+    topic: function() {
+      var log4js = sandbox.require(
+        '../lib/log4js', 
+        { 
+          requires: { 
+            './appenders/file': 
+            {
+              name: "file",
+              appender: function() {},
+              configure: function(configuration) {
+                throw new Error("oh noes");
+              }
+            }
+          }
+        }
+      ), 
+      config = { appenders: 
+                 [ { "type" : "file",
+                     "filename" : "cheesy-wotsits.log",
+                     "maxLogSize" : 1024,
+                     "backups" : 3
+                   }
+                 ]
+               };
+      try {
+        log4js.configure(config);
+      } catch (e) {
+        return e;
+      }    
+    },
+    'should wrap error in a meaningful message': function(e) {
+      assert.ok(e.message.indexOf('log4js configuration problem for') > -1);
+    }
+  },
+
   'configuration when passed as filename': {
     topic: function() {
-            var appenderConfig
+      var appenderConfig, 
-          , configFilename
+      configFilename, 
-          , log4js = sandbox.require(
+      log4js = sandbox.require(
-                '../lib/log4js'
+        '../lib/log4js', 
-              , { requires:
+        { requires:
           { 'fs':
-                    {
+            { statSync: 
-                        statSync: function() {
+              function() {
                 return { mtime: Date.now() };
               },
-                        readFileSync: function(filename) {
+              readFileSync: 
+              function(filename) {
                 configFilename = filename;
                 return JSON.stringify({
                   appenders: [
@@ -149,15 +304,15 @@ vows.describe('log4js').addBatch({
                   ]
                 });
               },
-                        readdirSync: function() {
+              readdirSync: 
+              function() {
                 return ['file'];
               }
-                    }
+            }, 
-                , './appenders/file':
+            './appenders/file': 
-                    {
+            { name: "file", 
-                      name: "file"
+              appender: function() {}, 
-                    , appender: function() {}
+              configure: function(configuration) {
-                    , configure: function(configuration) {
                 appenderConfig = configuration;
                 return function() {};
               }
@@ -178,22 +333,22 @@ vows.describe('log4js').addBatch({
 
   'with no appenders defined' : {
     topic: function() {
-            var logger
+      var logger, 
-          , that = this
+      that = this, 
-          , fakeConsoleAppender = {
+      fakeConsoleAppender = {
-                name: "console"
+        name: "console", 
-              , appender: function() {
+        appender: function() {
           return function(evt) {
             that.callback(null, evt);
-                    }
+          };
-                }
+        }, 
-              , configure: function() {
+        configure: function() {
           return fakeConsoleAppender.appender();
         }
-          }
+      }, 
-          , log4js = sandbox.require(
+      log4js = sandbox.require(
-              '../lib/log4js'
+        '../lib/log4js', 
-            , {
+        {
           requires: {
             './appenders/console': fakeConsoleAppender
           }
@@ -215,15 +370,22 @@ vows.describe('log4js').addBatch({
     },
     'without a category': {
       'should register the function as a listener for all loggers': function (log4js) {
-                var appenderEvent, appender = function(evt) { appenderEvent = evt; }, logger = log4js.getLogger("tests");
+        var appenderEvent, 
+        appender = function(evt) { appenderEvent = evt; }, 
+        logger = log4js.getLogger("tests");
+
         log4js.addAppender(appender);
         logger.debug("This is a test");
         assert.equal(appenderEvent.data[0], "This is a test");
         assert.equal(appenderEvent.categoryName, "tests");
         assert.equal(appenderEvent.level.toString(), "DEBUG");
       },
-            'should also register as an appender for loggers if an appender for that category is defined': function (log4js) {
+      'if an appender for a category is defined': {
-                var otherEvent, appenderEvent, cheeseLogger;
+        'should register for that category': function (log4js) {
+          var otherEvent, 
+          appenderEvent, 
+          cheeseLogger;
+          
           log4js.addAppender(function (evt) { appenderEvent = evt; });
           log4js.addAppender(function (evt) { otherEvent = evt; }, 'cheese');
         
@@ -239,11 +401,15 @@ vows.describe('log4js').addBatch({
           assert.isUndefined(otherEvent);
           assert.equal(appenderEvent.data[0], "this should not be propagated to otherEvent");
         }
+      }
     },
     
     'with a category': {
       'should only register the function as a listener for that category': function(log4js) {
-                var appenderEvent, appender = function(evt) { appenderEvent = evt; }, logger = log4js.getLogger("tests");
+        var appenderEvent, 
+        appender = function(evt) { appenderEvent = evt; }, 
+        logger = log4js.getLogger("tests");
+
         log4js.addAppender(appender, 'tests');
         logger.debug('this is a category test');
         assert.equal(appenderEvent.data[0], 'this is a category test');
@@ -256,7 +422,10 @@ vows.describe('log4js').addBatch({
     
     'with multiple categories': {
       'should register the function as a listener for all the categories': function(log4js) {
-                var appenderEvent, appender = function(evt) { appenderEvent = evt; }, logger = log4js.getLogger('tests');
+        var appenderEvent, 
+        appender = function(evt) { appenderEvent = evt; }, 
+        logger = log4js.getLogger('tests');
+
         log4js.addAppender(appender, 'tests', 'biscuits');
         
         logger.debug('this is a test');
@@ -273,7 +442,9 @@ vows.describe('log4js').addBatch({
         assert.isUndefined(appenderEvent);
       },
       'should register the function when the list of categories is an array': function(log4js) {
-                var appenderEvent, appender = function(evt) { appenderEvent = evt; };
+        var appenderEvent, 
+        appender = function(evt) { appenderEvent = evt; };
+
         log4js.addAppender(appender, ['tests', 'pants']);
         
         log4js.getLogger('tests').debug('this is a test');
@@ -296,13 +467,13 @@ vows.describe('log4js').addBatch({
     topic: function() {
       var appenderEvents = [],
       fakeConsole = {
-                    'name': 'console'
+        'name': 'console', 
-                  , 'appender': function () {
+        'appender': function () {
           return function(evt) {
             appenderEvents.push(evt);
-                        }
+          };
-                    }
+        }, 
-                  , 'configure': function (config) {
+        'configure': function (config) {
           return fakeConsole.appender();
         }
       },
@@ -388,8 +559,11 @@ vows.describe('log4js').addBatch({
         assert.instanceOf(err, Error);
         assert.equal(err.message, "this should not be called.");
       }
+    }
   },
-        'configuration': {
+  'console configuration': {
+    topic: setupConsoleTest,
+    'when disabled': {
       topic: function(test) {
         test.log4js.replaceConsole();
         test.log4js.configure({ replaceConsole: false });
@@ -403,6 +577,25 @@ vows.describe('log4js').addBatch({
         assert.instanceOf(err, Error);
         assert.equal(err.message, 'this should not be called.');
       }
+    },
+    'when enabled': {
+      topic: function(test) {
+        test.log4js.restoreConsole();
+        test.log4js.configure({ replaceConsole: true });
+        //log4js.configure clears all appenders
+        test.log4js.addAppender(function(evt) {
+          test.logEvents.push(evt);
+        });
+
+        test.fakeConsole.debug("Some debug");
+        return test.logEvents;
+      },
+      
+      'should allow for turning on console replacement': function (logEvents) {
+        assert.equal(logEvents.length, 1);
+        assert.equal(logEvents[0].level.toString(), "DEBUG");
+        assert.equal(logEvents[0].data[0], "Some debug");
+      }
     }
   },
   'configuration persistence' : {
@@ -423,156 +616,15 @@ vows.describe('log4js').addBatch({
       assert.equal(logEvent.data[0], "This should go to the appender defined in firstLog4js");
     }
   },
-    'configuration reload with configuration changing' : {
+
+  'getDefaultLogger': {
     topic: function() {
-            var pathsChecked = [],
+      return require('../lib/log4js').getDefaultLogger();
-            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) {
+    'should return a logger': function(logger) {
-                    assert.equal(file, modulePath);
+      assert.ok(logger.info);
-                    assert.equal(encoding, 'utf8');
+      assert.ok(logger.debug);
-                    return JSON.stringify(fakeFS.config);
+      assert.ok(logger.error);
-                },
-                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');
     }
   }
 }).export(module);

test/logglyAppender-test.js

@@ -0,0 +1,82 @@
+"use strict";
+var vows = require('vows')
+, assert = require('assert')
+, log4js = require('../lib/log4js')
+, sandbox = require('sandboxed-module')
+;
+
+function setupLogging(category, options) {
+  var msgs = [];
+  
+  var fakeLoggly = {
+    createClient: function (options) {
+      return {
+        config: options,
+        log: function (msg, tags) {
+          msgs.push({
+            msg: msg,
+            tags: tags
+          });
+        }
+      };
+    }
+  };
+
+  var fakeLayouts = {
+    layout: function(type, config) {
+      this.type = type;
+      this.config = config;
+      return log4js.layouts.messagePassThroughLayout;
+    },
+    basicLayout: log4js.layouts.basicLayout,
+    messagePassThroughLayout: log4js.layouts.messagePassThroughLayout
+  };
+
+  var fakeConsole = {
+    errors: [],
+    error: function(msg, value) {
+      this.errors.push({ msg: msg, value: value });
+    }
+  };
+
+  var logglyModule = sandbox.require('../lib/appenders/loggly', {
+    requires: {
+      'loggly': fakeLoggly,
+      '../layouts': fakeLayouts
+    },
+    globals: {
+      console: fakeConsole
+    }
+  });
+
+  log4js.addAppender(logglyModule.configure(options), category);
+  
+  return {
+    logger: log4js.getLogger(category),
+    loggly: fakeLoggly,
+    layouts: fakeLayouts,
+    console: fakeConsole,
+    results: msgs
+  };
+}
+
+log4js.clearAppenders();
+vows.describe('log4js logglyAppender').addBatch({
+  'minimal config': {
+    topic: function() {
+      var setup = setupLogging('loggly', {
+        token: 'your-really-long-input-token',
+        subdomain: 'your-subdomain',
+        tags: ['loggly-tag1', 'loggly-tag2', 'loggly-tagn'] 
+      });
+      
+      setup.logger.log('trace', 'Log event #1');
+      return setup;
+    },
+    'there should be one message only': function (topic) {
+      //console.log('topic', topic);
+      assert.equal(topic.results.length, 1);
+    }
+  }
+
+}).export(module);

test/logstashUDP-test.js

@@ -0,0 +1,106 @@
+"use strict";
+var sys = require("sys");
+var vows = require('vows')
+, assert = require('assert')
+, log4js = require('../lib/log4js')
+, sandbox = require('sandboxed-module')
+;
+
+function setupLogging(category, options) {
+  var udpSent = {};
+  
+  var fakeDgram = {
+    createSocket: function (type) {
+      return {
+        send: function(buffer, offset, length, port, host, callback) {
+          udpSent.date = new Date();
+          udpSent.host = host;
+          udpSent.port = port;
+          udpSent.length = length;
+          udpSent.offset = 0;
+          udpSent.buffer = buffer;
+          callback(undefined, length);
+        }
+      };
+    }
+  };
+
+  var logstashModule = sandbox.require('../lib/appenders/logstashUDP', {
+    requires: {
+      'dgram': fakeDgram
+    }
+  });
+  log4js.clearAppenders();
+  log4js.addAppender(logstashModule.configure(options), category);
+  
+  return {
+    logger: log4js.getLogger(category),
+    results: udpSent
+  };
+}
+
+vows.describe('logstashUDP appender').addBatch({
+  'when logging with logstash via UDP': {
+    topic: function() {
+      var setup = setupLogging('logstashUDP', {
+        "host": "127.0.0.1",
+        "port": 10001,
+        "type": "logstashUDP",
+        "logType": "myAppType",
+        "category": "myLogger",
+        "fields": {
+          "field1": "value1",
+          "field2": "value2"
+        },
+        "layout": {
+          "type": "pattern",
+          "pattern": "%m"
+        }
+      });
+      setup.logger.log('trace', 'Log event #1');
+      return setup;
+    },
+    'an UDP packet should be sent': function (topic) {
+      assert.equal(topic.results.host, "127.0.0.1");
+      assert.equal(topic.results.port, 10001);
+      assert.equal(topic.results.offset, 0);
+      var json = JSON.parse(topic.results.buffer.toString());
+      assert.equal(json.type, 'myAppType');
+      var fields = {
+        field1: 'value1',
+        field2: 'value2',
+        level: 'TRACE'
+      };
+      assert.equal(JSON.stringify(json.fields), JSON.stringify(fields));
+      assert.equal(json.message, 'Log event #1');
+      // Assert timestamp, up to hours resolution.
+      var date = new Date(json['@timestamp']);
+      assert.equal(
+        date.toISOString().substring(0, 14),
+        topic.results.date.toISOString().substring(0, 14)
+      );
+    }
+  },
+
+  'when missing some options': {
+    topic: function() {
+      var setup = setupLogging('myLogger', {
+        "host": "127.0.0.1",
+        "port": 10001,
+        "type": "logstashUDP",
+        "category": "myLogger",
+        "layout": {
+          "type": "pattern",
+          "pattern": "%m"
+        }
+      });
+      setup.logger.log('trace', 'Log event #1');
+      return setup;
+    },
+    'it sets some defaults': function (topic) {
+      var json = JSON.parse(topic.results.buffer.toString());
+      assert.equal(json.type, 'myLogger');
+      assert.equal(JSON.stringify(json.fields), JSON.stringify({'level': 'TRACE'}));
+    }
+  }
+}).export(module);

test/multiprocess-test.js

@@ -1,6 +1,8 @@
-var vows = require('vows'),
+"use strict";
-    sandbox = require('sandboxed-module'),
+var vows = require('vows')
-    assert = require('assert');
+, sandbox = require('sandboxed-module')
+, assert = require('assert')
+;
 
 function makeFakeNet() {
   return {
@@ -67,12 +69,13 @@ vows.describe('Multiprocess Appender').addBatch({
       
       //don't need a proper log event for the worker tests
       appender('before connect');
-            fakeNet.cbs['connect']();
+      fakeNet.cbs.connect();
       appender('after connect');
-            fakeNet.cbs['close'](true);
+      fakeNet.cbs.close(true);
       appender('after error, before connect');
-            fakeNet.cbs['connect']();
+      fakeNet.cbs.connect();
       appender('after error, after connect');
+	  appender(new Error('Error test'));
       
       return fakeNet;
     },
@@ -96,6 +99,13 @@ vows.describe('Multiprocess Appender').addBatch({
       assert.equal(net.data[6], JSON.stringify('after error, after connect'));
       assert.equal(net.data[7], '__LOG4JS__');
       assert.equal(net.createConnectionCalled, 2);
+    },
+    'should serialize an Error correctly': function(net) {
+      assert(JSON.parse(net.data[8]).stack, "Expected:\n\n" + net.data[8] + "\n\n to have a 'stack' property");
+      var actual = JSON.parse(net.data[8]).stack;
+      var expectedRegex = /^Error: Error test/;
+      assert(actual.match(expectedRegex), "Expected: \n\n " + actual + "\n\n to match " + expectedRegex);
+
     }
   },
   'worker with timeout': {
@@ -112,13 +122,13 @@ vows.describe('Multiprocess Appender').addBatch({
       
       //don't need a proper log event for the worker tests
       appender('before connect');
-            fakeNet.cbs['connect']();
+      fakeNet.cbs.connect();
       appender('after connect');
-            fakeNet.cbs['timeout']();
+      fakeNet.cbs.timeout();
       appender('after timeout, before close');
-            fakeNet.cbs['close']();
+      fakeNet.cbs.close();
       appender('after close, before connect');
-            fakeNet.cbs['connect']();
+      fakeNet.cbs.connect();
       appender('after close, after connect');
       
       return fakeNet;
@@ -181,15 +191,27 @@ vows.describe('Multiprocess Appender').addBatch({
     },
     'when a client connects': {
       topic: function(net) {
-              var logString = JSON.stringify({ level: { level: 10000, levelStr: 'DEBUG' }, data: ['some debug']}) + '__LOG4JS__';
+        var logString = JSON.stringify(
+          { level: { level: 10000, levelStr: 'DEBUG' }
+            , data: ['some debug']}
+        ) + '__LOG4JS__';
         
-                net.cbs['connect']();
+        net.cbs.data(
-                net.cbs['data'](JSON.stringify({ level: { level: 40000, levelStr: 'ERROR' }, data: ['an error message'] }) + '__LOG4JS__');
+          JSON.stringify(
-                net.cbs['data'](logString.substring(0, 10));
+            { level: { level: 40000, levelStr: 'ERROR' }
-                net.cbs['data'](logString.substring(10));
+              , data: ['an error message'] }
-                net.cbs['data'](logString + logString + logString);
+          ) + '__LOG4JS__'
-                net.cbs['end'](JSON.stringify({ level:  { level: 50000, levelStr: 'FATAL' }, data: ["that's all folks"] }) + '__LOG4JS__');
+        );
-                net.cbs['data']('bad message__LOG4JS__');
+        net.cbs.data(logString.substring(0, 10));
+        net.cbs.data(logString.substring(10));
+        net.cbs.data(logString + logString + logString);
+        net.cbs.end(
+          JSON.stringify(
+            { level:  { level: 50000, levelStr: 'FATAL' }
+              , data: ["that's all folks"] }
+          ) + '__LOG4JS__'
+        );
+        net.cbs.data('bad message__LOG4JS__');
         return net;
       },
       'should parse log messages into log events and send to appender': function(net) {
@@ -239,4 +261,51 @@ vows.describe('Multiprocess Appender').addBatch({
       assert.equal(net.host, 'localhost');
     }
   }
+}).addBatch({
+  'configure': {
+    topic: function() {
+      var results = {}
+      , fakeNet = makeFakeNet()
+      , appender = sandbox.require(
+        '../lib/appenders/multiprocess',
+        {
+          requires: {
+            'net': fakeNet,
+            '../log4js': {
+              loadAppender: function(app) {
+                results.appenderLoaded = app;
+              },
+              appenderMakers: {
+                'madeupappender': function(config, options) {
+                  results.config = config;
+                  results.options = options;
+                }
+              }
+            }
+          }
+        }
+      ).configure(
+        {
+          mode: 'master',
+          appender: {
+            type: 'madeupappender',
+            cheese: 'gouda'
+          }
+        },
+        { crackers: 'jacobs' }
+      );
+
+      return results;
+        
+    },
+    'should load underlying appender for master': function(results) {
+      assert.equal(results.appenderLoaded, 'madeupappender');
+    },
+    'should pass config to underlying appender': function(results) {
+      assert.equal(results.config.cheese, 'gouda');
+    },
+    'should pass options to underlying appender': function(results) {
+      assert.equal(results.options.crackers, 'jacobs');
+    }
+  }
 }).exportTo(module);

test/nolog-test.js

@@ -1,5 +1,8 @@
+"use strict";
 var vows = require('vows')
 , assert = require('assert')
+, util   = require('util')
+, EE     = require('events').EventEmitter
 , levels = require('../lib/levels');
 
 function MockLogger() {
@@ -30,13 +33,14 @@ function MockRequest(remoteAddr, method, originalUrl) {
 }
 
 function MockResponse(statusCode) {
-
+  var r = this;
   this.statusCode = statusCode;
 
   this.end = function(chunk, encoding) {
-
+      r.emit('finish');
   };
 }
+util.inherits(MockResponse, EE);
 
 vows.describe('log4js connect logger').addBatch({
   'getConnectLoggerModule': {
@@ -60,11 +64,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d){
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-                  return d.ml.messages;
+          setTimeout(function() {
-              }
+              cb(null, d.ml.messages);
-            , 'check message': function(messages){
+          },10);
+        }, 
+        'check message': function(messages){
           assert.isArray(messages);
           assert.equal(messages.length, 1);
           assert.ok(levels.INFO.isEqualTo(messages[0].level));
@@ -80,11 +87,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-                  return d.ml.messages;
+          setTimeout(function() {
-	      }
+              cb(null, d.ml.messages);
-	    , 'check message': function(messages) {
+          },10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -102,11 +112,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d){
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-                  return d.ml.messages;
+          setTimeout(function() { 
-              }
+            cb(null, d.ml.messages) 
-            , 'check message': function(messages){
+          }, 10);
+        }, 
+        'check message': function(messages){
           assert.isArray(messages);
           assert.equal(messages.length, 1);
           assert.ok(levels.INFO.isEqualTo(messages[0].level));
@@ -122,11 +135,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -135,11 +151,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -156,11 +175,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d){
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-        }
+            cb(null, d.ml.messages) 
-        , 'check message': function(messages){
+          }, 10);
+        }, 
+        'check message': function(messages){
           assert.isArray(messages);
           assert.equal(messages.length, 1);
           assert.ok(levels.INFO.isEqualTo(messages[0].level));
@@ -176,11 +198,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -190,11 +215,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -211,11 +239,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d){
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-        }
+            cb(null, d.ml.messages) 
-        , 'check message': function(messages){
+          }, 10);
+        }, 
+        'check message': function(messages){
           assert.isArray(messages);
           assert.equal(messages.length, 1);
           assert.ok(levels.INFO.isEqualTo(messages[0].level));
@@ -231,11 +262,14 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
@@ -245,15 +279,18 @@ vows.describe('log4js connect logger').addBatch({
         topic: function(d) {
           var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
           var res = new MockResponse(200);
+          var cb  = this.callback;
           d.cl(req, res, function() { });
           res.end('chunk', 'encoding');
-          return d.ml.messages;
+          setTimeout(function() { 
-	      }
+            cb(null, d.ml.messages) 
-	      , 'check message': function(messages) {
+          }, 10);
+        }, 
+        'check message': function(messages) {
           assert.isArray(messages);
           assert.equal(messages.length, 0);
         }
-	    },
+      }
     }
   }
 

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);

test/setLevel-asymmetry-test.js

@@ -1,5 +1,9 @@
-// This test shows an asymmetry between setLevel and isLevelEnabled (in log4js-node@0.4.3 and earlier):
+"use strict";
-// 1) setLevel("foo") works, but setLevel(log4js.levels.foo) silently does not (sets the level to TRACE).
+/* jshint loopfunc: true */
+// This test shows an asymmetry between setLevel and isLevelEnabled 
+// (in log4js-node@0.4.3 and earlier):
+// 1) setLevel("foo") works, but setLevel(log4js.levels.foo) silently 
+//    does not (sets the level to TRACE).
 // 2) isLevelEnabled("foo") works as does isLevelEnabled(log4js.levels.foo).
 //
 
@@ -19,7 +23,8 @@ var strLevels= ['Trace','Debug','Info','Warn','Error','Fatal'];
 
 var log4jsLevels =[];
 // populate an array with the log4js.levels that match the strLevels.
-// Would be nice if we could iterate over log4js.levels instead, but log4js.levels.toLevel prevents that for now.
+// Would be nice if we could iterate over log4js.levels instead, 
+// but log4js.levels.toLevel prevents that for now.
 strLevels.forEach(function(l) {
   log4jsLevels.push(log4js.levels.toLevel(l));
 });
@@ -29,18 +34,19 @@ strLevels.forEach(function(l) {
 var levelTypes = {
   'string': strLevels,
   'log4js.levels.level': log4jsLevels,
-}
+};
 
 // Set up the basic vows batch for this test
 var batch = {
   setLevel: {
   }
-}
+};
 
 showProgress('Populating batch object...');
 
 // Populating the batch object programmatically,
-// as I don't have the patience to manually populate it with the (strLevels.length x levelTypes.length) ^ 2 = 144 possible test combinations
+// as I don't have the patience to manually populate it with 
+// the (strLevels.length x levelTypes.length) ^ 2 = 144 possible test combinations
 for (var type in levelTypes) {
   var context = 'is called with a '+type;
   var levelsToTest = levelTypes[type];
@@ -58,15 +64,30 @@ for (var type in levelTypes) {
         var t = type;
         var ct = comparisonType;
         var expectedResult = log4jsLevel.isLessThanOrEqualTo(comparisonLevel);
-        var vow = 'isLevelEnabled('+comparisonLevel+') called with a '+comparisonType+' should return '+expectedResult;
+        var vow = 'isLevelEnabled(' + comparisonLevel + 
+          ') called with a ' + comparisonType + 
+          ' should return ' + expectedResult;
         showProgress('Setting up the vows vow for '+vow);
 
         batch.setLevel[context][subContext][vow] = function(levelToSet) {
           logger.setLevel(levelToSet);
-          showProgress('*** Checking setLevel( '+level+' ) of type '+t+', and isLevelEnabled( '+comparisonLevel+' ) of type '+ct+'. Expecting: '+expectedResult);
+          showProgress(
-          assert.equal(logger.isLevelEnabled(comparisonLevel), expectedResult, 'Failed: calling setLevel( '+level+' ) with type '+type+', isLevelEnabled( '+comparisonLevel+' ) of type '+comparisonType+' did not return '+expectedResult);
+            '*** Checking setLevel( ' + level + 
+              ' ) of type ' + t + 
+              ', and isLevelEnabled( ' + comparisonLevel + 
+              ' ) of type ' + ct + '. Expecting: ' + expectedResult
+          );
+          assert.equal(
+            logger.isLevelEnabled(comparisonLevel), 
+            expectedResult, 
+            'Failed: calling setLevel( ' + level + 
+              ' ) with type ' + type + 
+              ', isLevelEnabled( ' + comparisonLevel + 
+              ' ) of type ' + comparisonType + 
+              ' did not return ' + expectedResult
+          );
         };
-      })
+      });
     }
   });
 

test/smtpAppender-test.js

@@ -1,7 +1,9 @@
-var vows = require('vows'),
+"use strict";
-    assert = require('assert'),
+var vows = require('vows')
-    log4js = require('../lib/log4js'),
+, assert = require('assert')
-    sandbox = require('sandboxed-module');
+, log4js = require('../lib/log4js')
+, sandbox = require('sandboxed-module')
+;
 
 function setupLogging(category, options) {
   var msgs = [];
@@ -13,14 +15,36 @@ function setupLogging(category, options) {
 				sendMail: function (msg, callback) {
           msgs.push(msg);
           callback(null, true);
+        },
+        close: function() {}
+			};
 		}
   };
+
+  var fakeLayouts = {
+    layout: function(type, config) {
+      this.type = type;
+      this.config = config;
+      return log4js.layouts.messagePassThroughLayout;
+    },
+    basicLayout: log4js.layouts.basicLayout,
+    messagePassThroughLayout: log4js.layouts.messagePassThroughLayout
+  };
+
+  var fakeConsole = {
+    errors: [],
+    error: function(msg, value) {
+      this.errors.push({ msg: msg, value: value });
     }
   };
 
   var smtpModule = sandbox.require('../lib/appenders/smtp', {
 		requires: {
-		    'nodemailer': fakeMailer
+      'nodemailer': fakeMailer,
+      '../layouts': fakeLayouts
+		},
+    globals: {
+      console: fakeConsole
     }
   });
 
@@ -29,6 +53,8 @@ function setupLogging(category, options) {
   return {
 		logger: log4js.getLogger(category),
 		mailer: fakeMailer,
+    layouts: fakeLayouts,
+    console: fakeConsole,
 		results: msgs
   };
 }
@@ -48,7 +74,6 @@ vows.describe('log4js smtpAppender').addBatch({
 		topic: function() {
       var setup = setupLogging('minimal config', {
         recipients: 'recipient@domain.com',
-			transport: "SMTP",
         SMTP: {
           port: 25,
           auth: {
@@ -72,7 +97,6 @@ vows.describe('log4js smtpAppender').addBatch({
         recipients: 'recipient@domain.com',
         sender: 'sender@domain.com',
         subject: 'This is subject',
-			transport: "SMTP",
         SMTP: {
           port: 25,
           auth: {
@@ -90,12 +114,24 @@ vows.describe('log4js smtpAppender').addBatch({
       checkMessages(result, 'sender@domain.com', 'This is subject');
     }
   },
+  'config with layout': {
+    topic: function() {
+      var setup = setupLogging('config with layout', {
+        layout: {
+          type: "tester"
+        }
+      });
+      return setup;
+    },
+    'should configure layout': function(result) {
+      assert.equal(result.layouts.type, 'tester');
+    }
+  },
   'separate email for each event': {
     topic: function() {
       var self = this;
       var setup = setupLogging('separate email for each event', {
         recipients: 'recipient@domain.com',
-				transport: "SMTP",
         SMTP: {
           port: 25,
           auth: {
@@ -111,10 +147,10 @@ vows.describe('log4js smtpAppender').addBatch({
       }, 500);
       setTimeout(function () {
         setup.logger.info('Log event #3');
-		    }, 1050);
+      }, 1100);
       setTimeout(function () {
         self.callback(null, setup);
-		    }, 2100);
+      }, 3000);
     },
     'there should be three messages': function (result) {
       assert.equal(result.results.length, 3);
@@ -129,7 +165,6 @@ vows.describe('log4js smtpAppender').addBatch({
       var setup = setupLogging('multiple events in one email', {
         recipients: 'recipient@domain.com',
         sendInterval: 1,
-				transport: "SMTP",
         SMTP: {
           port: 25,
           auth: {
@@ -142,13 +177,13 @@ vows.describe('log4js smtpAppender').addBatch({
       }, 0);
       setTimeout(function () {
         setup.logger.info('Log event #2');
-		    }, 500);
+      }, 100);
       setTimeout(function () {
         setup.logger.info('Log event #3');
-		    }, 1050);
+      }, 1500);
       setTimeout(function () {
         self.callback(null, setup);
-		    }, 2100);
+      }, 3000);
     },
     'there should be two messages': function (result) {
       assert.equal(result.results.length, 2);
@@ -157,12 +192,35 @@ vows.describe('log4js smtpAppender').addBatch({
       assert.equal(result.results[0].to, 'recipient@domain.com');
       assert.equal(result.results[0].subject, 'Log event #1');
       assert.equal(result.results[0].text.match(new RegExp('.+Log event #[1-2]$', 'gm')).length, 2);
-	
       assert.equal(result.results[1].to, 'recipient@domain.com');
       assert.equal(result.results[1].subject, 'Log event #3');
       assert.ok(new RegExp('.+Log event #3\n$').test(result.results[1].text));
     }
+  },
+  'error when sending email': {
+    topic: function() {
+      var setup = setupLogging('error when sending email', {
+        recipients: 'recipient@domain.com',
+        sendInterval: 0,
+        SMTP: { port: 25, auth: { user: 'user@domain.com' } }
+      });
+
+      setup.mailer.createTransport = function() {
+        return {
+          sendMail: function(msg, cb) {
+            cb({ message: "oh noes" });
+          },
+          close: function() { }
+        };
+      };
+
+      setup.logger.info("This will break");
+      return setup.console;
+    },
+    'should be logged to console': function(cons) {
+      assert.equal(cons.errors.length, 1);
+      assert.equal(cons.errors[0].msg, "log4js.smtpAppender - Error happened");
+      assert.equal(cons.errors[0].value.message, 'oh noes');
+    }
   }
-
 }).export(module);
-

test/streams/BaseRollingFileStream-test.js

@@ -0,0 +1,93 @@
+"use strict";
+var vows = require('vows')
+, assert = require('assert')
+, fs = require('fs')
+, sandbox = require('sandboxed-module');
+
+vows.describe('../../lib/streams/BaseRollingFileStream').addBatch({
+  'when node version < 0.10.0': {
+    topic: function() {
+      var streamLib = sandbox.load(
+        '../../lib/streams/BaseRollingFileStream',
+        {
+          globals: {
+            process: {
+              version: '0.8.11'
+            }
+          },
+          requires: {
+            'readable-stream': {
+              Writable: function() {}
+            }
+          }
+        }
+      );
+      return streamLib.required;
+    },
+    'it should use readable-stream to maintain compatibility': function(required) {
+      assert.ok(required['readable-stream']);
+      assert.ok(!required.stream);
+    }
+  },
+
+  'when node version > 0.10.0': {
+    topic: function() {
+      var streamLib = sandbox.load(
+        '../../lib/streams/BaseRollingFileStream',
+        {
+          globals: {
+            process: {
+              version: '0.10.1'
+            }
+          },
+          requires: {
+            'stream': {
+              Writable: function() {}
+            }
+          }
+        }
+      );
+      return streamLib.required;
+    },
+    'it should use the core stream module': function(required) {
+      assert.ok(required.stream);
+      assert.ok(!required['readable-stream']);
+    }
+  },
+
+  'when no filename is passed': {
+    topic: require('../../lib/streams/BaseRollingFileStream'),
+    'it should throw an error': function(BaseRollingFileStream) {
+      try {
+        new BaseRollingFileStream();
+        assert.fail('should not get here');
+      } catch (e) {
+        assert.ok(e);
+      }
+    }
+  },
+
+  'default behaviour': {
+    topic: function() {
+      var BaseRollingFileStream = require('../../lib/streams/BaseRollingFileStream')
+      , stream = new BaseRollingFileStream('basetest.log');
+      return stream;
+    },
+    teardown: function() {
+      try {
+        fs.unlink('basetest.log');
+      } catch (e) {
+        console.error("could not remove basetest.log", e);
+      }
+    },
+    'it should not want to roll': function(stream) {
+      assert.isFalse(stream.shouldRoll());
+    },
+    'it should not roll': function(stream) {
+      var cbCalled = false;
+      //just calls the callback straight away, no async calls
+      stream.roll('basetest.log', function() { cbCalled = true; });
+      assert.isTrue(cbCalled);
+    }
+  }
+}).exportTo(module);

test/streams/DateRollingFileStream-test.js

@@ -1,8 +1,18 @@
-var vows = require('vows'),
+"use strict";
-    assert = require('assert'),
+var vows = require('vows')
-    fs = require('fs'),
+, assert = require('assert')
-    DateRollingFileStream = require('../../lib/streams').DateRollingFileStream,
+, fs = require('fs')
-    testTime = new Date(2012, 8, 12, 10, 37, 11);
+, semver = require('semver')
+, streams
+, DateRollingFileStream
+, testTime = new Date(2012, 8, 12, 10, 37, 11);
+
+if (semver.satisfies(process.version, '>=0.10.0')) {
+  streams = require('stream');
+} else {
+  streams = require('readable-stream');
+}
+DateRollingFileStream = require('../../lib/streams').DateRollingFileStream;
 
 function cleanUp(filename) {
   return function() {
@@ -16,18 +26,22 @@ function now() {
 
 vows.describe('DateRollingFileStream').addBatch({
   'arguments': {
-        topic: new DateRollingFileStream(__dirname + '/test-date-rolling-file-stream-1', 'yyyy-mm-dd.hh'),
+    topic: new DateRollingFileStream(
+      __dirname + '/test-date-rolling-file-stream-1', 
+      'yyyy-mm-dd.hh'
+    ),
     teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-1'),
     
-        'should take a filename and a pattern and return a FileWriteStream': function(stream) {
+    'should take a filename and a pattern and return a WritableStream': function(stream) {
       assert.equal(stream.filename, __dirname + '/test-date-rolling-file-stream-1');
       assert.equal(stream.pattern, 'yyyy-mm-dd.hh');
-            assert.instanceOf(stream, fs.FileWriteStream);
+      assert.instanceOf(stream, streams.Writable);
     },
     'with default settings for the underlying stream': function(stream) {
-            assert.equal(stream.mode, 420);
+      assert.equal(stream.theStream.mode, 420);
-            assert.equal(stream.flags, 'a');
+      assert.equal(stream.theStream.flags, 'a');
-            assert.equal(stream.encoding, 'utf8');
+      //encoding is not available on the underlying stream
+      //assert.equal(stream.encoding, 'utf8');
     }
   },
   
@@ -41,20 +55,27 @@ vows.describe('DateRollingFileStream').addBatch({
   },
 
   'with stream arguments': {
-        topic: new DateRollingFileStream(__dirname + '/test-date-rolling-file-stream-3', 'yyyy-MM-dd', { mode: 0666 }),
+    topic: new DateRollingFileStream(
+      __dirname + '/test-date-rolling-file-stream-3', 
+      'yyyy-MM-dd', 
+      { mode: parseInt('0666', 8) }
+    ),
     teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-3'),
     
     'should pass them to the underlying stream': function(stream) {
-            assert.equal(stream.mode, 0666);
+      assert.equal(stream.theStream.mode, parseInt('0666', 8));
     }
   },
 
   'with stream arguments but no pattern': {
-        topic: new DateRollingFileStream(__dirname + '/test-date-rolling-file-stream-4', { mode: 0666 }),
+    topic: new DateRollingFileStream(
+      __dirname + '/test-date-rolling-file-stream-4', 
+      { mode: parseInt('0666', 8) }
+    ),
     teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-4'),
     
     'should pass them to the underlying stream': function(stream) {
-            assert.equal(stream.mode, 0666);
+      assert.equal(stream.theStream.mode, parseInt('0666', 8));
     },
     'should use default pattern': function(stream) {
       assert.equal(stream.pattern, '.yyyy-MM-dd');
@@ -64,10 +85,12 @@ vows.describe('DateRollingFileStream').addBatch({
   'with a pattern of .yyyy-MM-dd': {
     topic: function() {
       var that = this,
-                stream = new DateRollingFileStream(__dirname + '/test-date-rolling-file-stream-5', '.yyyy-MM-dd', null, now);
+      stream = new DateRollingFileStream(
-            stream.on("open", function() {
+        __dirname + '/test-date-rolling-file-stream-5', '.yyyy-MM-dd', 
-                stream.write("First message\n");
+        null, 
-                //wait for the file system to catch up with us
+        now
+      );
+      stream.write("First message\n", 'utf8', function() {
         that.callback(null, stream);
       });
     },
@@ -85,8 +108,7 @@ vows.describe('DateRollingFileStream').addBatch({
     'when the day changes': {
       topic: function(stream) {
         testTime = new Date(2012, 8, 13, 0, 10, 12);
-                stream.write("Second message\n");
+        stream.write("Second message\n", 'utf8', this.callback);
-                setTimeout(this.callback, 100);
       },
       teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-5.2012-09-12'),
 
@@ -96,7 +118,14 @@ vows.describe('DateRollingFileStream').addBatch({
           fs.readdir(__dirname, this.callback);
         },
         'should be two': function(files) {
-                    assert.equal(files.filter(function(file) { return file.indexOf('test-date-rolling-file-stream-5') > -1; }).length, 2);
+          assert.equal(
+            files.filter(
+              function(file) { 
+                return file.indexOf('test-date-rolling-file-stream-5') > -1; 
+              }
+            ).length, 
+            2
+          );
         }
       },
       
@@ -118,6 +147,81 @@ vows.describe('DateRollingFileStream').addBatch({
         }
       }
     }
+  },
+  
+  'with alwaysIncludePattern': {
+    topic: function() {
+      var that = this,
+      testTime = new Date(2012, 8, 12, 0, 10, 12),
+      stream = new DateRollingFileStream(
+        __dirname + '/test-date-rolling-file-stream-pattern', 
+        '.yyyy-MM-dd', 
+        {alwaysIncludePattern: true}, 
+        now
+      );
+      stream.write("First message\n", 'utf8', function() {
+        that.callback(null, stream);
+      });
+    },
+    teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-12'),
+    
+    'should create a file with the pattern set': {
+      topic: function(stream) {
+        fs.readFile(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-12', this.callback);
+      },
+      'file should contain first message': function(result) {
+        assert.equal(result.toString(), "First message\n");
+      }
+    },
+    
+    'when the day changes': {
+      topic: function(stream) {
+        testTime = new Date(2012, 8, 13, 0, 10, 12);
+        stream.write("Second message\n", 'utf8', this.callback);
+      },
+      teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-13'),
+      
+      
+      'the number of files': {
+        topic: function() {
+          fs.readdir(__dirname, this.callback);
+        },
+        'should be two': function(files) {
+          assert.equal(
+            files.filter(
+              function(file) { 
+                return file.indexOf('test-date-rolling-file-stream-pattern') > -1; 
+              }
+            ).length, 
+            2
+          );
+        }
+      },
+      
+      'the file with the later date': {
+        topic: function() {
+          fs.readFile(
+            __dirname + '/test-date-rolling-file-stream-pattern.2012-09-13', 
+            this.callback
+          );
+        },
+        'should contain the second message': function(contents) {
+          assert.equal(contents.toString(), "Second message\n");
+        }
+      },
+      
+      'the file with the date': {
+        topic: function() {
+          fs.readFile(
+            __dirname + '/test-date-rolling-file-stream-pattern.2012-09-12', 
+            this.callback
+          );
+        },
+        'should contain the first message': function(contents) {
+          assert.equal(contents.toString(), "First message\n");
+        }
+      }
+    }
   }
 
 }).exportTo(module);

test/streams/bufferedStream-test.js

@@ -1,130 +0,0 @@
-var vows = require('vows')
-, assert = require('assert')
-, events = require('events')
-, BufferedWriteStream = require('../../lib/streams').BufferedWriteStream;
-
-function FakeStream() {
-    this.writes = [];
-    this.canWrite = false;
-    this.callbacks = {};
-}
-
-FakeStream.prototype.on = function(event, callback) {
-    this.callbacks[event] = callback;
-}
-
-FakeStream.prototype.write = function(data, encoding) {
-    assert.equal("utf8", encoding);
-    this.writes.push(data);
-    return this.canWrite;
-}
-
-FakeStream.prototype.emit = function(event, payload) {
-    this.callbacks[event](payload);
-}
-
-FakeStream.prototype.block = function() {
-    this.canWrite = false;
-}
-
-FakeStream.prototype.unblock = function() {
-    this.canWrite = true;
-    this.emit("drain");
-}
-
-vows.describe('BufferedWriteStream').addBatch({
-    'stream': {
-        topic: new BufferedWriteStream(new FakeStream()),
-        'should take a stream as an argument and return a stream': function(stream) {
-            assert.instanceOf(stream, events.EventEmitter);
-        }
-    },
-    'before stream is open': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            stream.write("Some data", "utf8");
-            stream.write("Some more data", "utf8");
-            return fakeStream.writes;
-        },
-        'should buffer writes': function(writes) {
-            assert.equal(writes.length, 0);
-        }
-    },
-    'when stream is open': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            stream.write("Some data", "utf8");
-            fakeStream.canWrite = true;
-            fakeStream.emit("open");
-            stream.write("Some more data", "utf8");
-            return fakeStream.writes;
-        },
-        'should write data to stream from before stream was open': function (writes) {
-            assert.equal(writes[0], "Some data");
-        },
-        'should write data to stream from after stream was open': function (writes) {
-            assert.equal(writes[1], "Some more data");
-        }
-    },
-    'when stream is blocked': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            fakeStream.emit("open");
-            fakeStream.block();
-            stream.write("will not know it is blocked until first write", "utf8");
-            stream.write("so this one will be buffered, but not the previous one", "utf8");
-            return fakeStream.writes;
-        },
-        'should buffer writes': function (writes) {
-            assert.equal(writes.length, 1);
-            assert.equal(writes[0], "will not know it is blocked until first write");
-        }
-    },
-    'when stream is unblocked': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            fakeStream.emit("open");
-            fakeStream.block();
-            stream.write("will not know it is blocked until first write", "utf8");
-            stream.write("so this one will be buffered, but not the previous one", "utf8");
-            fakeStream.unblock();
-            return fakeStream.writes;
-        },
-        'should send buffered data': function (writes) {
-            assert.equal(writes.length, 2);
-            assert.equal(writes[1], "so this one will be buffered, but not the previous one");
-        }
-    },
-    'when stream is closed': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            fakeStream.emit("open");
-            fakeStream.block();
-            stream.write("first write to notice stream is blocked", "utf8");
-            stream.write("data while blocked", "utf8");
-            stream.end();
-            return fakeStream.writes;
-        },
-        'should send any buffered writes to the stream': function (writes) {
-            assert.equal(writes.length, 2);
-            assert.equal(writes[1], "data while blocked");
-        }
-    },
-    'when stream errors': {
-        topic: function() {
-            var fakeStream = new FakeStream(),
-            stream = new BufferedWriteStream(fakeStream);
-            stream.on("error", this.callback);
-            fakeStream.emit("error", "oh noes!");
-        },
-        'should emit error': function(err, value) {
-            assert.equal(err, "oh noes!");
-        }
-    }
-
-}).exportTo(module);

test/streams/rollingFileStream-test.js

@@ -1,8 +1,19 @@
+"use strict";
 var vows = require('vows')
+, async = require('async')
 , assert = require('assert')
 , events = require('events')
 , fs = require('fs')
-, RollingFileStream = require('../../lib/streams').RollingFileStream;
+, semver = require('semver')
+, streams
+, RollingFileStream;
+
+if (semver.satisfies(process.version, '>=0.10.0')) {
+  streams = require('stream');
+} else {
+  streams = require('readable-stream');
+}
+RollingFileStream = require('../../lib/streams').RollingFileStream;
 
 function remove(filename) {
   try {
@@ -12,31 +23,41 @@ function remove(filename) {
   }
 }
 
+function create(filename) {
+  fs.writeFileSync(filename, "test file");
+}
+
 vows.describe('RollingFileStream').addBatch({
   'arguments': {
     topic: function() {
       remove(__dirname + "/test-rolling-file-stream");
       return new RollingFileStream("test-rolling-file-stream", 1024, 5);
     },
-        'should take a filename, file size in bytes, number of backups as arguments and return a FileWriteStream': function(stream) {
+    'should take a filename, file size (bytes), no. backups,  return Writable': function(stream) {
-            assert.instanceOf(stream, fs.FileWriteStream);
+      assert.instanceOf(stream, streams.Writable);
       assert.equal(stream.filename, "test-rolling-file-stream");
       assert.equal(stream.size, 1024);
       assert.equal(stream.backups, 5);
     },
     'with default settings for the underlying stream': function(stream) {
-            assert.equal(stream.mode, 420);
+      assert.equal(stream.theStream.mode, 420);
-            assert.equal(stream.flags, 'a');
+      assert.equal(stream.theStream.flags, 'a');
-            assert.equal(stream.encoding, 'utf8');
+      //encoding isn't a property on the underlying stream
+      //assert.equal(stream.theStream.encoding, 'utf8');
     }
   },
   'with stream arguments': {
     topic: function() {
       remove(__dirname + '/test-rolling-file-stream');
-            return new RollingFileStream('test-rolling-file-stream', 1024, 5, { mode: 0666 });
+      return new RollingFileStream(
+        'test-rolling-file-stream', 
+        1024, 
+        5, 
+        { mode: parseInt('0666', 8) }
+      );
     },
     'should pass them to the underlying stream': function(stream) {
-            assert.equal(stream.mode, 0666);
+      assert.equal(stream.theStream.mode, parseInt('0666', 8));
     }
   },
   'without size': {
@@ -63,14 +84,15 @@ vows.describe('RollingFileStream').addBatch({
   'writing less than the file size': {
     topic: function() {
       remove(__dirname + "/test-rolling-file-stream-write-less");
-            var that = this, stream = new RollingFileStream(__dirname + "/test-rolling-file-stream-write-less", 100);
+      var that = this
-            stream.on("open", function() { that.callback(null, stream); });
+      , stream = new RollingFileStream(
-        },
+        __dirname + "/test-rolling-file-stream-write-less", 
-        '(when open)': {
+        100
-            topic: function(stream) {
+      );
-                stream.write("cheese", "utf8");
+      stream.write("cheese", "utf8", function() {
         stream.end();
-                fs.readFile(__dirname + "/test-rolling-file-stream-write-less", "utf8", this.callback);
+        fs.readFile(__dirname + "/test-rolling-file-stream-write-less", "utf8", that.callback);
+      });
     },
     'should write to the file': function(contents) {
       assert.equal(contents, "cheese");
@@ -80,8 +102,14 @@ vows.describe('RollingFileStream').addBatch({
         fs.readdir(__dirname, this.callback);
       },
       'should be one': function(files) {
-                    assert.equal(files.filter(function(file) { return file.indexOf('test-rolling-file-stream-write-less') > -1; }).length, 1);
+        assert.equal(
+          files.filter(
+            function(file) { 
+              return file.indexOf('test-rolling-file-stream-write-less') > -1; 
             }
+          ).length, 
+          1
+        );
       }
     }
   },
@@ -89,21 +117,32 @@ vows.describe('RollingFileStream').addBatch({
     topic: function() {
       remove(__dirname + "/test-rolling-file-stream-write-more");
       remove(__dirname + "/test-rolling-file-stream-write-more.1");
-            var that = this, stream = new RollingFileStream(__dirname + "/test-rolling-file-stream-write-more", 45);
+      var that = this
-            stream.on("open", function() {
+      , stream = new RollingFileStream(
-                for (var i=0; i < 7; i++) {
+        __dirname + "/test-rolling-file-stream-write-more", 
-                    stream.write(i +".cheese\n", "utf8");
+        45
+      );
+      async.each(
+        [0, 1, 2, 3, 4, 5, 6], 
+        function(i, cb) {
+          stream.write(i +".cheese\n", "utf8", cb);
+        }, 
+        function() {
+          stream.end();
+          that.callback();
         }
-                //wait for the file system to catch up with us
+      );
-                setTimeout(that.callback, 100);
-            });
     },
     'the number of files': {
       topic: function() {
         fs.readdir(__dirname, this.callback);
       },
       'should be two': function(files) {
-                assert.equal(files.filter(function(file) { return file.indexOf('test-rolling-file-stream-write-more') > -1; }).length, 2);
+        assert.equal(files.filter(
+          function(file) { 
+            return file.indexOf('test-rolling-file-stream-write-more') > -1; 
+          }
+        ).length, 2);
       }
     },
     'the first file': {
@@ -122,5 +161,50 @@ vows.describe('RollingFileStream').addBatch({
         assert.equal(contents, '0.cheese\n1.cheese\n2.cheese\n3.cheese\n4.cheese\n');
       }
     }
+  },
+  'when many files already exist': {
+    topic: function() {
+      remove(__dirname + '/test-rolling-stream-with-existing-files.11');
+      remove(__dirname + '/test-rolling-stream-with-existing-files.20');
+      remove(__dirname + '/test-rolling-stream-with-existing-files.-1');
+      remove(__dirname + '/test-rolling-stream-with-existing-files.1.1');
+      remove(__dirname + '/test-rolling-stream-with-existing-files.1');
+      
+
+      create(__dirname + '/test-rolling-stream-with-existing-files.11');
+      create(__dirname + '/test-rolling-stream-with-existing-files.20');
+      create(__dirname + '/test-rolling-stream-with-existing-files.-1');
+      create(__dirname + '/test-rolling-stream-with-existing-files.1.1');
+      create(__dirname + '/test-rolling-stream-with-existing-files.1');
+
+      var that = this
+      , stream = new RollingFileStream(
+        __dirname + "/test-rolling-stream-with-existing-files", 
+        45,
+        5
+      );
+      async.each(
+        [0, 1, 2, 3, 4, 5, 6], 
+        function(i, cb) {
+          stream.write(i +".cheese\n", "utf8", cb);
+        }, 
+        function() {
+          stream.end();
+          that.callback();
+        }
+      );
+    },
+    'the files': {
+      topic: function() {
+        fs.readdir(__dirname, this.callback);
+      },
+      'should be rolled': function(files) {
+        assert.include(files, 'test-rolling-stream-with-existing-files');
+        assert.include(files, 'test-rolling-stream-with-existing-files.1');
+        assert.include(files, 'test-rolling-stream-with-existing-files.2');
+        assert.include(files, 'test-rolling-stream-with-existing-files.11');
+        assert.include(files, 'test-rolling-stream-with-existing-files.20');
+      }
+    }
   }  
 }).exportTo(module);

test/subcategories-test.js

@@ -0,0 +1,86 @@
+"use strict";
+var assert = require('assert')
+, vows = require('vows')
+, sandbox = require('sandboxed-module')
+, log4js = require('../lib/log4js')
+, levels = require('../lib/levels');
+
+vows.describe('subcategories').addBatch({
+    'loggers created after levels configuration is loaded': {
+      topic: function() {
+
+        log4js.configure({
+          "levels": {
+            "sub1": "WARN",
+            "sub1.sub11": "TRACE",
+            "sub1.sub11.sub111": "WARN",
+            "sub1.sub12": "INFO"            
+          }
+        }, { reloadSecs: 30 })
+
+        return {
+          "sub1":  log4js.getLogger('sub1'), // WARN
+          "sub11":  log4js.getLogger('sub1.sub11'), // TRACE
+          "sub111":  log4js.getLogger('sub1.sub11.sub111'), // WARN
+          "sub12":  log4js.getLogger('sub1.sub12'), // INFO
+
+          "sub13":  log4js.getLogger('sub1.sub13'), // Inherits sub1: WARN
+          "sub112":  log4js.getLogger('sub1.sub11.sub112'), // Inherits sub1.sub11: TRACE
+          "sub121":  log4js.getLogger('sub1.sub12.sub121'), // Inherits sub12: INFO
+          "sub0":  log4js.getLogger('sub0') // Not defined, not inherited: TRACE
+        };
+      },
+      'check logger levels': function(loggers) {
+        assert.equal(loggers.sub1.level, levels.WARN);
+        assert.equal(loggers.sub11.level, levels.TRACE);
+        assert.equal(loggers.sub111.level, levels.WARN);
+        assert.equal(loggers.sub12.level, levels.INFO);
+
+        assert.equal(loggers.sub13.level, levels.WARN);
+        assert.equal(loggers.sub112.level, levels.TRACE);
+        assert.equal(loggers.sub121.level, levels.INFO);
+        assert.equal(loggers.sub0.level, levels.TRACE);         
+      }
+    },
+    'loggers created before levels configuration is loaded': {
+      topic: function() {
+
+        var loggers = {
+          "sub1":  log4js.getLogger('sub1'), // WARN
+          "sub11":  log4js.getLogger('sub1.sub11'), // TRACE
+          "sub111":  log4js.getLogger('sub1.sub11.sub111'), // WARN
+          "sub12":  log4js.getLogger('sub1.sub12'), // INFO
+
+          "sub13":  log4js.getLogger('sub1.sub13'), // Inherits sub1: WARN
+          "sub112":  log4js.getLogger('sub1.sub11.sub112'), // Inherits sub1.sub11: TRACE
+          "sub121":  log4js.getLogger('sub1.sub12.sub121'), // Inherits sub12: INFO
+          "sub0":  log4js.getLogger('sub0') // Not defined, not inherited: TRACE
+        };
+
+
+        log4js.configure({
+          "levels": {
+            "sub1": "WARN",
+            "sub1.sub11": "TRACE",
+            "sub1.sub11.sub111": "WARN",
+            "sub1.sub12": "INFO"            
+          }
+        }, { reloadSecs: 30 })
+
+        return loggers;
+
+
+      },
+      'check logger levels': function(loggers) {
+        assert.equal(loggers.sub1.level, levels.WARN);
+        assert.equal(loggers.sub11.level, levels.TRACE);
+        assert.equal(loggers.sub111.level, levels.WARN);
+        assert.equal(loggers.sub12.level, levels.INFO);
+
+        assert.equal(loggers.sub13.level, levels.WARN);
+        assert.equal(loggers.sub112.level, levels.TRACE);
+        assert.equal(loggers.sub121.level, levels.INFO);
+        assert.equal(loggers.sub0.level, levels.TRACE);         
+      }
+    }
+}).exportTo(module);

test/with-categoryFilter.json

@@ -0,0 +1,23 @@
+{
+  "appenders": [
+    { 
+      "type": "categoryFilter",
+      "exclude": "web",
+      "appender": {
+        "type": "file",
+        "filename": "test/categoryFilter-noweb.log", 
+        "layout": { 
+          "type": "messagePassThrough" 
+        } 
+      }
+    },
+    { 
+      "category": "web", 
+      "type": "file",
+      "filename": "test/categoryFilter-web.log", 
+      "layout": { 
+        "type": "messagePassThrough" 
+      } 
+    }
+  ]
+}

test/with-logLevelFilter.json

@@ -12,6 +12,19 @@
         } 
       }
     },
+    {
+      "category": "tests",
+      "type": "logLevelFilter",
+      "level": "TRACE",
+      "maxLevel": "DEBUG",
+      "appender": {
+        "type": "file",
+        "filename": "test/logLevelFilter-debugs.log",
+        "layout": {
+          "type": "messagePassThrough"
+          }
+        }
+    },
     { 
       "category": "tests", 
       "type": "file",
@@ -23,6 +36,6 @@
   ],
   
   "levels": {
-    "tests":  "DEBUG"
+    "tests":  "TRACE"
   }
 }