Merge pull request #1211 from log4js-node/update-test

chore(test): improved test cases
This commit is contained in:
Lam Wei Li 2022-03-15 16:43:15 +08:00 committed by GitHub
commit 34af8dc692
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 211 additions and 69 deletions

View File

@ -73,14 +73,16 @@ const createAppender = (name, config) => {
`Appender ${appenderConfig.type} exports an appender function.`,
"DeprecationWarning", "log4js-node-DEP0001"
);
debug(`DEPRECATION: Appender ${appenderConfig.type} exports an appender function.`);
debug("[log4js-node-DEP0001]",
`DEPRECATION: Appender ${appenderConfig.type} exports an appender function.`);
}
if (appenderModule.shutdown) {
process.emitWarning(
`Appender ${appenderConfig.type} exports a shutdown function.`,
"DeprecationWarning", "log4js-node-DEP0002"
);
debug(`DEPRECATION: Appender ${appenderConfig.type} exports a shutdown function.`);
debug("[log4js-node-DEP0002]",
`DEPRECATION: Appender ${appenderConfig.type} exports a shutdown function.`);
}
debug(`${name}: clustering.isMaster ? ${clustering.isMaster()}`);

View File

@ -160,7 +160,8 @@ function patternLayout(pattern, tokens) {
"Please use %d{ABSOLUTETIME} instead.",
"DeprecationWarning", "log4js-node-DEP0003"
);
debug("DEPRECATION: Pattern %d{ABSOLUTE} is deprecated and replaced by %d{ABSOLUTETIME}.");
debug("[log4js-node-DEP0003]",
"DEPRECATION: Pattern %d{ABSOLUTE} is deprecated and replaced by %d{ABSOLUTETIME}.");
// falls through
case 'ABSOLUTETIME':
case 'ABSOLUTETIME_FORMAT':
@ -172,7 +173,8 @@ function patternLayout(pattern, tokens) {
"Please use %d{DATETIME} instead.",
"DeprecationWarning", "log4js-node-DEP0004"
);
debug("DEPRECATION: Pattern %d{DATE} is deprecated and replaced by %d{DATETIME}.");
debug("[log4js-node-DEP0004]",
"DEPRECATION: Pattern %d{DATE} is deprecated and replaced by %d{DATETIME}.");
// falls through
case 'DATETIME':
case 'DATETIME_FORMAT':

View File

