Skip to content

Commit

Permalink
fix: logger fails to print null objects
Browse files Browse the repository at this point in the history 
In case you try printing the following:
```
const obj1 = null;
this.$logger.info("value %s", obj1);
```
Our implementation fails with error: `Cannot read property hasOwnProperty of null`.
The problem is in the way we check for passed logger options in the args passed to `logger` methods. The `typeof null` returns object, so next parts of the code fail.

Also passed logger options are handled by priority, i.e. the first passed option should be used. This allows callers of methods that specify some logger options internaly, to overwrite their values. Add unit tests for this behavior.
Fix the case when same logger option is passed multiple times in different objects - currently only one of the instances is removed and the other one is included in the message visible to the user. Now all such objects are removed.
Add unit tests for all of the described cases.
  • Loading branch information
@rosen-vladimirov
rosen-vladimirov committed Jun 5, 2019
1 parent 812d980 commit 6256958
Show file tree
Hide file tree
Showing 2 changed files with 102 additions and 12 deletions.
31 changes: 20 additions & 11 deletions lib/common/logger/logger.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -154,31 +154,40 @@ export class Logger implements ILogger {
}

private getLogOptionsForMessage(data: any[]): { data: any[], [key: string]: any } {
const opts = _.keys(LoggerConfigData);
const loggerOptionKeys = _.keys(LoggerConfigData);
const dataToCheck = data.filter(el => {
// objects created with Object.create(null) do not have `hasOwnProperty` function
if (!!el && typeof el === "object" && el.hasOwnProperty && typeof el.hasOwnProperty === "function") {
for (const key of loggerOptionKeys) {
if (el.hasOwnProperty(key)) {
// include only the elements which have one of the keys we've specified as logger options
return true;
}
}
}

const result: any = {};
const cleanedData = _.cloneDeep(data);
return false;
});

// objects created with Object.create(null) do not have `hasOwnProperty` function
const dataToCheck = data.filter(el => typeof el === "object" && el.hasOwnProperty && typeof el.hasOwnProperty === "function");
const result: any = {
data: _.difference(data, dataToCheck)
};

for (const element of dataToCheck) {
if (opts.length === 0) {
if (loggerOptionKeys.length === 0) {
break;
}

const remainingOpts = _.cloneDeep(opts);
const remainingOpts = _.cloneDeep(loggerOptionKeys);
for (const prop of remainingOpts) {
const hasProp = element && element.hasOwnProperty(prop);
if (hasProp) {
opts.splice(opts.indexOf(prop), 1);
loggerOptionKeys.splice(loggerOptionKeys.indexOf(prop), 1);
result[prop] = element[prop];
cleanedData.splice(cleanedData.indexOf(element), 1);
}
}
}

result.data = cleanedData;
return result;
}

Expand All @@ -195,7 +204,7 @@ export class Logger implements ILogger {
/*******************************************************************************************
* Metods below are deprecated. Delete them in 6.0.0 release: *
* Present only for backwards compatibility as some plugins (nativescript-plugin-firebase) *
* use these methods in their hooks *
* use these methods in their hooks *
*******************************************************************************************/

out(...args: any[]): void {
Expand Down
83 changes: 82 additions & 1 deletion lib/common/test/unit-tests/logger.ts
View file
Original file line number Diff line number Diff line change
@@ -1,8 +1,10 @@
import { Yok } from "../../yok";
import { Logger } from "../../logger/logger";
import * as path from "path";
import * as util from "util";
import { assert } from "chai";
import * as fileSystemFile from "../../file-system";
import { LoggerConfigData } from "../../../constants";

const passwordReplacement = "*******";
const debugTrace = ["debug", "trace"];
Expand Down Expand Up @@ -33,7 +35,11 @@ describe("logger", () => {
fs = testInjector.resolve("fs");
outputs = {
debug: "",
trace: ""
trace: "",
info: "",
error: "",
context: {},
removedContext: {}
};

const log4jsLogger = {
Expand All @@ -42,6 +48,18 @@ describe("logger", () => {
},
trace: (...args: string[]) => {
outputs.trace += args.join("");
},
info: (...args: string[]) => {
outputs.info += util.format.apply(null, args);
},
error: (...args: string[]) => {
outputs.error += util.format.apply(null, args);
},
addContext(key: string, value: any): void {
outputs.context[key] = value;
},
removeContext(key: string): void {
outputs.removedContext[key] = true;
}
};

Expand Down Expand Up @@ -139,4 +157,67 @@ describe("logger", () => {
assert.deepEqual(outputs.trace, `${request}${requestBody}`, "logger.trace should not obfuscate body of request unless it is towards api/itmstransporter");
});
});

describe("info", () => {
[undefined, null, false, "string value", 42, { obj: 1 }, ["string value 1", "string value 2"]].forEach(value => {
it(`handles formatted message with '${value}' value in one of the args`, () => {
logger.info("test %s", value);
assert.equal(outputs.info, `test ${value}`);
assert.deepEqual(outputs.context, {}, "Nothing should be added to logger context.");
assert.deepEqual(outputs.removedContext, {}, "Removed context should be empty.");
});

it(`handles formatted message with '${value}' value in one of the args and additional values passed to context`, () => {
logger.info("test %s", value, { [LoggerConfigData.skipNewLine]: true });
assert.equal(outputs.info, `test ${value}`);
assert.deepEqual(outputs.context, { [LoggerConfigData.skipNewLine]: true }, `${LoggerConfigData.skipNewLine} should be set with value true.`);
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.skipNewLine]: true }, `Removed context should contain ${LoggerConfigData.skipNewLine}`);
});
});

it("sets correct context when multiple logger options are passed in one object", () => {
logger.info("test", { [LoggerConfigData.skipNewLine]: true, [LoggerConfigData.useStderr]: true });
assert.equal(outputs.info, "test");
assert.deepEqual(outputs.context, { [LoggerConfigData.skipNewLine]: true, [LoggerConfigData.useStderr]: true });
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.skipNewLine]: true, [LoggerConfigData.useStderr]: true });
});

