Skip to content

Commit

Permalink
Merge pull request #1211 from log4js-node/update-test
Browse files Browse the repository at this point in the history
chore(test): improved test cases
  • Loading branch information
lamweili committed Mar 15, 2022
2 parents e58a48a + c863c77 commit 34af8dc
Show file tree
Hide file tree
Showing 6 changed files with 211 additions and 69 deletions.
6 changes: 4 additions & 2 deletions lib/appenders/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -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()}`);
Expand Down
6 changes: 4 additions & 2 deletions lib/layouts.js
Original file line number Diff line number Diff line change
Expand Up @@ -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':
Expand All @@ -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':
Expand Down
129 changes: 104 additions & 25 deletions test/tap/default-settings-test.js
Original file line number Diff line number Diff line change
@@ -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;

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

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

t.plan(3);
t.equal(
output.length,
0,
"Nothing should be logged until configure is called."
);
logger.info("This should not be logged yet.");
t.equal(output.length, 0, "nothing should be logged");

log4js.configure({
appenders: { stdout: { type: "stdout" } },
categories: { default: { appenders: ["stdout"], level: "debug" } }
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();
});
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.end();
});
18 changes: 13 additions & 5 deletions test/tap/file-sighup-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -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 = {
Expand All @@ -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 => {
Expand Down
47 changes: 47 additions & 0 deletions test/tap/layouts-test.js
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
const { test } = require("tap");
const debug = require("debug");
const os = require("os");
const path = require("path");

Expand Down Expand Up @@ -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() {
Expand Down Expand Up @@ -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,
Expand All @@ -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,
Expand All @@ -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,
Expand All @@ -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,
Expand Down

0 comments on commit 34af8dc

Please sign in to comment.