Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix: calling logger methods without a message #501

Merged
merged 8 commits into from
Jul 16, 2022
Merged

Fix: calling logger methods without a message #501

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
c99b513
Handle calling logger methods without message.
RobinTail Jul 16, 2022
e3b4b5c
Improving tests of logger.
RobinTail Jul 16, 2022
a70f26f
Asserting call params in test.
RobinTail Jul 16, 2022
3e0c900
No deleting entries in meta.
RobinTail Jul 16, 2022
e4d5968
Testing color with hasAnsi instead of asserting with chalk.
RobinTail Jul 16, 2022
4579d05
Use Node 18.5 in CI.
RobinTail Jul 16, 2022
ed9bad2
Merge branch 'master' into handle-no-message-logger
RobinTail Jul 16, 2022
e9bce0d
Revert "Use Node 18.5 in CI."
RobinTail Jul 16, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 6 additions & 2 deletions package.json
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,13 +71,15 @@
"devDependencies": {
"@tsconfig/node12": "^1.0.9",
"@types/cors": "^2.8.12",
"@types/has-ansi": "^5.0.0",
"@types/jest": "^27.0.2",
"@types/mime": "^2.0.3",
"@types/node-fetch": "^2.5.12",
"@types/ramda": "^0.28.0",
"@types/triple-beam": "^1.3.2",
"@typescript-eslint/eslint-plugin": "^5.4.0",
"@typescript-eslint/parser": "^5.4.0",
"chalk": "^4.1.2",
"cors": "^2.8.5",
"eslint": "^8.2.0",
"eslint-config-airbnb-base": "^15.0.0",
Expand All @@ -86,16 +88,18 @@
"eslint-plugin-import": "^2.25.3",
"eslint-plugin-prettier": "^4.0.0",
"form-data": "^3.0.0",
"has-ansi": "^4.0.1",
"husky": "^7.0.0",
"jest": "^27.3.1",
"make-coverage-badge": "^1.2.0",
"mockdate": "^3.0.5",
"node-fetch": "^2.6.5",
"prettier": "2.7.1",
"strip-ansi": "^6.0.1",
"ts-jest": "^27.0.7",
"ts-node": "^10.9.1",
"tsd": "^0.21.0",
"typescript": "^4.7.4",
"winston-transport": "^4.4.0"
"typescript": "^4.7.4"
},
"engines": {
"node": ">=12.0.0 <19.0.0"
Expand Down
22 changes: 15 additions & 7 deletions src/logger.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,21 +9,29 @@ const { combine, colorize, timestamp: useTimestamp, printf } = winston.format;

export function createLogger(loggerConfig: LoggerConfig): winston.Logger {
const prettyPrint = (meta: any) => {
delete meta[LEVEL];
delete meta[MESSAGE];
delete meta[SPLAT];
return inspect(meta, false, 1, loggerConfig.color);
const {
[LEVEL]: noLevel,
[MESSAGE]: noMessage,
[SPLAT]: noSplat,
...rest
} = meta;
return inspect(rest, false, 1, loggerConfig.color);
};

const getOutputFormat = (isPretty?: boolean) =>
printf(
({ timestamp, message, level, durationMs, ...meta }) =>
printf(({ timestamp, message, level, durationMs, ...meta }) => {
if (typeof message === "object") {
meta = { ...meta, ...(message as object) };
message = "[No message]";
}
return (
`${timestamp} ${level}: ${message}` +
(durationMs === undefined ? "" : ` duration: ${durationMs}ms`) +
(Object.keys(meta).length === 0
? ""
: " " + (isPretty ? prettyPrint(meta) : JSON.stringify(meta)))
);
);
});

const formats: Format[] = [useTimestamp()];

Expand Down
3 changes: 0 additions & 3 deletions tests/helpers.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,9 +18,6 @@ export const waitFor = async (cb: () => boolean) =>
}, 100);
});

export const delay = async (ms: number) =>
new Promise((resolve) => setTimeout(resolve, ms));