it("sets correct context when multiple logger options are passed in multiple objects", () => {
logger.info({ [LoggerConfigData.useStderr]: true }, "test", { [LoggerConfigData.skipNewLine]: true });
assert.equal(outputs.info, "test");
assert.deepEqual(outputs.context, { [LoggerConfigData.skipNewLine]: true, [LoggerConfigData.useStderr]: true });
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.skipNewLine]: true, [LoggerConfigData.useStderr]: true });
});
});

describe("printMarkdown", () => {
it(`passes markdown formatted text to log4js.info method`, () => {
logger.printMarkdown("header text\n==");
assert.isTrue(outputs.info.indexOf("# header text") !== -1);
});

it(`passes skipNewLine to log4js context`, () => {
logger.printMarkdown("`coloured` text");
assert.isTrue(outputs.info.indexOf("coloured") !== -1);
assert.deepEqual(outputs.context, { [LoggerConfigData.skipNewLine]: true }, `${LoggerConfigData.skipNewLine} should be set with value true.`);
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.skipNewLine]: true }, `Removed context should contain ${LoggerConfigData.skipNewLine}`);
});
});

describe("error", () => {
const errorMessage = "this is error message";
it(`passes useStderr to log4js context`, () => {
logger.error(errorMessage);
assert.equal(outputs.error, errorMessage);
assert.deepEqual(outputs.context, { [LoggerConfigData.useStderr]: true }, `${LoggerConfigData.useStderr} should be set with value true.`);
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.useStderr]: true }, `Removed context should contain ${LoggerConfigData.useStderr}`);
});

it(`allows overwrite of useStderr`, () => {
logger.error(errorMessage, { [LoggerConfigData.useStderr]: false });
assert.equal(outputs.error, errorMessage);
assert.deepEqual(outputs.context, { [LoggerConfigData.useStderr]: false }, `${LoggerConfigData.useStderr} should be set with value false.`);
assert.deepEqual(outputs.removedContext, { [LoggerConfigData.useStderr]: true }, `Removed context should contain ${LoggerConfigData.useStderr}`);
});
});
});

0 comments on commit 6256958

Please sign in to comment.