cartodb4/log4js-node
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Merged Gareth's latest changes in

Browse Source
This commit is contained in:
Daniel Bell
2011-07-26 11:11:27 +10:00
parent 3b241095cb b72182c0cf
commit 623bc1859f
12 changed files with 620 additions and 408 deletions
Download Patch File Download Diff File Expand all files Collapse all files

183
test/fileAppender.js Normal file
View File

@@ -0,0 +1,183 @@
var vows = require('vows')
, fs = require('fs')
, log4js = require('../lib/log4js')
, assert = require('assert');
log4js.clearAppenders();
function remove(filename) {
try {
fs.unlinkSync(filename);
} catch (e) {
//doesn't really matter if it failed
}
}
vows.describe('log4js fileAppender').addBatch({
'with default fileAppender settings': {
topic: function() {
var testFile = __dirname + '/fa-default-test.log'
, logger = log4js.getLogger('default-settings');
remove(testFile);
log4js.addAppender(log4js.fileAppender(testFile), 'default-settings');
logger.info("This should be in the file.");
fs.readFile(testFile, "utf8", this.callback);
},
'should write log messages to the file': function(err, fileContents) {
assert.include(fileContents, "This should be in the file.\n");
},
'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 = __dirname + '/fa-maxFileSize-test.log'
, logger = log4js.getLogger('max-file-size');
remove(testFile);
//log file of 50 bytes maximum, no backups, check every 10ms for changes
log4js.addAppender(log4js.fileAppender(testFile, log4js.layouts.basicLayout, 50, 0, 0.01), 'max-file-size');
logger.info("This is the first log message.");
//we have to wait before writing the second one, because node is too fast for the file system.
var that = this;
setTimeout(function() {
logger.info("This is the second log message.");
fs.readFile(testFile, "utf8", that.callback);
}, 500);
},
'log file should only contain the second message': function(err, fileContents) {
assert.include(fileContents, "This is the second log message.\n");
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 one': function(err, files) {
var logFiles = files.filter(function(file) { return file.indexOf('fa-maxFileSize-test.log') > -1; });
assert.length(logFiles, 1);
}
}
},
'with a max file size and 2 backups': {
topic: function() {
var testFile = __dirname + '/fa-maxFileSize-with-backups-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, check every 10ms for changes
log4js.addAppender(log4js.fileAppender(testFile, log4js.layouts.basicLayout, 50, 2, 0.01), 'max-file-size-backups');
logger.info("This is the first log message.");
//we have to wait before writing the second one, because node is too fast for the file system.
var that = this;
setTimeout(function() {
logger.info("This is the second log message.");
}, 200);
setTimeout(function() {
logger.info("This is the third log message.");
}, 400);
setTimeout(function() {
logger.info("This is the fourth log message.");
fs.readdir(__dirname, that.callback);
}, 600);
},
'the log files': {
topic: function(files) {
var logFiles = files.filter(function(file) { return file.indexOf('fa-maxFileSize-with-backups-test.log') > -1; });
return logFiles;
},
'should be 3': function (files) {
assert.length(files, 3);
},
'should be named in sequence': function (files) {
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(logFiles[0], "utf8", this.callback);
},
'should be the last log message': function(err, contents) {
assert.include(contents, 'This is the fourth log message.');
}
},
'and the contents of the second file': {
topic: function(logFiles) {
fs.readFile(logFiles[1], "utf8", this.callback);
},
'should be the third log message': function(err, contents) {
assert.include(contents, 'This is the third log message.');
}
},
'and the contents of the third file': {
topic: function(logFiles) {
fs.readFile(logFiles[2], "utf8", this.callback);
},
'should be the second log message': function(err, contents) {
assert.include(contents, 'This is the second log message.');
}
}
}
}
}).addBatch({
'configure' : {
'with fileAppender': {
topic: function() {
var log4js = require('../lib/log4js')
, 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');
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) {
assert.include(contents, 'this should be written to the file\n');
assert.equal(contents.indexOf('this should not be written to the file'), -1);
},
'and log rolling': {
topic: function() {
var sandbox = require('sandboxed-module')
, that = this
, fileAppender = sandbox.require(
'../lib/appenders/file.js'
, { requires:
{ 'fs':
{
watchFile: function(filename, options, cb) {
that.callback(null, filename);
}
, createWriteStream: function() {
return {
on: function() {}
, end: function() {}
, destroy: function() {}
};
}
}
}
}
);
fileAppender.configure({
filename: "cheese.log"
, maxLogSize: 100
, backups: 5
, pollInterval: 30
});
},
'should watch the log file': function(watchedFile) {
assert.equal(watchedFile, 'cheese.log');
}
}
}
}
}).export(module);