@ -1,48 +1,127 @@
const { test } = require("tap");
const debug = require("debug");
const sandbox = require("@log4js-node/sandboxed-module");
test("default settings", t => {
const output = [];
test("default settings", batch => {
const originalListener = process.listeners("warning")[process.listeners("warning").length - 1];
const warningListener = error => {
if (error.name === "DeprecationWarning") {
if (error.code.startsWith("log4js-node-DEP0001") || error.code.startsWith("log4js-node-DEP0002")) {
return;
}
}
originalListener(error);
};
process.off("warning", originalListener);
process.on("warning", warningListener);
const debugWasEnabled = debug.enabled("log4js:appenders");
const debugLogs = [];
const originalWrite = process.stderr.write;
process.stderr.write = (string, encoding, fd) => {
debugLogs.push(string);
if (debugWasEnabled) {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:appenders`);
batch.teardown(async () => {
// next event loop so that past warnings will not be printed
setImmediate(() => {
process.off("warning", warningListener);
process.on("warning", originalListener);
});
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const output = [];
const log4js = sandbox.require("../../lib/log4js", {
requires: {
"./appenders/stdout": {
name: "stdout",
appender() {
appender() { // deprecated
return function(evt) {
output.push(evt);
};
},
shutdown() {
shutdown() { // deprecated
},
configure() {
return this.appender();
}
}
},
debug
}
});
const logger = log4js.getLogger("default-settings");
logger.info("This should not be logged yet.");
let logger;
t.plan(3);
t.equal(
output.length,
0,
"Nothing should be logged until configure is called."
);
log4js.configure({
appenders: { stdout: { type: "stdout" } },
categories: { default: { appenders: ["stdout"], level: "debug" } }
batch.test("should call configure() on getLogger() if not configured", t => {
const DEP0001 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0001") > -1).length;
const DEP0002 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0002") > -1).length;
logger = log4js.getLogger("default-settings");
t.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0001") > -1).length,
DEP0001 + 1,
"deprecation log4js-node-DEP0001 emitted"
);
t.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0002") > -1).length,
DEP0002 + 1,
"deprecation log4js-node-DEP0002 emitted"
);
t.end();
});
logger.info("This should go to stdout.");
t.equal(output.length, 1, "It should log to stdout.");
t.equal(
output[0].data[0],
"This should go to stdout.",
"It should log the message."
);
t.end();
batch.test("nothing should be logged until level is set or configure() is called", t => {
const originalLevel = logger.level;
t.equal(
originalLevel.levelStr,
"OFF",
"default logger.level should be OFF"
);
logger.info("This should not be logged yet.");
t.equal(output.length, 0, "nothing should be logged");
t.test("after level is set", assert => {
logger.level = "debug";
logger.info("This should be logged.");
assert.equal(output.length, 1, "should log the message if level is set");
assert.equal(output[output.length - 1].data[0], "This should be logged.");
logger.level = originalLevel;
assert.end();
});
t.test("after configure() is called", assert => {
const DEP0001 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0001") > -1).length;
const DEP0002 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0002") > -1).length;
log4js.configure({
appenders: { stdout: { type: "stdout" } },
categories: { default: { appenders: ["stdout"], level: "debug" } }
});
assert.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0001") > -1).length,
DEP0001 + 1,
"deprecation log4js-node-DEP0001 emitted"
);
assert.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0002") > -1).length,
DEP0002 + 1,
"deprecation log4js-node-DEP0002 emitted"
);
logger.info("This should go to stdout.");
assert.equal(output.length, 2, "should log the message after configure() is called");
assert.equal(output[output.length - 1].data[0], "This should go to stdout.");
assert.end();
});
t.end();
});
batch.end();
});

View File

@ -14,11 +14,15 @@ test("file appender single SIGHUP handler", t => {
const initialListeners = process.listenerCount("SIGHUP");
let warning;
const originalListener = process.listeners("warning")[process.listeners("warning").length - 1];
const warningListener = error => {
if (error.type === "SIGHUP" && error.name === "MaxListenersExceededWarning") {
warning = error;
return;
}
originalListener(error);
};
process.off("warning", originalListener);
process.on("warning", warningListener);
const config = {
@ -39,21 +43,25 @@ test("file appender single SIGHUP handler", t => {
log4js.configure(config);
t.teardown(async () => {
// next event loop so that past warnings will not be printed
setImmediate(() => {
process.off("warning", warningListener);
process.on("warning", originalListener);
});
await new Promise(resolve => { log4js.shutdown(resolve); });
const filenames = Object.values(config.appenders).map(appender => appender.filename);
await removeFiles(filenames);
process.off("warning", warningListener);
});
t.plan(2);
// put in a timeout 0 to allow event emitter/listener to happen
setTimeout(() => {
// next event loop to allow event emitter/listener to happen
setImmediate(() => {
t.notOk(warning, "should not have MaxListenersExceededWarning for SIGHUP");
t.equal(process.listenerCount("SIGHUP") - initialListeners, 1, "should be 1 SIGHUP listener");
t.end();
}, 0);
});
});
test("file appender SIGHUP", t => {

View File

@ -1,4 +1,5 @@
const { test } = require("tap");
const debug = require("debug");
const os = require("os");
const path = require("path");
@ -245,6 +246,40 @@ test("log4js layouts", batch => {
});
batch.test("patternLayout", t => {
const originalListener = process.listeners("warning")[process.listeners("warning").length - 1];
const warningListener = error => {
if (error.name === "DeprecationWarning") {
if (error.code.startsWith("log4js-node-DEP0003") || error.code.startsWith("log4js-node-DEP0004")) {
return;
}
}
originalListener(error);
};
process.off("warning", originalListener);
process.on("warning", warningListener);
const debugWasEnabled = debug.enabled("log4js:layouts");
const debugLogs = [];
const originalWrite = process.stderr.write;
process.stderr.write = (string, encoding, fd) => {
debugLogs.push(string);
if (debugWasEnabled) {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:layouts`);
batch.teardown(async () => {
// next event loop so that past warnings will not be printed
setImmediate(() => {
process.off("warning", warningListener);
process.on("warning", originalListener);
});
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const tokens = {
testString: "testStringToken",
testFunction() {
@ -421,6 +456,7 @@ test("log4js layouts", batch => {
"2010-12-05T14:18:30.045+10:00"
);
const DEP0003 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0003") > -1).length;
testPattern(
assert,
layout,
@ -429,6 +465,11 @@ test("log4js layouts", batch => {
"%d{ABSOLUTE}", // deprecated
"14:18:30.045"
);
assert.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0003") > -1).length,
DEP0003 + 1,
"deprecation log4js-node-DEP0003 emitted"
);
testPattern(
assert,
layout,
@ -438,6 +479,7 @@ test("log4js layouts", batch => {
"14:18:30.045"
);
const DEP0004 = debugLogs.filter((e) => e.indexOf("log4js-node-DEP0004") > -1).length;
testPattern(
assert,
layout,
@ -446,6 +488,11 @@ test("log4js layouts", batch => {
"%d{DATE}", // deprecated
"05 12 2010 14:18:30.045"
);
assert.equal(
debugLogs.filter((e) => e.indexOf("log4js-node-DEP0004") > -1).length,
DEP0004 + 1,
"deprecation log4js-node-DEP0004 emitted"
);
testPattern(
assert,
layout,

View File

@ -74,10 +74,6 @@ test("multiFile appender", batch => {
);
batch.test("should close file after timeout", t => {
t.teardown(async () => {
await new Promise(resolve => { log4js.shutdown(resolve); });
await removeFiles("logs/C.log");
});
/* checking that the file is closed after a timeout is done by looking at the debug logs
since detecting file locks with node.js is platform specific.
*/
@ -90,7 +86,16 @@ test("multiFile appender", batch => {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
debug.enable("log4js:multiFile");
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:multiFile`);
t.teardown(async () => {
await new Promise(resolve => { log4js.shutdown(resolve); });
await removeFiles("logs/C.log");
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const timeoutMs = 25;
log4js.configure({
appenders: {
@ -113,19 +118,11 @@ test("multiFile appender", batch => {
`C not used for > ${timeoutMs} ms => close`,
"(timeout1) should have closed"
);
if (!debugWasEnabled) {
debug.disable("log4js:multiFile");
}
process.stderr.write = originalWrite;
t.end();
}, timeoutMs*1 + 50); // add a 50 ms delay
});
batch.test("should close file safely after timeout", t => {
t.teardown(async () => {
await new Promise(resolve => { sandboxedLog4js.shutdown(resolve); }); // eslint-disable-line no-use-before-define
await removeFiles("logs/C.log");
});
const error = new Error("fileAppender shutdown error");
const sandboxedLog4js = sandbox.require("../../lib/log4js", {
requires: {
@ -157,7 +154,16 @@ test("multiFile appender", batch => {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
debug.enable("log4js:multiFile");
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:multiFile`);
t.teardown(async () => {
await new Promise(resolve => { sandboxedLog4js.shutdown(resolve); });
await removeFiles("logs/C.log");
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const timeoutMs = 25;
sandboxedLog4js.configure({
appenders: {
@ -185,19 +191,11 @@ test("multiFile appender", batch => {
`ignore error on file shutdown: ${error.message}`,
"safely shutdown"
);
if (!debugWasEnabled) {
debug.disable("log4js:multiFile");
}
process.stderr.write = originalWrite;
t.end();
}, timeoutMs*1 + 50); // add a 50 ms delay
});
batch.test("should close file after extended timeout", t => {
t.teardown(async () => {
await new Promise(resolve => { log4js.shutdown(resolve); });
await removeFiles("logs/D.log");
});
/* checking that the file is closed after a timeout is done by looking at the debug logs
since detecting file locks with node.js is platform specific.
*/
@ -210,7 +208,16 @@ test("multiFile appender", batch => {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
debug.enable("log4js:multiFile");
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:multiFile`);
t.teardown(async () => {
await new Promise(resolve => { log4js.shutdown(resolve); });
await removeFiles("logs/D.log");
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const timeoutMs = 100;
log4js.configure({
appenders: {
@ -247,18 +254,11 @@ test("multiFile appender", batch => {
`D not used for > ${timeoutMs} ms => close`,
"(timeout2) should have closed"
);
if (!debugWasEnabled) {
debug.disable("log4js:multiFile");
}
process.stderr.write = originalWrite;
t.end();
}, timeoutMs*2 + 50); // add a 50 ms delay
});
batch.test("should clear interval for active timers on shutdown", t => {
t.teardown(async () => {
await removeFiles("logs/D.log");
});
/* checking that the file is closed after a timeout is done by looking at the debug logs
since detecting file locks with node.js is platform specific.
*/
@ -271,7 +271,15 @@ test("multiFile appender", batch => {
originalWrite.apply(process.stderr, [string, encoding, fd]);
}
};
debug.enable("log4js:multiFile");
const originalNamespace = debug.disable();
debug.enable(`${originalNamespace}, log4js:multiFile`);
t.teardown(async () => {
await removeFiles("logs/D.log");
process.stderr.write = originalWrite;
debug.enable(originalNamespace);
});
const timeoutMs = 100;
log4js.configure({
appenders: {
@ -302,10 +310,6 @@ test("multiFile appender", batch => {
"calling shutdown for D",
"should have called shutdown"
);
if (!debugWasEnabled) {
debug.disable("log4js:multiFile");
}
process.stderr.write = originalWrite;
t.end();
});
});