export const serializeSchemaForTest = (
schema: z.ZodTypeAny
): Record<string, any> => {
Expand Down
124 changes: 91 additions & 33 deletions tests/unit/logger.spec.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,37 +1,47 @@
import { createLogger, LoggerConfig } from "../../src";
import Transport from "winston-transport";
import { SPLAT } from "triple-beam";
import { delay } from "../helpers";
import { LEVEL, MESSAGE, SPLAT } from "triple-beam";
import MockDate from "mockdate";
import stripAnsi from "strip-ansi";
import hasAnsi from "has-ansi";

describe("Logger", () => {
let log: any[] = [];

const createTransport = (level: string) => {
return new Transport({
level,
log: (info) => log.push(info),
logv: (info) => log.push(info),
});
};

beforeEach(() => {
log = [];
MockDate.set("2022-01-01T00:00:00Z");
});

afterAll(() => {
MockDate.reset();
});

const dropColorInObjectProps = <T extends Record<string | symbol, any>>(
obj: T
) => {
return Reflect.ownKeys(obj).reduce(
(acc, key) => ({
...acc,
[key]: typeof obj[key] === "string" ? stripAnsi(obj[key]) : obj[key],
}),
{} as typeof obj
);
};

describe("createLogger()", () => {
test("Should create silent logger", () => {
const loggerConfig: LoggerConfig = {
level: "silent",
color: false,
};
const logger = createLogger(loggerConfig);
const transform = jest.spyOn(logger.transports[0].format!, "transform");
expect(logger.silent).toBeTruthy();
expect(logger.isErrorEnabled()).toBeTruthy();
expect(logger.isWarnEnabled()).toBeTruthy();
expect(logger.isInfoEnabled()).toBeFalsy();
expect(logger.isVerboseEnabled()).toBeFalsy();
expect(logger.isDebugEnabled()).toBeFalsy();
expect(logger.isSillyEnabled()).toBeFalsy();
logger.error("test");
expect(transform).toBeCalledTimes(0);
});

test("Should create warn logger", () => {
Expand All @@ -40,19 +50,27 @@ describe("Logger", () => {
color: false,
};
const logger = createLogger(loggerConfig);
const transform = jest.spyOn(logger.transports[0].format!, "transform");
expect(logger.isErrorEnabled()).toBeTruthy();
expect(logger.isWarnEnabled()).toBeTruthy();
expect(logger.isInfoEnabled()).toBeFalsy();
expect(logger.isVerboseEnabled()).toBeFalsy();
expect(logger.isDebugEnabled()).toBeFalsy();
expect(logger.isSillyEnabled()).toBeFalsy();
logger.add(createTransport(loggerConfig.level));
logger.warn("testing warn message", { withMeta: true });
expect(log).toHaveLength(1);
expect(log[0]).toHaveProperty("level");
expect(log[0]).toHaveProperty("message");
expect(log[0].message).toBe("testing warn message");
expect(log[0][SPLAT]).toEqual([{ withMeta: true }]);
expect(transform).toBeCalled();
const params = transform.mock.calls[0][0];
expect(params).toEqual({
level: "warn",
[LEVEL]: "warn",
timestamp: "2022-01-01T00:00:00.000Z",
[SPLAT]: [{ withMeta: true }],
withMeta: true,
message: "testing warn message",
[MESSAGE]:
'2022-01-01T00:00:00.000Z warn: testing warn message {"withMeta":true}',
});
expect(hasAnsi(params.level)).toBeFalsy();
});

test("Should create debug logger", () => {
Expand All @@ -61,35 +79,75 @@ describe("Logger", () => {
color: true,
};
const logger = createLogger(loggerConfig);
const transform = jest.spyOn(logger.transports[0].format!, "transform");
expect(logger.isErrorEnabled()).toBeTruthy();
expect(logger.isWarnEnabled()).toBeTruthy();
expect(logger.isInfoEnabled()).toBeTruthy();
expect(logger.isVerboseEnabled()).toBeTruthy();
expect(logger.isDebugEnabled()).toBeTruthy();
expect(logger.isSillyEnabled()).toBeFalsy();
logger.add(createTransport(loggerConfig.level));
logger.debug("testing debug message", { withColorful: "output" });
expect(log).toHaveLength(1);
expect(log[0]).toHaveProperty("level");
expect(log[0]).toHaveProperty("message");
expect(log[0].message).toBe("testing debug message");
expect(log[0][SPLAT]).toEqual([{ withColorful: "output" }]);
expect(transform).toBeCalled();
const params = transform.mock.calls[0][0];
expect(dropColorInObjectProps(params)).toEqual({
level: "debug",
[LEVEL]: "debug",
timestamp: "2022-01-01T00:00:00.000Z",
[SPLAT]: [{ withColorful: "output" }],
withColorful: "output",
message: "testing debug message",
[MESSAGE]: `2022-01-01T00:00:00.000Z debug: testing debug message { withColorful: 'output' }`,
});
expect(hasAnsi(params.level)).toBeTruthy();
});

test("Should manage profiling", async () => {
test("Should manage profiling", () => {
const loggerConfig: LoggerConfig = {
level: "debug",
color: true,
};
const logger = createLogger(loggerConfig);
logger.add(createTransport(loggerConfig.level));
const transform = jest.spyOn(logger.transports[0].format!, "transform");
logger.profile("long-test");
await delay(500);
MockDate.set("2022-01-01T00:00:00.554Z");
logger.profile("long-test");
expect(log).toHaveLength(1);
expect(log[0]).toHaveProperty("level");
expect(log[0]).toHaveProperty("message");
expect(log[0].message).toBe("long-test");
expect(transform).toBeCalled();
const params = transform.mock.calls[0][0];
expect(dropColorInObjectProps(params)).toEqual({
durationMs: 554,
level: "info",
[LEVEL]: "info",
timestamp: "2022-01-01T00:00:00.554Z",
message: "long-test",
[MESSAGE]: `2022-01-01T00:00:00.554Z info: long-test duration: 554ms`,
});
expect(hasAnsi(params.level)).toBeTruthy();
});

test("Should handle empty message", () => {
const loggerConfig: LoggerConfig = {
level: "debug",
color: true,
};
const logger = createLogger(loggerConfig);
const transform = jest.spyOn(logger.transports[0].format!, "transform");
expect(logger.isErrorEnabled()).toBeTruthy();
expect(logger.isWarnEnabled()).toBeTruthy();
expect(logger.isInfoEnabled()).toBeTruthy();
expect(logger.isVerboseEnabled()).toBeTruthy();
expect(logger.isDebugEnabled()).toBeTruthy();
expect(logger.isSillyEnabled()).toBeFalsy();
logger.error({ someData: "test" });
expect(transform).toBeCalled();
const params = transform.mock.calls[0][0];
expect(dropColorInObjectProps(params)).toEqual({
level: "error",
[LEVEL]: "error",
timestamp: "2022-01-01T00:00:00.000Z",
message: { someData: "test" },
[MESSAGE]: `2022-01-01T00:00:00.000Z error: [No message] { someData: 'test' }`,
});
expect(hasAnsi(params.level)).toBeTruthy();
});
});
});
26 changes: 24 additions & 2 deletions yarn.lock
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1113,6 +1113,11 @@
dependencies:
"@types/node" "*"

"@types/has-ansi@^5.0.0":
version "5.0.0"
resolved "https://registry.yarnpkg.com/@types/has-ansi/-/has-ansi-5.0.0.tgz#aa95db284f7a54991e3597c71fd0747f48fcfa65"
integrity sha512-1mwAilzr9t7E+h+KHaOE3Jxio9G3c2DSQTcjz/JV/xJ9DUuQastSiYmjJz4D07Vh12+tKM4owiFOe2+XOmvEig==

"@types/http-errors@^1.8.2":
version "1.8.2"
resolved "https://registry.yarnpkg.com/@types/http-errors/-/http-errors-1.8.2.tgz#7315b4c4c54f82d13fa61c228ec5c2ea5cc9e0e1"
Expand Down Expand Up @@ -1390,6 +1395,11 @@ ansi-escapes@^4.2.1:
dependencies:
type-fest "^0.21.3"

ansi-regex@^4.1.0:
version "4.1.1"
resolved "https://registry.yarnpkg.com/ansi-regex/-/ansi-regex-4.1.1.tgz#164daac87ab2d6f6db3a29875e2d1766582dabed"
integrity sha512-ILlv4k/3f6vfQ4OoP2AGvirOktlQ98ZEL1k9FaQjxa3L1abBgbuTDAdPOpvbGncC0BTVQrl+OM8xZGK6tWXt7g==

ansi-regex@^5.0.1:
version "5.0.1"
resolved "https://registry.yarnpkg.com/ansi-regex/-/ansi-regex-5.0.1.tgz#082cb2c89c9fe8659a311a53bd6a4dc5301db304"
Expand Down Expand Up @@ -1692,7 +1702,7 @@ chalk@^2.0.0:
escape-string-regexp "^1.0.5"
supports-color "^5.3.0"

chalk@^4.0.0, chalk@^4.1.0:
chalk@^4.0.0, chalk@^4.1.0, chalk@^4.1.2:
version "4.1.2"
resolved "https://registry.yarnpkg.com/chalk/-/chalk-4.1.2.tgz#aac4e2b7734a740867aeb16bf02aad556a1e7a01"
integrity sha512-oKnbhFyRIXpUuez8iBMmyEa4nbj4IOQyuhc/wy9kY7/WVPcwIO9VA668Pu8RkO7+0G76SLROeyw9CpQ061i4mA==
Expand Down Expand Up @@ -2676,6 +2686,13 @@ hard-rejection@^2.1.0:
resolved "https://registry.yarnpkg.com/hard-rejection/-/hard-rejection-2.1.0.tgz#1c6eda5c1685c63942766d79bb40ae773cecd883"
integrity sha512-VIZB+ibDhx7ObhAe7OVtoEbuP4h/MuOTHJ+J8h/eBXotJYl0fBgR72xDFCKgIh22OJZIOVNxBMWuhAr10r8HdA==

has-ansi@^4.0.1:
version "4.0.1"
resolved "https://registry.yarnpkg.com/has-ansi/-/has-ansi-4.0.1.tgz#f216a8c8d7b129e490dc15f4a62cc1cdb9603ce8"
integrity sha512-Qr4RtTm30xvEdqUXbSBVWDu+PrTokJOwe/FU+VdfJPk+MXAPoeOzKpRyrDTnZIJwAkQ4oBLTU53nu0HrkF/Z2A==
dependencies:
ansi-regex "^4.1.0"

has-bigints@^1.0.1:
version "1.0.1"
resolved "https://registry.yarnpkg.com/has-bigints/-/has-bigints-1.0.1.tgz#64fe6acb020673e3b78db035a5af69aa9d07b113"
Expand Down Expand Up @@ -3777,6 +3794,11 @@ minimist@^1.2.0, minimist@^1.2.5, minimist@^1.2.6:
resolved "https://registry.yarnpkg.com/minimist/-/minimist-1.2.6.tgz#8637a5b759ea0d6e98702cfb3a9283323c93af44"
integrity sha512-Jsjnk4bw3YJqYzbdyBiNsPWHPfO++UGG749Cxs6peCu5Xg4nrena6OVxOYxrQTqww0Jmwt+Ref8rggumkTLz9Q==

mockdate@^3.0.5:
version "3.0.5"
resolved "https://registry.yarnpkg.com/mockdate/-/mockdate-3.0.5.tgz#789be686deb3149e7df2b663d2bc4392bc3284fb"
integrity sha512-iniQP4rj1FhBdBYS/+eQv7j1tadJ9lJtdzgOpvsOHng/GbcDh2Fhdeq+ZRldrPYdXvCyfFUmFeEwEGXZB5I/AQ==

mri@1.1.4:
version "1.1.4"
resolved "https://registry.yarnpkg.com/mri/-/mri-1.1.4.tgz#7cb1dd1b9b40905f1fac053abe25b6720f44744a"
Expand Down Expand Up @@ -4980,7 +5002,7 @@ which@^2.0.1:
dependencies:
isexe "^2.0.0"

winston-transport@^4.4.0, winston-transport@^4.5.0:
winston-transport@^4.5.0:
version "4.5.0"
resolved "https://registry.yarnpkg.com/winston-transport/-/winston-transport-4.5.0.tgz#6e7b0dd04d393171ed5e4e4905db265f7ab384fa"
integrity sha512-YpZzcUzBedhlTAfJg6vJDlyEai/IFMIVcaEZZyl3UXIl4gmqRpU7AE89AHLkbzLUsv0NVmw7ts+iztqKxxPW1Q==
Expand Down