Skip to content
This repository has been archived by the owner on Jun 21, 2023. It is now read-only.

Replace pino pretty with util.inspect #25

Merged
merged 5 commits into from
Nov 18, 2019
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
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: 7 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -133,7 +133,7 @@ const logger = require('cosmas').default({
If the `NODE_ENV` environment variable is set to `test`, all logs are turned off (minimal loglevel is set to `silent` which effectively turns logging off).

### Pretty print
If you set `pretty` option to `true`, you enable pretty print mode intended for development use. `pkgVersion` and `severity` are ommited from output.
If you set `pretty` option to `true`, you enable pretty print mode intended for development use. `cosmas.pkgVersion`, `cosmas.loggerName` and `severity` are ommited from the output.

### Otherwise
[Standard pino log](https://github.com/pinojs/pino#usage) is used and it's optimized for Google Stackdriver logging. That means that default log level is `debug`, pretty print is turned off and [pino's `messageKey` option](https://github.com/pinojs/pino/blob/master/docs/API.md#pinooptions-stream) is set to `message`.
Expand All @@ -159,6 +159,12 @@ Options override both default logger configuration and environment-specific conf
- `req` - logs `body`, `query`, `url`, `method` and omits `password` and `passwordCheck` from `body` and `query`
- `res` - logs `out`, `time`, `headers.x-deviceid`, `headers.authorization` and `headers.user-agent`

## Reserved keys
Cosmas uses some object keys for its own purposes. Those keys should not be used in data you send to log functions as they may be overwritten by Cosmas. Those keys are:

- `cosmas.loggerName` - used for the name of logger
- `cosmas.pkgVersion` - used for the version of `cosmas`
- `message` - used for the log message text

## Tips

Expand Down
6 changes: 5 additions & 1 deletion src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,10 @@ export interface AckeeLoggerFactory extends AckeeLogger {
(data?: string | AckeeLoggerOptions): AckeeLogger;
}

// cannot use Symbols, because they aren't JSON.stringifyable
export const loggerNameKey = 'cosmas.loggerName';
export const pkgVersionKey = 'cosmas.pkgVersion';

const makeCallable = <T extends object, F extends (...args: any[]) => any>(obj: T, fun: F): T & F =>
new Proxy(fun as any, {
get: (_target, key) => (obj as any)[key],
Expand Down Expand Up @@ -67,7 +71,7 @@ const defaultLogger = (options: AckeeLoggerOptions & { loggerName?: string } = {

const isTesting = process.env.NODE_ENV === 'test';
const defaultLevel: Level = options.defaultLevel || (isTesting ? 'silent' : 'debug');
const messageKey = options.pretty ? 'msg' : 'message'; // "message" is the best option for Google Stackdriver,
smoliji marked this conversation as resolved.
Show resolved Hide resolved
const messageKey = 'message'; // best option for Google Stackdriver,
const streams = initLoggerStreams(defaultLevel, Object.assign({}, options, { messageKey }));

options.ignoredHttpMethods = options.ignoredHttpMethods || ['OPTIONS'];
Expand Down
49 changes: 18 additions & 31 deletions src/streams.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,12 @@ import * as fs from 'fs';
import * as path from 'path';
import * as pino from 'pino';
import { Transform, TransformCallback } from 'stream';
import * as util from 'util';
import { loggerNameKey, pkgVersionKey } from '.';
import { AckeeLoggerOptions, AckeeLoggerStream } from './interfaces';
import { levels } from './levels';
import { StackDriverFormatStream } from './stackdriver';

const isString = (x: any) => typeof x === 'string' || x instanceof String;

const pkgJson = JSON.parse(fs.readFileSync(path.resolve(path.join(__dirname, '..', 'package.json')), 'utf8'));

const getDefaultTransformStream = (options: AckeeLoggerOptions & { messageKey: string; loggerName?: string }) => {
Expand All @@ -16,20 +16,25 @@ const getDefaultTransformStream = (options: AckeeLoggerOptions & { messageKey: s
public _transform(chunk: any, _encoding: string, callback: TransformCallback) {
const obj = JSON.parse(chunk);
const loggerName = options.loggerName;
let res;
if (loggerName) {
// always put logger name to message
obj[options.messageKey] = `[${loggerName}] ${obj[options.messageKey]}`;
}
if (loggerName && !options.pretty) {
// do not put logger name field to pretty outputs
obj[loggerNameKey] = loggerName;
}

if (options.pretty) {
obj['name\0'] = obj.name; // add null character so that it is not interpreted by pino-pretty but still visible to user unchanged
delete obj.name;
if (loggerName) {
obj.name = loggerName;
}
res = util.inspect(obj, { colors: true, showHidden: true, depth: 10 });
smoliji marked this conversation as resolved.
Show resolved Hide resolved
} else {
obj.pkgVersion = pkgJson.version;
if (obj[options.messageKey] && isString(obj[options.messageKey]) && loggerName) {
obj[options.messageKey] = `[${loggerName}] ${obj[options.messageKey]}`;
}
// do not put pkgVersion to pretty outputs
obj[pkgVersionKey] = pkgJson.version;
res = JSON.stringify(obj);
}

this.push(`${JSON.stringify(obj)}\n`);
this.push(`${res}\n`);
callback();
}
}
Expand All @@ -55,35 +60,17 @@ const initLoggerStreams = (
let streams: AckeeLoggerStream[];
if (options.streams) {
streams = options.streams.map(stream => Object.assign({ level: defaultLevel }, stream));
} else if (options.pretty) {
const pretty = pino({
prettyPrint: {
levelFirst: true,
},
});
pretty.pipe(process.stdout);
const prettyErr = pino({
prettyPrint: {
levelFirst: true,
},
});
prettyErr.pipe(process.stderr);
streams = [
{ level: defaultLevel, maxLevel: levels.warn, stream: pretty as any },
{ level: 'warn', stream: prettyErr as any },
];
} else {
streams = [
{ level: defaultLevel, maxLevel: levels.warn, stream: process.stdout },
{ level: 'warn', stream: process.stderr },
];
}
if (!options.disableStackdriverFormat) {
if (!options.pretty && !options.disableStackdriverFormat) {
streams = decorateStreams(streams, StackDriverFormatStream);
}

streams = decorateStreams(streams, getDefaultTransformStream(options));

return streams;
};

Expand Down
31 changes: 21 additions & 10 deletions src/tests/index.test.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
import 'jest-extended';
import isString = require('lodash.isstring');
import { Writable } from 'stream';
import loggerFactory from '..';
import loggerFactory, { pkgVersionKey, loggerNameKey } from '..';
import { levels } from '../levels';

test('can create default logger', () => {
Expand All @@ -15,16 +15,16 @@ test('can create named logger', () => {
expect((logger.options as any).loggerName).toBe('myApp');
});

test.skip('can create logger with options', () => { // TODO: will work after pretty mechanics update - broken bc of deps update
test('can create logger with options', () => {
const logger = loggerFactory({ pretty: true });
expect(logger).toBeDefined();
expect(logger.options.pretty).toBe(true);
});

const testWriteStream = (resolve, assert) => ({
const testWriteStream = (resolve, assert, isJson = true) => ({
stream: new Writable({
write: (chunk, encoding, next) => {
const json = JSON.parse(chunk);
const json = isJson ? JSON.parse(chunk) : chunk.toString();
assert(json);
next();
resolve();
Expand Down Expand Up @@ -92,7 +92,7 @@ test('automatic severity field can be disabled by options', () =>
test('logger version is logged', () =>
new Promise((resolve, reject) => {
const logger = loggerFactory({
streams: [testWriteStream(resolve, json => expect(json.pkgVersion).not.toBe(undefined))],
streams: [testWriteStream(resolve, json => expect(json[pkgVersionKey]).not.toBe(undefined))],
});

logger.fatal('Hello');
Expand Down Expand Up @@ -120,8 +120,8 @@ test('silent stream does not write', () => {

const exampleMessages = [
{ type: 'simple', logData: 'Hello' },
{ type: 'message-key', logData: { message: 'You gotta do, what you gotta do' } },
{ type: 'msg-key', logData: { message: 'Mirror, mirror, on the wall' } },
{ type: 'message-key', logData: { message: 'You gotta do, what you gotta do', name: 'Futurama' } },
{ type: 'msg-key', logData: { msg: 'Mirror, mirror, on the wall', name: 'Sleeping Beauty' } },
];

exampleMessages.forEach(data => {
Expand All @@ -133,6 +133,10 @@ exampleMessages.forEach(data => {
streams: [
testWriteStream(resolve, json => {
expect(json.message).toStartWith(`[${loggerName}] `);
expect(json[loggerNameKey]).toBe(loggerName);
if ((data.logData as any).name) {
expect(json.name).toBe((data.logData as any).name);
}
}),
],
});
Expand All @@ -153,9 +157,16 @@ exampleMessages.forEach(data => {
const rootLogger = loggerFactory({
pretty: true,
streams: [
testWriteStream(resolve, json => {
expect(json.name).toEqual(loggerName);
}),
testWriteStream(
resolve,
message => {
expect(message).toContain(loggerName);
if ((data.logData as any).name) {
expect(message).toContain((data.logData as any).name);
}
},
false
),
],
});
const logger = rootLogger(loggerName);
Expand Down