diff --git a/README.md b/README.md index dd3f0b1..4e767a9 100644 --- a/README.md +++ b/README.md @@ -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`. @@ -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 diff --git a/src/index.ts b/src/index.ts index cdd568a..7596a3b 100644 --- a/src/index.ts +++ b/src/index.ts @@ -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 = any>(obj: T, fun: F): T & F => new Proxy(fun as any, { get: (_target, key) => (obj as any)[key], @@ -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, + const messageKey = 'message'; // best option for Google Stackdriver, const streams = initLoggerStreams(defaultLevel, Object.assign({}, options, { messageKey })); options.ignoredHttpMethods = options.ignoredHttpMethods || ['OPTIONS']; diff --git a/src/streams.ts b/src/streams.ts index 12812ef..0ba4b86 100644 --- a/src/streams.ts +++ b/src/streams.ts @@ -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 }) => { @@ -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: Infinity }); } 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(); } } @@ -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; }; diff --git a/src/tests/index.test.ts b/src/tests/index.test.ts index e2fdc38..7d07c23 100644 --- a/src/tests/index.test.ts +++ b/src/tests/index.test.ts @@ -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', () => { @@ -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(); @@ -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'); @@ -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 => { @@ -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); + } }), ], }); @@ -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);