31
test/layouts.js
View File

@@ -65,7 +65,19 @@ vows.describe('log4js layouts').addBatch({
, toString: function() { return "ERROR"; }
}
}), "thing 1");
}
},
'should output the first item even if it is not a string': function(layout) {
assert.equal(layout({
data: [ { thing: 1} ]
, startTime: new Date(2010, 11, 5, 14, 18, 30, 45)
, categoryName: "cheese"
, level: {
colour: "green"
, toString: function() { return "ERROR"; }
}
}), "{ thing: 1 }");
}
},
'basicLayout': {
@@ -90,29 +102,24 @@ vows.describe('log4js layouts').addBatch({
error = new Error("Some made-up error"),
stack = error.stack.split(/\n/);
event.data = ['this is a test', error];
event.data = ['this is a test ', error];
output = layout(event);
lines = output.split(/\n/);
assert.length(lines, stack.length+1);
assert.equal(lines[0], "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test");
assert.equal(lines[1], "Error: Some made-up error");
assert.length(lines, stack.length);
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+1], stack[i]);
assert.equal(lines[i+1], stack[i+1]);
}
},
'should output any extra data in the log event as util.inspect strings': function(args) {
var layout = args[0], event = args[1], output, lines;
event.data = ['this is a test', {
event.data = ['this is a test ', {
name: 'Cheese',
message: 'Gorgonzola smells.'
}];
output = layout(event);
lines = output.split(/\n/);
assert.length(lines, 2);
assert.equal(lines[0], "[2010-12-05 14:18:30.045] [DEBUG] tests - this is a test");
assert.equal(lines[1], "{ 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.' }");
}
},

69
test/logLevelFilter.js Normal file
View File

@@ -0,0 +1,69 @@
var vows = require('vows')
, fs = require('fs')
, assert = require('assert');
function remove(filename) {
try {
fs.unlinkSync(filename);
} catch (e) {
//doesn't really matter if it failed
}
}
vows.describe('log4js logLevelFilter').addBatch({
'appender': {
topic: function() {
var log4js = require('../lib/log4js'), logEvents = [], logger;
log4js.clearAppenders();
log4js.addAppender(log4js.logLevelFilter('ERROR', function(evt) { logEvents.push(evt); }), "logLevelTest");
logger = log4js.getLogger("logLevelTest");
logger.debug('this should not trigger an event');
logger.warn('neither should this');
logger.error('this should, though');
logger.fatal('so should this');
return logEvents;
},
'should only pass log events greater than or equal to its own level' : function(logEvents) {
assert.length(logEvents, 2);
assert.equal(logEvents[0].data[0], 'this should, though');
assert.equal(logEvents[1].data[0], 'so should this');
}
},
'configure': {
topic: function() {
var log4js = require('../lib/log4js')
, logger;
remove(__dirname + '/logLevelFilter.log');
remove(__dirname + '/logLevelFilter-warnings.log');
log4js.configure('test/with-logLevelFilter.json');
logger = log4js.getLogger("tests");
logger.info('main');
logger.error('both');
logger.warn('both');
logger.debug('main');
return logger;
},
'tmp-tests.log': {
topic: function() {
fs.readFile(__dirname + '/logLevelFilter.log', 'utf8', this.callback);
},
'should contain all log messages': function(contents) {
var messages = contents.trim().split('\n');
assert.deepEqual(messages, ['main','both','both','main']);
}
},
'tmp-tests-warnings.log': {
topic: function() {
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');
assert.deepEqual(messages, ['both','both']);
}
}
}
}).export(module);

389
test/logging.js
View File

@@ -55,225 +55,33 @@ vows.describe('log4js').addBatch({
},
'fileAppender': {
topic: function() {
var appender
, logmessages = []
, thing = "thing"
, fakeFS = {
createWriteStream: function() {
assert.equal(arguments[0], './tmp-tests.log');
assert.isObject(arguments[1]);
assert.equal(arguments[1].flags, 'a');
assert.equal(arguments[1].mode, 0644);
assert.equal(arguments[1].encoding, 'utf8');
return {
write: function(message) {
logmessages.push(message);
}
, end: function() {}
, destroySoon: function() {}
};
},
watchFile: function() {
throw new Error("watchFile should not be called if logSize is not defined");
}
},
log4js = sandbox.require(
'../lib/log4js',
{
requires: {
'fs': fakeFS
}
}
);
log4js.clearAppenders();
appender = log4js.fileAppender('./tmp-tests.log', log4js.layouts.messagePassThroughLayout);
log4js.addAppender(appender, 'file-test');
var logger = log4js.getLogger('file-test');
logger.debug("this is a test");
return logmessages;
},
'should write log messages to file': function(logmessages) {
assert.length(logmessages, 1);
assert.equal(logmessages, "this is a test\n");
'invalid configuration': {
'should throw an exception': function() {
assert.throws(function() {
log4js.configure({ "type": "invalid" });
});
}
},
'fileAppender - with rolling based on size and number of files to keep': {
'configuration when passed as object': {
topic: function() {
var watchCb,
filesOpened = [],
filesEnded = [],
filesRenamed = [],
newFilenames = [],
existingFiles = ['tests.log'],
log4js = sandbox.require(
'../lib/log4js'
, {
requires: {
'fs': {
watchFile: function(file, options, callback) {
assert.equal(file, 'tests.log');
assert.equal(options.persistent, false);
assert.equal(options.interval, 30000);
assert.isFunction(callback);
watchCb = callback;
},
createWriteStream: function(file) {
assert.equal(file, 'tests.log');
filesOpened.push(file);
return {
end: function() {
filesEnded.push(file);
}
};
},
statSync: function(file) {
if (existingFiles.indexOf(file) < 0) {
throw new Error("this file doesn't exist");
} else {
return true;
}
},
renameSync: function(oldFile, newFile) {
filesRenamed.push(oldFile);
existingFiles.push(newFile);
}
var appenderConfig
, log4js = sandbox.require(
'../lib/log4js'
, { requires:
{ './appenders/file.js':
{
name: "file"
, appender: function() {}
, configure: function(configuration) {
appenderConfig = configuration;
return function() {};
}
}
}
);
var appender = log4js.fileAppender('tests.log', log4js.messagePassThroughLayout, 1024, 2, 30);
return [watchCb, filesOpened, filesEnded, filesRenamed, existingFiles];
},
'should close current log file, rename all old ones, open new one on rollover': function(args) {
var watchCb = args[0]
, filesOpened = args[1]
, filesEnded = args[2]
, filesRenamed = args[3]
, existingFiles = args[4];
assert.isFunction(watchCb);
//tell the watchCb that the file is below the threshold
watchCb({ size: 891 }, { size: 0 });
//filesOpened should still be the first one.
assert.length(filesOpened, 1);
//tell the watchCb that the file is now over the threshold
watchCb({ size: 1053 }, { size: 891 });
//it should have closed the first log file.
assert.length(filesEnded, 1);
//it should have renamed the previous log file
assert.length(filesRenamed, 1);
//and we should have two files now
assert.length(existingFiles, 2);
assert.deepEqual(existingFiles, ['tests.log', 'tests.log.1']);
//and opened a new log file.
assert.length(filesOpened, 2);
//now tell the watchCb that we've flipped over the threshold again
watchCb({ size: 1025 }, { size: 123 });
//it should have closed the old file
assert.length(filesEnded, 2);
//it should have renamed both the old log file, and the previous '.1' file
assert.length(filesRenamed, 3);
assert.deepEqual(filesRenamed, ['tests.log', 'tests.log.1', 'tests.log' ]);
//it should have renamed 2 more file
assert.length(existingFiles, 4);
assert.deepEqual(existingFiles, ['tests.log', 'tests.log.1', 'tests.log.2', 'tests.log.1']);
//and opened a new log file
assert.length(filesOpened, 3);
//tell the watchCb we've flipped again.
watchCb({ size: 1024 }, { size: 234 });
//close the old one again.
assert.length(filesEnded, 3);
//it should have renamed the old log file and the 2 backups, with the last one being overwritten.
assert.length(filesRenamed, 5);
assert.deepEqual(filesRenamed, ['tests.log', 'tests.log.1', 'tests.log', 'tests.log.1', 'tests.log' ]);
//it should have renamed 2 more files
assert.length(existingFiles, 6);
assert.deepEqual(existingFiles, ['tests.log', 'tests.log.1', 'tests.log.2', 'tests.log.1', 'tests.log.2', 'tests.log.1']);
//and opened a new log file
assert.length(filesOpened, 4);
}
},
'configure' : {
topic: function() {
var messages = {}, fakeFS = {
createWriteStream: function(file) {
return {
write: function(message) {
if (!messages.hasOwnProperty(file)) {
messages[file] = [];
}
messages[file].push(message);
}
, end: function() {}
, destroySoon: function() {}
};
},
readFileSync: function(file, encoding) {
return require('fs').readFileSync(file, encoding);
},
watchFile: function(file) {
messages.watchedFile = file;
}
},
log4js = sandbox.require(
'../lib/log4js'
, {
requires: {
'fs': fakeFS
}
}
);
return [ log4js, messages ];
},
'should load appender configuration from a json file': function(args) {
var log4js = args[0], messages = args[1];
delete messages['tmp-tests.log'];
log4js.clearAppenders();
//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');
var logger = log4js.getLogger("tests");
logger.info('this should not be written to the file');
logger.warn('this should be written to the file');
assert.length(messages['tmp-tests.log'], 1);
assert.equal(messages['tmp-tests.log'][0], 'this should be written to the file\n');
},
'should handle logLevelFilter configuration': function(args) {
var log4js = args[0], messages = args[1];
delete messages['tmp-tests.log'];
delete messages['tmp-tests-warnings.log'];
log4js.clearAppenders();
log4js.configure('test/with-logLevelFilter.json');
var logger = log4js.getLogger("tests");
logger.info('main');
logger.error('both');
logger.warn('both');
logger.debug('main');
assert.length(messages['tmp-tests.log'], 4);
assert.length(messages['tmp-tests-warnings.log'], 2);
assert.deepEqual(messages['tmp-tests.log'], ['main\n','both\n','both\n','main\n']);
assert.deepEqual(messages['tmp-tests-warnings.log'], ['both\n','both\n']);
},
'should handle fileAppender with log rolling' : function(args) {
var log4js = args[0], messages = args[1];
delete messages['tmp-test.log'];
log4js.configure('test/with-log-rolling.json');
assert.equal(messages.watchedFile, 'tmp-test.log');
},
'should handle an object or a file name': function(args) {
var log4js = args[0],
messages = args[1],
config = {
)
, config = {
"appenders": [
{
"type" : "file",
@@ -284,34 +92,88 @@ vows.describe('log4js').addBatch({
}
]
};
delete messages['cheesy-wotsits.log'];
log4js.configure(config);
assert.equal(messages.watchedFile, 'cheesy-wotsits.log');
return appenderConfig;
},
'should be passed to appender config': function(configuration) {
assert.equal(configuration.filename, 'cheesy-wotsits.log');
}
},
'configuration when passed as filename': {
topic: function() {
var appenderConfig
, configFilename
, log4js = sandbox.require(
'../lib/log4js'
, { requires:
{ 'fs':
{
readFileSync: function(filename) {
configFilename = filename;
return JSON.stringify({
appenders: [
{ type: "file"
, filename: "whatever.log"
}
]
});
},
readdirSync: function() {
return ['file.js'];
}
}
, './appenders/file.js':
{
name: "file"
, appender: function() {}
, configure: function(configuration) {
appenderConfig = configuration;
return function() {};
}
}
}
}
);
log4js.configure("/path/to/cheese.json");
return [ configFilename, appenderConfig ];
},
'should read the config from a file': function(args) {
assert.equal(args[0], '/path/to/cheese.json');
},
'should pass config to appender': function(args) {
assert.equal(args[1].filename, "whatever.log");
}
},
'with no appenders defined' : {
topic: function() {
var logger
, message
, that = this
, fakeConsoleAppender = {
name: "console"
, appender: function() {
return function(evt) {
that.callback(null, evt);
}
}
, configure: function() {
return fakeConsoleAppender.appender();
}
}
, log4js = sandbox.require(
'../lib/log4js'
, {
globals: {
console: {
log: function(msg) {
message = msg;
}
}
requires: {
'./appenders/console.js': fakeConsoleAppender
}
}
}
);
logger = log4js.getLogger("some-logger");
logger.debug("This is a test");
return message;
},
'should default to the console appender': function(message) {
assert.isTrue(/This is a test$/.test(message));
'should default to the console appender': function(evt) {
assert.equal(evt.data[0], "This is a test");
}
},
@@ -403,10 +265,13 @@ vows.describe('log4js').addBatch({
'default setup': {
topic: function() {
var pathsChecked = [],
message,
appenderEvent,
logger,
modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
fakeFS = {
readdirSync: function(dir) {
return require('fs').readdirSync(dir);
},
readFileSync: function (file, encoding) {
assert.equal(file, modulePath);
assert.equal(encoding, 'utf8');
@@ -422,28 +287,27 @@ vows.describe('log4js').addBatch({
}
},
fakeConsole = {
log : function (msg) { message = msg; },
info: this.log,
warn: this.log,
debug: this.log,
error: this.log
'name': 'console'
, 'appender': function () {
return function(evt) { appenderEvent = evt; }
}
, 'configure': function (config) {
return fakeConsole.appender();
}
},
log4js = sandbox.require(
'../lib/log4js',
{
requires: {
'fs': fakeFS
},
globals: {
'console': fakeConsole
, './appenders/console.js': fakeConsole
}
}
);
logger = log4js.getLogger('a-test');
logger.debug("this is a test");
return [ pathsChecked, message, modulePath ];
return [ pathsChecked, appenderEvent, modulePath ];
},
'should check current directory, require paths, and finally the module dir for log4js.json': function(args) {
@@ -458,27 +322,8 @@ vows.describe('log4js').addBatch({
},
'should configure log4js from first log4js.json found': function(args) {
var message = args[1];
assert.equal(message, 'this is a test');
}
},
'logLevelFilter': {
topic: function() {
var log4js = require('../lib/log4js'), logEvents = [], logger;
log4js.clearAppenders();
log4js.addAppender(log4js.logLevelFilter('ERROR', function(evt) { logEvents.push(evt); }), "logLevelTest");
logger = log4js.getLogger("logLevelTest");
logger.debug('this should not trigger an event');
logger.warn('neither should this');
logger.error('this should, though');
logger.fatal('so should this');
return logEvents;
},
'should only pass log events greater than or equal to its own level' : function(logEvents) {
assert.length(logEvents, 2);
assert.equal(logEvents[0].data[0], 'this should, though');
assert.equal(logEvents[1].data[0], 'so should this');
var appenderEvent = args[1];
assert.equal(appenderEvent.data[0], 'this is a test');
}
},
@@ -549,12 +394,15 @@ vows.describe('log4js').addBatch({
'configuration reload' : {
topic: function() {
var pathsChecked = [],
messages = [],
logEvents = [],
logger,
modulePath = require('path').normalize(__dirname + '/../lib/log4js.json'),
fakeFS = {
config: { appenders: [ { type: 'console', layout: { type: 'messagePassThrough' } } ],
levels: { 'a-test' : 'INFO' } },
readdirSync: function(dir) {
return require('fs').readdirSync(dir);
},
readFileSync: function (file, encoding) {
assert.equal(file, modulePath);
assert.equal(encoding, 'utf8');
@@ -570,11 +418,13 @@ vows.describe('log4js').addBatch({
}
},
fakeConsole = {
log : function (msg) { messages.push(msg); },
info: this.log,
warn: this.log,
debug: this.log,
error: this.log
'name': 'console',
'appender': function () {
return function(evt) { logEvents.push(evt); };
},
'configure': function (config) {
return fakeConsole.appender();
}
},
setIntervalCallback,
fakeSetInterval = function(cb, timeout) {
@@ -584,7 +434,8 @@ vows.describe('log4js').addBatch({
'../lib/log4js',
{
requires: {
'fs': fakeFS
'fs': fakeFS,
'./appenders/console.js': fakeConsole
},
globals: {
'console': fakeConsole,
@@ -601,14 +452,14 @@ vows.describe('log4js').addBatch({
logger.info("info3");
logger.debug("debug4");
return [ pathsChecked, messages, modulePath ];
return [ pathsChecked, logEvents, modulePath ];
},
'should configure log4js from first log4js.json found': function(args) {
var messages = args[1];
assert.length(messages, 3);
assert.equal(messages[0], 'info1');
assert.equal(messages[1], 'info3');
assert.equal(messages[2], 'debug4');
var logEvents = args[1];
assert.length(logEvents, 3);
assert.equal(logEvents[0].data[0], 'info1');
assert.equal(logEvents[1].data[0], 'info3');
assert.equal(logEvents[2].data[0], 'debug4');
}
}

4
test/with-logLevelFilter.json
View File

@@ -6,7 +6,7 @@
"level": "WARN",
"appender": {
"type": "file",
"filename": "tmp-tests-warnings.log",
"filename": "test/logLevelFilter-warnings.log",
"layout": {
"type": "messagePassThrough"
}
@@ -15,7 +15,7 @@
{
"category": "tests",
"type": "file",
"filename": "tmp-tests.log",
"filename": "test/logLevelFilter.log",
"layout": {
"type": "messagePassThrough"
}