Skip to content

Commit

Permalink
don't use async for logging because we lose stack traces
Browse files Browse the repository at this point in the history
  • Loading branch information
@hiro5id
hiro5id committed Dec 12, 2019
1 parent de7e22b commit 73bd31c
Show file tree
Hide file tree
Showing 3 changed files with 66 additions and 69 deletions.
2 changes: 1 addition & 1 deletion src/get-calling-filename.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ import callsites from 'callsites';

export function getCallingFilename(): string | null {
const callsitesList = callsites();
const callsite = callsitesList[4];
const callsite = callsitesList[3];
let name: string | null = callsite.getFileName();
if (name) {
name = name.replace(appRootPath.toString(), '');
Expand Down
115 changes: 56 additions & 59 deletions src/logger.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -233,14 +233,27 @@ function ifEverythingFailsLogger(functionName: string, err: Error) {

let logParams!: { logLevel: LOG_LEVEL; debugString: boolean };

export function LoggerAdaptToConsole(options?: { logLevel?: LOG_LEVEL; debugString?: boolean }) {
export async function LoggerAdaptToConsole(options?: { logLevel?: LOG_LEVEL; debugString?: boolean }) {
const defaultOptions = {
logLevel: LOG_LEVEL.info,
debugString: false,
};

logParams = { ...defaultOptions, ...options };

// log package name
packageName = '';
const getPackageName = new Promise<string>(packageResolve => {
const readJson = require('read-package-json');
// tslint:disable-next-line:variable-name
readJson(path.join(appRootPath.toString(), 'package.json'), null, false, (_err: any, data: any) => {
packageName = data.name;
packageResolve();
});
});
getPackageName.catch(reason => {
packageName = `<error>:${reason}`;
});

Logger.level = logParams.logLevel;

if (consoleErrorBackup == null) {
Expand Down Expand Up @@ -304,6 +317,8 @@ export function LoggerAdaptToConsole(options?: { logLevel?: LOG_LEVEL; debugStri
console.log = (...args: any[]) => {
return logUsingWinston(args, LOG_LEVEL.info);
};

return getPackageName;
}

function filterNullOrUndefinedParameters(args: any): number {
Expand Down Expand Up @@ -352,76 +367,58 @@ function findExplicitLogLevelAndUseIt(args: any, level: LOG_LEVEL) {
return level;
}

let packageName: string | null = null;
let packageName: string = '';

export async function logUsingWinston(args: any[], level: LOG_LEVEL) {
// log package name
try {
const getPackageName = new Promise<string>(packageResolve => {
if (packageName == null) {
const readJson = require('read-package-json');
// tslint:disable-next-line:variable-name
readJson(path.join(appRootPath.toString(), 'package.json'), null, false, (_err: any, data: any) => {
packageResolve(data.name);
});
} else {
packageResolve(packageName);
}
});

packageName = await getPackageName;
export function logUsingWinston(args: any[], level: LOG_LEVEL) {
if (packageName.length === 0) {
args.push({ '@packageName': '<not-yet-set> Please await the call LoggerAdaptToConsole() on startup' });
} else {
args.push({ '@packageName': packageName });
} catch (err) {
args.push({ '@packageName': `<error>:${err.message}` });
}

return new Promise(resolve => {
// log debug logging if needed
try {
if (logParams.debugString) {
// this line is only for enabling testing
if ((console as any).debugStringException != null) {
(console as any).debugStringException();
}

let argsStringArray = args.map(m => JSON.stringify(m, Object.getOwnPropertyNames(m)));
if (!argsStringArray) {
argsStringArray = [];
}
args.push({ _loggerDebug: argsStringArray });
// log debug logging if needed
try {
if (logParams.debugString) {
// this line is only for enabling testing
if ((console as any).debugStringException != null) {
(console as any).debugStringException();
}
} catch (err) {
args.push({ _loggerDebug: `err ${err.message}` });
}

// Discover calling filename
try {
const name = getCallingFilename();
if (name) {
args.push({ '@filename': name, '@logCallStack': getCallStack() });
} else {
args.push({ '@filename': '<unknown>', '@logCallStack': getCallStack() });
let argsStringArray = args.map(m => JSON.stringify(m, Object.getOwnPropertyNames(m)));
if (!argsStringArray) {
argsStringArray = [];
}
} catch (err) {
args.push({ '@filename': `<error>:${err.message}`, '@logCallStack': err.message });
args.push({ _loggerDebug: argsStringArray });
}
} catch (err) {
args.push({ _loggerDebug: `err ${err.message}` });
}

try {
level = findExplicitLogLevelAndUseIt(args, level);
// Discover calling filename
try {
const name = getCallingFilename();
if (name) {
args.push({ '@filename': name, '@logCallStack': getCallStack() });
} else {
args.push({ '@filename': '<unknown>', '@logCallStack': getCallStack() });
}
} catch (err) {
args.push({ '@filename': `<error>:${err.message}`, '@logCallStack': err.message });
}

// this line is only for enabling testing
if (console.exception != null) {
console.exception();
}
const { message, errorObject } = extractParametersFromArguments(args);
try {
level = findExplicitLogLevelAndUseIt(args, level);

Logger.log(level, message, errorObject);
} catch (err) {
ifEverythingFailsLogger('console.log', err);
// this line is only for enabling testing
if (console.exception != null) {
console.exception();
}
const { message, errorObject } = extractParametersFromArguments(args);

resolve();
});
Logger.log(level, message, errorObject);
} catch (err) {
ifEverythingFailsLogger('console.log', err);
}
}

/**
Expand Down
18 changes: 9 additions & 9 deletions test/logger.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ import {
describe('logger', () => {
it('logs error in correct shape', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();
try {
// action
NativeConsoleLog('testing native log');
Expand Down Expand Up @@ -44,7 +44,7 @@ describe('logger', () => {

it('logs error in correct shape using console.log', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();
try {
// action
await console.log('some string', new ErrorWithContext('error \r\nobject', {'extra-context': 'extra-context'}));
Expand Down Expand Up @@ -74,7 +74,7 @@ describe('logger', () => {

it('console.log is correctly adapted when using a combination of types', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();
try {
// action
await console.log(
Expand Down Expand Up @@ -165,7 +165,7 @@ describe('logger', () => {
it('console.debug works', async () => {
const backupLevel = GetLogLevel();
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole({logLevel:LOG_LEVEL.debug});
await LoggerAdaptToConsole({logLevel:LOG_LEVEL.debug});

try {
await console.debug('this is a message', {'extra-context': 'hello'});
Expand Down Expand Up @@ -259,7 +259,7 @@ describe('logger', () => {

it('logs error properly when extra context is a string and main error is an error object', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();

const extraContext = 'this is a test string';
const mainError = new Error('error message 2');
Expand Down Expand Up @@ -291,7 +291,7 @@ describe('logger', () => {

it('console.info works', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();

await console.info('this is a test', {a: 'stuff-a', b: 'stuff-b'}, 'more messages', {c: 'stuff-c'});

Expand Down Expand Up @@ -319,7 +319,7 @@ describe('logger', () => {

it('handles object with circular reference', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();

const circObject: any = {bob:"bob"};
circObject.circ = circObject;
Expand All @@ -337,7 +337,7 @@ describe('logger', () => {

it('Handle where a string is passed to the logger that happens to be JSON, with new lines in it', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();

const circObject: any = {bob:"bob"};
circObject.circ = circObject;
Expand Down Expand Up @@ -446,7 +446,7 @@ describe('logger', () => {

it('handle empty object', async () => {
const {originalWrite, outputText} = overrideStdOut();
LoggerAdaptToConsole();
await LoggerAdaptToConsole();

await console.log({}, 'this is a test', {a: 'stuff-a', b: 'stuff-b'}, 'more messages', {c: 'stuff-c'}, {});

Expand Down

0 comments on commit 73bd31c

Please sign in to comment.