From bb31ed77568959670cce62ca2847234b3f2cb87f Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Tue, 10 Jul 2018 13:09:50 +0200 Subject: [PATCH 01/11] v5 docs --- README.md | 434 ++---------------- docs/api.md | 1006 ++++++++++++++++++++--------------------- docs/benchmarks.md | 58 +++ docs/browser.md | 199 ++++++++ docs/child-loggers.md | 95 ++++ docs/ecosystem.md | 7 +- docs/faq.md | 260 ----------- docs/help.md | 119 +++++ docs/transports.md | 42 +- docs/web.md | 170 +++++++ docsify/sidebar.md | 46 +- index.html | 26 +- pino-tree.png | Bin 0 -> 13407 bytes 13 files changed, 1267 insertions(+), 1195 deletions(-) create mode 100644 docs/benchmarks.md create mode 100644 docs/browser.md create mode 100644 docs/child-loggers.md delete mode 100644 docs/faq.md create mode 100644 docs/help.md create mode 100644 docs/web.md create mode 100644 pino-tree.png diff --git a/README.md b/README.md index 83b53ca15..5e9fb1984 100644 --- a/README.md +++ b/README.md @@ -2,423 +2,85 @@ # pino  [![Build Status](https://travis-ci.org/pinojs/pino.svg?branch=master)](https://travis-ci.org/pinojs/pino) [![Coverage Status](https://coveralls.io/repos/github/pinojs/pino/badge.svg?branch=master)](https://coveralls.io/github/pinojs/pino?branch=master) [![TypeScript definitions on DefinitelyTyped](http://definitelytyped.org/badges/standard.svg)](http://definitelytyped.org) -[Extremely fast](#benchmarks) node.js logger, inspired by Bunyan. - -* [Installation](#install) -* [Usage](#usage) -* [Benchmarks](#benchmarks) -* [API ⇗](docs/api.md) -* [FAQ ⇗](docs/faq.md) -* [Redaction ⇗](docs/redaction.md) -* [Ecosystem ⇗](docs/ecosystem.md) -* [Pretty Printing ⇗](docs/pretty.md) -* [Extreme mode explained ⇗](docs/extreme.md) -* [Transports with Pino](#transports) -* [Pino in the browser](#browser) -* [Caveats](#caveats) -* [Team](#team) -* [Contributing](#contributing) -* [Acknowledgements](#acknowledgements) -* [License](#license) +[Very low overhead](#benchmarks) Node.js logger, inspired by Bunyan. + +## Documentation + +* [Benchmarks ⇗](/docs/benchmarks.md) +* [API ⇗](/docs/api.md) +* [Browser API ⇗](/docs/browser.md) +* [Redaction ⇗](/docs/redaction.md) +* [Child Loggers ⇗](/docs/child-loggers.md) +* [Transports ⇗](/docs/transports.md) +* [Web Frameworks ⇗](/docs/web.md) +* [Pretty Printing ⇗](/docs/pretty.md) +* [Extreme Mode ⇗](/docs/extreme.md) +* [Ecosystem ⇗](/docs/ecosystem.md) +* [Help ⇗](/docs/help.md) ## Install ``` -npm install pino --save +$ npm install pino --save ``` -If you need support for Node.js v0.12 or v0.10, please install the latest 2.x release using the `legacy` tag: - -``` -npm install pino@legacy --save -``` - -Documentation for the legacy version 2.x is available on the [`v2.x.x` branch](https://github.com/pinojs/pino/tree/v2.x.x). - ## Usage ```js -'use strict' - -var pino = require('pino')() - -pino.info('hello world') -pino.error('this is at error level') -pino.info('the answer is %d', 42) -pino.info({ obj: 42 }, 'hello world') -pino.info({ obj: 42, b: 2 }, 'hello world') -pino.info({ obj: { aa: 'bbb' } }, 'another') -setImmediate(function () { - pino.info('after setImmediate') -}) -pino.error(new Error('an error')) - -var child = pino.child({ a: 'property' }) -child.info('hello child!') +const logger = require('pino')() -var childsChild = child.child({ another: 'property' }) -childsChild.info('hello baby..') +logger.info('hello world') +const child = logger.child({ a: 'property' }) +child.info('hello child!') ``` This produces: ``` -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098958,"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":50,"msg":"this is at error level","time":1459529098959,"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"the answer is 42","time":1459529098960,"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098960,"obj":42,"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello world","time":1459529098960,"obj":42,"b":2,"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"another","time":1459529098960,"obj":{"aa":"bbb"},"v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":50,"msg":"an error","time":1459529098961,"type":"Error","stack":"Error: an error\n at Object. (/Users/davidclements/z/nearForm/pino/example.js:14:12)\n at Module._compile (module.js:435:26)\n at Object.Module._extensions..js (module.js:442:10)\n at Module.load (module.js:356:32)\n at Function.Module._load (module.js:311:12)\n at Function.Module.runMain (module.js:467:10)\n at startup (node.js:136:18)\n at node.js:963:3","v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello child!","time":1459529098962,"a":"property","v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"hello baby..","time":1459529098962,"another":"property","a":"property","v":1} -{"pid":94473,"hostname":"MacBook-Pro-3.home","level":30,"msg":"after setImmediate","time":1459529098963,"v":1} - -``` - -If you have the [`pino-pretty`](https://github.com/pinojs/pino-pretty) module -installed then you can make these logs easier to read: - -![pretty demo](pretty-demo.png) - - -## Benchmarks - -As far as we know, it is one of the fastest loggers in town: - -`pino.info('hello world')`: - -``` -BASIC benchmark averages -Bunyan average: 549.042ms -Winston average: 467.873ms -Bole average: 201.529ms -Debug average: 253.724ms -LogLevel average: 282.653ms -Pino average: 188.956ms -PinoExtreme average: 108.809ms -``` - -`pino.info({'hello': 'world'})`: - -``` -OBJECT benchmark averages -BunyanObj average: 564.363ms -WinstonObj average: 464.824ms -BoleObj average: 230.220ms -LogLevelObject average: 474.857ms -PinoObj average: 201.442ms -PinoUnsafeObj average: 202.687ms -PinoExtremeObj average: 108.689ms -PinoUnsafeExtremeObj average: 106.718ms -``` - -`pino.info(aBigDeeplyNestedObject)`: - -``` -DEEPOBJECT benchmark averages -BunyanDeepObj average: 5293.279ms -WinstonDeepObj average: 9020.292ms -BoleDeepObj average: 9169.043ms -LogLevelDeepObj average: 15260.917ms -PinoDeepObj average: 8467.807ms -PinoUnsafeDeepObj average: 6159.227ms -PinoExtremeDeepObj average: 8354.557ms -PinoUnsafeExtremeDeepObj average: 6214.073ms -``` - -`pino.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})`: - -``` -BunyanInterpolateExtra average: 778.408ms -WinstonInterpolateExtra average: 627.956ms -BoleInterpolateExtra average: 429.757ms -PinoInterpolateExtra average: 316.043ms -PinoUnsafeInterpolateExtra average: 316.809ms -PinoExtremeInterpolateExtra average: 218.468ms -PinoUnsafeExtremeInterpolateExtra average: 215.040ms -``` - -In many cases, pino is over 5x faster than alternatives. - -For a fair comparison, [LogLevel](http://npm.im/loglevel) was extended -to include a timestamp and [bole](http://npm.im/bole) had -`fastTime` mode switched on. - - -## Transports - -A transport in most logging libraries is something that runs in-process to -perform some operation with the finalized log line. For example, a transport -might send the log line to a standard syslog server after processing the log -line and reformatting it. For details on implementing, and some already written, -transports, see our [Transports⇗](docs/transports.md) document. - -> **Pino *does not* natively support in-process transports.** - -Pino does not support in-process transports because Node processes are -single threaded processes (ignoring some technical details). Given this -restriction, one of the methods Pino employs to achieve its speed is to -purposefully offload the handling of logs, and their ultimate destination, to -external processes so that the threading capabilities of the OS can be -used (or other CPUs). - -One consequence of this methodology is that "error" logs do not get written to -`stderr`. However, since Pino logs are in a parseable format, it is possible to -use tools like [pino-tee][pino-tee] or [jq][jq] to work with the logs. For -example, to view only logs marked as "error" logs: - -``` -$ node an-app.js | jq 'select(.level == 50)' +{"level":30,"time":1531171074631,"msg":"hello world","pid":657,"hostname":"Davids-MBP-3.fritz.box","v":1} +{"level":30,"time":1531171082399,"msg":"hello child!","pid":657,"hostname":"Davids-MBP-3.fritz.box","a":"property","v":1} ``` -In short, the way Pino generates logs: - -1. Reduces the impact of logging on your application to an extremely minimal amount. -2. Gives greater flexibility in how logs are processed and stored. - -Given all of the above, Pino clearly promotes out-of-process log processing. -However, it is possible to wrap Pino and perform processing in-process. -For an example of this, see [pino-multi-stream][pinoms]. +For using Pino with a web framework see: -[pino-tee]: https://npm.im/pino-tee -[jq]: https://stedolan.github.io/jq/ -[pinoms]: https://npm.im/pino-multi-stream +* [Pino with Fastify](docs/web.md#fastify) +* [Pino with Express](docs/web.md#express) +* [Pino with Hapi](docs/web.md#hapi) +* [Pino with Restify](docs/web.md#restify) +* [Pino with Koa](docs/web.md#koa) +* [Pino with Node core `http`](docs/web.md#http) - -## Pino in the browser - -Pino is compatible with [`browserify`](http://npm.im) for browser side usage: - -This can be useful with isomorphic/universal JavaScript code. - -By default, in the browser, -`pino` uses corresponding [Log4j](https://en.wikipedia.org/wiki/Log4j) `console` methods (`console.error`, `console.warn`, `console.info`, `console.debug`, `console.trace`) and uses `console.error` for any `fatal` level logs. - -### Browser Options - -Pino can be passed a `browser` object in the options object, -which can have the following properties: - -#### `asObject` (Boolean) - -```js -var pino = require('pino')({browser: {asObject: true}}) -``` - -The `asObject` option will create a pino-like log object instead of -passing all arguments to a console method, for instance: - -```js -pino.info('hi') // creates and logs {msg: 'hi', level: 30, time: } -``` -When `write` is set, `asObject` will always be `true`. + +## Essentials -#### `write` (Function | Object) +### Development Formatting -Instead of passing log messages to `console.log` they can be passed to -a supplied function. +The [`pino-pretty`](https://github.com/pinojs/pino-pretty) module can be used to +format logs during development: -If `write` is set to a single function, all logging objects are passed -to this function. - -```js -var pino = require('pino')({browser: {write: (o) => { - // do something with o -}}}) -``` - -If `write` is an object, it can have methods that correspond to the -levels. When a message is logged at a given level, the corresponding -method is called. If a method isn't present, the logging falls back -to using the `console`. - - -```js -var pino = require('pino')({browser: {write: { - info: function (o) { - //process info log object - }, - error: function (o) { - //process error log object - } -}}}) -``` - -#### `serialize`: (Boolean | Array) - -The serializers provided to `pino` are ignored by default in the browser, including -the standard serializers provided with Pino. Since the default destination for log -messages is the console, values such as `Error` objects are enhanced for inspection, -which they otherwise wouldn't be if the Error serializer was enabled. - -We can turn all serializers on, - -```js -var pino = require('pino')({ - browser: { - serialize: true - } -}) -``` - -Or we can selectively enable them via an array: - -```js -var pino = require('pino')({ - serializers: { - custom: myCustomSerializer, - another: anotherSerializer - }, - browser: { - serialize: ['custom'] - } -}) -// following will apply myCustomSerializer to the custom property, -// but will not apply anotherSerizlier to another key -pino.info({custom: 'a', another: 'b'}) -``` - -When `serialize` is `true` the standard error serializer is also enabled (see https://github.com/pinojs/pino/blob/master/docs/api.md#stdSerializers). -This is a global serializer which will apply to any `Error` objects passed to the logger methods. - -If `serialize` is an array the standard error serializer is also automatically enabled, it can -be explicitly disabled by including a string in the serialize array: `!stdSerializers.err`, like so: - -```js -var pino = require('pino')({ - serializers: { - custom: myCustomSerializer, - another: anotherSerializer - }, - browser: { - serialize: ['!stdSerializers.err', 'custom'] //will not serialize Errors, will serialize `custom` keys - } -}) -``` - -The `serialize` array also applies to any child logger serializers (see https://github.com/pinojs/pino/blob/master/docs/api.md#discussion-2 -for how to set child-bound serializers). - -Unlike server pino the serializers apply to every object passed to the logger method, -if the `asObject` option is `true`, this results in the serializers applying to the -first object (as in server pino). - -For more info on serializers see https://github.com/pinojs/pino/blob/master/docs/api.md#parameters. - -#### `transmit` (Object) - -An object with `send` and `level` properties. - -The `transmit.level` property specifies the minimum level (inclusive) of when the `send` function -should be called, if not supplied the `send` function be called based on the main logging `level` -(set via `options.level`, defaulting to `info`). - -The `transmit` object must have a `send` function which will be called after -writing the log message. The `send` function is passed the level of the log -message and a `logEvent` object. - -The `logEvent` object is a data structure representing a log message, it represents -the arguments passed to a logger statement, the level -at which they were logged and the heirarchy of child bindings. - -The `logEvent` format is structured like so: - -```js -{ - ts = Number, - messages = Array, - bindings = Array, - level: { label = String, value = Number} -} -``` - -The `ts` property is a unix epoch timestamp in milliseconds, the time is taken from the moment the -logger method is called. - -The `messages` array is all arguments passed to logger method, (for instance `logger.info('a', 'b', 'c')` -would result in `messages` array `['a', 'b', 'c']`). - -The `bindings` array represents each child logger (if any), and the relevant bindings. -For instance given `logger.child({a: 1}).child({b: 2}).info({c: 3})`, the bindings array -would hold `[{a: 1}, {b: 2}]` and the `messages` array would be `[{c: 3}]`. The `bindings` -are ordered according to their position in the child logger heirarchy, with the lowest index -being the top of the heirarchy. - -By default serializers are not applied to log output in the browser, but they will *always* be -applied to `messages` and `bindings` in the `logEvent` object. This allows us to ensure a consistent -format for all values between server and client. - -The `level` holds the label (for instance `info`), and the corresponding numerical value -(for instance `30`). This could be important in cases where client side level values and -labels differ from server side. - -The point of the `send` function is to remotely record log messages: - -```js -var pino = require('pino')({ - browser: { - transmit: { - level: 'warn', - send: function (level, logEvent) { - if (level === 'warn') { - // maybe send the logEvent to a separate endpoint - // or maybe analyse the messages further before sending - } - // we could also use the `logEvent.level.value` property to determine - // numerical value - if (logEvent.level.value >= 50) { // covers error and fatal - - // send the logEvent somewhere - } - } - } - } -}) -``` - - -## Caveats - -### Duplicate Keys - -It's possible for naming conflicts to arise between child loggers and -children of child loggers. - -This isn't as bad as it sounds, even if you do use the same keys between -parent and child loggers Pino resolves the conflict in the sanest way. +![pretty demo](pretty-demo.png) -For example, consider the following: +### Transports & Log Processing -```js -var pino = require('pino') -var fs = require('fs') -pino(fs.createWriteStream('./my-log')) - .child({a: 'property'}) - .child({a: 'prop'}) - .info('howdy') -``` +Due to Node's single-threaded event-loop, it's highly recommended that sending, +alert triggering, reformatting and all forms of log processing +is conducted in a separate process. In Pino parlance we call all log processors +"transports", and recommend that the transports be run as separate +processes, piping the stdout of the application to the stdin of the transport. -```sh -$ cat my-log -{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":1459534114473,"a":"property","a":"prop","v":1} -``` +For more details see our [Transports⇗](docs/transports.md) document. -Notice how there's two key's named `a` in the JSON output. The sub-childs properties -appear after the parent child properties. This means if we run our logs through `pino -t` (or convert them to objects in any other way) we'll end up with one `a` property whose value corresponds to the lowest child in the hierarchy: +### Low overhead -```sh -$ cat my-log | pino -t -{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":"2016-04-01T18:08:34.473Z","a":"prop","v":1} -``` +Using minimum resources for logging is very important. Log messages +tend to get added over time and this can lead to a throttling effect +on applications – such as reduced requests per second. -This equates to the same log output that Bunyan supplies. +In many cases, Pino is over 5x faster than alternatives. -One of Pino's performance tricks is to avoid building objects and stringifying -them, so we're building strings instead. This is why duplicate keys between -parents and children will end up in log output. +See the [Benchmarks](docs/benchmarks.md) document for comparisons. ## The Team diff --git a/docs/api.md b/docs/api.md index e2c2e0e9c..783455a9f 100644 --- a/docs/api.md +++ b/docs/api.md @@ -1,622 +1,583 @@ -# Table of Contents - -+ [pino](#constructor) -+ [Logger Instance](#logger) - * [.pino](#version) - * [.child](#child) - * [.level](#level) - * [.fatal](#fatal) - * [.error](#error) - * [.warn](#warn) - * [.info](#info) - * [.debug](#debug) - * [.trace](#trace) - * [.flush](#flush) - * [.addLevel](#addLevel) - * [.levelVal](#levelVal) - * [level-change (event)](#level-change) - * [.levels.values](#levelValues) - * [.levels.labels](#levelLabels) - * [.isLevelEnabled](#isLevelEnabled) - * [LOG_VERSION](#log_version) - * [.stdSerializers](#stdSerializers) - + [.req](#reqSerializer) - + [.res](#resSerializer) - + [.err](#errSerializer) - + [.wrapRequestSerializer](#wrapReq) - + [.wrapResponseSerializers](#wrapRes) - + [.stdTimeFunctions](#stdTimeFunctions) - + [.epochTime](#epochTimeFunction) - + [.unixTime](#unixTimeFunction) - + [.nullTime](#nullTimeFunction) -* [.destination](#destination) -* [.extreme](#extreme) -+ [Metadata Support](#metadata) - -# module.exports - - -## pino([options], [stream]) - -### Parameters: -+ `options` (object): - * `safe` (boolean): avoid error caused by circular references in the object tree. - Default: `true`. - * `name` (string): the name of the logger. Default: `undefined`. - * `serializers` (object): an object containing functions for custom serialization - of objects. These functions should return an JSONifiable object and they - should never throw. When logging an object, each top-level property matching the exact key of a serializer - will be serialized using the defined serializer. Alternatively, it is possible to register a serializer under the key `Symbol.for('pino.*')` which will act upon the complete log object, i.e. every property. - * `redact` (array|object): As an array, the `redact` option specifies paths that should - have their values redacted from any log output. Each path must be a string, and the syntax - for declaring paths corresponds to JavaScript dot and bracket notation. - See the [redaction](redaction.md) documentation for examples and more information. - **WARNING**: Never allow user input to define redacted paths. See [fast-redact#caveat](http://github.com/davidmarkclements/fast-redact#caveat) for details. - If an object is supplied, three options can be specified: - * `paths` (array): Required. An array of paths - * `censor` (string): Optional. A value to overwrite key which are to be redacted. Default: `'[Redacted]'` - * `remove` (boolean): Optional. Instead of censoring the value, remove both the key and the value. Default: `false` - * `timestamp` (boolean|function): Enables or disables the inclusion of a timestamp in the - log message. If a function is supplied, it must synchronously return a JSON string - representation of the time, e.g. `,"time":1493426328206` (which is the default). - If set to `false`, no timestamp will be included in the output. - See [stdTimeFunctions](#stdTimeFunctions) for a set of available functions - for passing in as a value for this option. Caution: any sort of formatted - time will significantly slow down Pino's performance. - * `level` (string): one of `'fatal'`, `'error'`, `'warn'`, `'info`', `'debug'`, - `'trace'`; also `'silent'` is supported to disable logging. Any other value - defines a custom level and requires supplying a level value via `levelVal`. - Default: 'info'. - * `levelVal` (integer): when defining a custom log level via `level`, set to an - integer value to define the new level. Default: `undefined`. - * `messageKey` (string): the string key for the 'message' in the JSON object. Default `msg`. - * `prettyPrint` (boolean|object): enables pretty printing log logs. This is intended for non-production - configurations. This may be set to a configuration object as outlined in the - [`pino-pretty` documentation](https://github.com/pinojs/pino-pretty). - The options object may additionally contain a `prettifier` property to define - which prettifier module to use. When not present, `prettifier` defaults to - `'pino-pretty'`. Regardless of the value, the specified prettifier module - must be installed as a separate dependency. Default: `false`. - * `onTerminated` (function): this function will be invoked during process shutdown when `extreme` is set to `true`. - The signature of the function is `onTerminated(eventName, err)`. If you do not specify a function, Pino will - invoke `process.exit(0)` when no error has occurred, and `process.exit(1)` otherwise. If you do specify a function, - it is up to you to terminate the process; you **must** perform only synchronous operations at this point. - See [Extreme mode explained](extreme.md) for more detail. - * `enabled` (boolean): enables logging. Default: `true` - * `browser` (Object): browser only, may have `asObject` and `write` keys, see [Pino in the Browser](/README.md#browser) - * `base` (Object): key-value object added as child logger to each log line. If set to `null` the `base` child logger is not added . Default: - * `pid` (process.pid) - * `hostname` (os.hostname) - * `name` of logger if supplied as option - * `crlf` (boolean): logs newline delimited JSON with `\r\n` instead of `\n`. Default: `false`. -+ `stream` (Writable): a writable stream where the logs will be written. - It can also receive some log-line [metadata](#metadata), if the - relative protocol is enabled. Default: `process.stdout` - -### Example: -```js -'use strict' - -var pino = require('pino') -var logger = pino({ - name: 'myapp', - safe: true, - serializers: { - req: pino.stdSerializers.req, - res: pino.stdSerializers.res - } -}) -``` -### Discussion: -Returns a new [logger](#logger) instance. +# API - -# Logger +* [pino() => logger](#export) + * [options](#options) + * [destination](#destination) +* [Logger Instance](#logger) + * [logger.trace()](#trace) + * [logger.debug()](#debug) + * [logger.info()](#info) + * [logger.warn()](#warn) + * [logger.error()](#error) + * [logger.fatal()](#fatal) + * [logger.child()](#child) + * [logger.flush()](#flush) + * [logger.level](#level) + * [logger.isLevelEnabled()](#isLevelEnabled) + * [logger.addLevel()](#addLevel) + * [logger.levelVal](#levelVal) + * [logger.levels](#levels) + * [Event: 'level-change'](#level-change) + * [logger.version](#version) + * [logger.LOG_VERSION](#log_version) +* [Statics](#statics) + * [pino.destination()](#pino-destination) + * [pino.extreme()](#pino-extreme) + * [pino.stdSerializers](#pino-stdSerializers) + * [pino.stdTimeFunctions](#pino-stdTimeFunctions) + * [pino.symbols](#pino-symbols) + * [pino.version](#pino-version) + * [pino.LOG_VERSION](#pino-LOG_VERSION) - -## .pino + +## `pino([options], [destination]) => logger` -Exposes the current version of Pino. +The exported `pino` function takes two optional arguments, +[`options`](#options) and [`destination`](#destination) and +returns a [logger instance](#logger). -### Example: -```js -var log = require('pino')() -if ('pino' in child) console.log(`pino version: ${log.pino}`) -``` + +### `options` (Object) - -## .child(bindings) +#### `name` (String) -### Parameters: -+ `bindings` (object): an object of key-value pairs to include in log lines - as properties. +Default: `undefined` -### Example: -```js -logger.child({ a: 'property' }).info('hello child!') -// generates -// {"pid":46497,"hostname":"MacBook-Pro-di-Matteo.local","level":30,"msg":"hello child!","time":1458124707120,"v":0,"a":"property"} -``` +The name of the logger. When set adds a `name` field to every JSON line logged. -### Discussion: -Creates a child logger, setting all key-value pairs in `bindings` as properties -in the log lines. All serializers will be applied to the given pair. +#### `level` (String) -Child loggers use the same output stream as the parent and inherit -the current log level of the parent at the time they are spawned. +Default: `'info'` -From v2.x.x the log level of a child is mutable (whereas in -v1.x.x it was immutable), and can be set independently of the parent. -If a `level` property is present in the object passed to `child` it will -override the child logger level. +One of `'fatal'`, `'error'`, `'warn'`, `'info`', `'debug'`, `'trace'` or `silent`. + +Additional levels can be explicitly added via the `logger.addLevel` method or implicitly +by setting a custom `level` and `levelVal` together. -For example: +* See [`logger.addLevel`](#addLevel) +* See [`levelVal option`](#opt-levelVal) -``` -var logger = pino() -logger.level = 'error' -logger.info('nope') //does not log -var child = logger.child({foo: 'bar'}) -child.info('nope again') //does not log -child.level = 'info' -child.info('hooray') //will log -logger.info('nope nope nope') //will not log, level is still set to error -logger.child({ foo: 'bar', level: 'debug' }).debug('debug!') -``` +#### `redact` (Array|Object): -Child loggers inherit the serializers from the parent logger but it is -possible to override them. +Default: `undefined` -For example: +As an array, the `redact` option specifies paths that should +have their values redacted from any log output. -``` -var pino = require('./pino') +Each path must be a string using a syntax which corresponds to JavaScript dot and bracket notation. -var customSerializers = { - test: function () { - return 'this is my serializer' - } -} -var child = pino().child({serializers: customSerializers}) +If an object is supplied, three options can be specified: + * `paths` (array): Required. An array of paths + * `censor` (String): Optional. A value to overwrite key which are to be redacted. Default: `'[Redacted]'` + * `remove` (Boolean): Optional. Instead of censoring the value, remove both the key and the value. Default: `false` -child.info({test: 'should not show up'}) -``` +**WARNING**: Never allow user input to define redacted paths. -Will produce the following output: +* See the [redaction ⇗](redaction.md) documentation. +* See [fast-redact#caveat ⇗](http://github.com/davidmarkclements/fast-redact#caveat) -``` -{"pid":7971,"hostname":"mycomputer.local","level":30,"time":1469488147985,"test":"this is my serializer","v":1} -``` + +#### `serializers` (Object) -Also from version 2.x.x we can spawn child loggers from child loggers, for instance: +Default: `{err: pino.stdSerializers.err}` -``` -var logger = pino() -var child = logger.child({father: true}) -var childChild = child.child({baby: true}) -``` +An object containing functions for custom serialization of objects. +These functions should return an JSONifiable object and they +should never throw. When logging an object, each top-level property +matching the exact key of a serializer will be serialized using the defined serializer. -Child logger creation is fast: +* See [pino.stdSerializers](#pino-stdSerializers) -``` -benchBunyanCreation*10000: 1291.332ms -benchBoleCreation*10000: 1630.542ms -benchPinoCreation*10000: 352.330ms -benchPinoExtremeCreation*10000: 102.282ms -``` +##### `serializers[Symbol.for('pino.*')]` (Function) -Logging through a child logger has little performance penalty: +Default: `undefined` -``` -benchBunyanChild*10000: 1343.933ms -benchBoleChild*10000: 1605.969ms -benchPinoChild*10000: 334.573ms -benchPinoExtremeChild*10000: 152.792ms -``` +The `serializers` object may contain a key which is the global symbol: `Symbol.for('pino.*')`. +This will act upon the complete log object rather than corresponding to a particular key. -Spawning children from children has negligible overhead: +#### `base` (Object) -``` -benchBunyanChildChild*10000: 1397.202ms -benchPinoChildChild*10000: 338.930ms -benchPinoExtremeChildChild*10000: 150.143ms -``` +Default: `{pid: process.pid, hostname: os.hostname}` - -## .level +Key-value object added as child logger to each log line. -### Example: -``` -logger.level = 'info' -``` +Set to `null` to avoid adding `pid` and `hostname` properties to each log. -### Discussion: +#### `enabled` (Boolean) -Set this property to the desired logging level. In order of priority, available -levels are: +Default: `true` - 1. `'fatal'` - 2. `'error'` - 3. `'warn'` - 4. `'info'` - 5. `'debug'` - 6. `'trace'` +Set to `false` to disable logging. -The logging level is a *minimum* level. For instance if `logger.level` is -`'info'` then all `'fatal'`, `'error'`, `'warn'`, and `'info'` logs will be enabled. +#### `safe` (Boolean) -You can pass `'silent'` to disable logging. +Default: `true` - -## .fatal([obj], msg, [...]) +Avoid throwing caused by circular references in the object tree. -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +#### `crlf` (Boolean) -### Discussion: -Log at `'fatal'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.fatal('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +Default: `false` -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. +Set to `true` to logs newline delimited JSON with `\r\n` instead of `\n`. -[formatstrs]: https://nodejs.org/dist/latest-v8.x/docs/api/util.html#util_util_format_format_args + +#### `timestamp` (Boolean|Function) - -## .error([obj], msg, [...]) +Default: `true` -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +Enables or disables the inclusion of a timestamp in the +log message. If a function is supplied, it must synchronously return a JSON string +representation of the time, e.g. `,"time":1493426328206` (which is the default). -### Discussion: -Log at `'error'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.error('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +If set to `false`, no timestamp will be included in the output. +See [stdTimeFunctions](#stdTimeFunctions) for a set of available functions +for passing in as a value for this option. -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. +**Caution**: attempting to format time in-process will significantly impact logging performance. - -## .warn([obj], msg, [...]) + +#### `levelVal` (Number) -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +Default: `undefined` -### Discussion: -Log at `'warn'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.warn('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +When defining a custom log level via `level`, set to an integer value to define the new level. -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. + +#### `messageKey` (String) - -## .info([obj], msg, [...]) +Default: `'msg'` -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +The string key for the 'message' in the JSON object. -### Discussion: -Log at `'info'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.info('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +#### `onTerminated` (Function) -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. +Default: `(evt, err) => err ? process.exit(1) : process.exit(0)` - -## .debug([obj], msg, [...]) +This function will be invoked during process shutdown when `extreme` is set to `true`. -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +The signature of the function is `onTerminated(eventName, err)`. If you do not specify a function, Pino will +invoke `process.exit(0)` when no error has occurred, and `process.exit(1)` otherwise. -### Discussion: -Log at `'debug'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.debug('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +If a function is specified it **must** perform only synchronous operations at this point and +then exit the process. -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. +* See [Extreme mode ⇗](/docs/extreme.md) - -## .trace([obj], msg, [...]) +#### `prettyPrint` (Boolean|Object) -### Parameters: -+ `obj` (object): object to be serialized -+ `msg` (string): the log message to write -+ `...` (*): format string values when `msg` is a format string +Default: `false` -### Discussion: -Log at `'trace'` level the given `msg`. The `msg` may contain up to 10 -[format string tokens][formatstrs] (given that the method accetps up to 11 -arguments total). The subsequent parameters passed will be used to fill in these -placeholder tokens with the associated value. Any extra parameters will be -silently ignored. For example, `log.trace('%s', 'a', 'b')` will only log the -string `a` and ignore the `'b'` parameter. +Enables pretty printing log logs. This is intended for non-production +configurations. This may be set to a configuration object as outlined in the +[`pino-pretty` documentation](https://github.com/pinojs/pino-pretty). +The options object may additionally contain a `prettifier` property to define +which prettifier module to use. When not present, `prettifier` defaults to +`'pino-pretty'`. Regardless of the value, the specified prettifier module +must be installed as a separate dependency. -If the first argument is an object, all its properties will be included in the -JSON line. The number of available format string tokens and associated -parameters will be reduced accodringly. +#### `browser` (Object) - -## .flush() +Browser only, may have `asObject` and `write` keys -### Discussion: -Flushes the content of the buffer in [extreme mode](extreme.md). It has no effect if -extreme mode is not enabled. +* See [Browser API](/docs/browser.md) - -## .addLevel(name, lvl) + +### `destination` (WritableStream) + +Default: `pino.destination(1)` (STDOUT) + +The `destination` parameter, at a minimum must be an object with a `write` method. +An ordinary Node.js `stream` can be passed as the destination (such as the result +of `fs.createWriteStream`) but for peak log writing performance it is strongly +recommended to use `pino.destination` or `pino.extreme` to create the destination stream. + +* See [`pino.destination`](#pino-destination) +* See [`pino.extreme`](#pino-extreme) -### Parameters: -+ `name` (string): defines the method name of the new level -+ `lvl` (integer): value for the level, e.g. `35` is between `info` and `warn` +#### `destination[Symbol.for('pino.metadata')]` + +Default: `false` + +Assigning the `pino.metadata` symbol key to `true` on the `destination` parameter +indicates after each log line is written, the following properties should be +set on the `destination` object: + +* the last logging level as `destination.lastLevel` +* the last logging message as `destination.lastMsg` +* the last logging object as `destination.lastObj` +* the last time as `destination.lastTime`, which will be the partial string returned + by the time function. +* the last logger instance as `destination.lastLogger` (to support child + loggers) -### Example: ```js -var pino = require('pino') -var log = pino() -log.addLevel('myLevel', 35) -log.level = 'myLevel' -log.myLevel('a message') +const logger = pino({}, { + [Symbol.for('pino.metadata')]: true, + write: function (chunk) { + console.log('lastLevel', this.lastLevel) + console.log('lastMsg', this.lastMsg) + console.log('lastObj', this.lastObj) + console.log('lastLogger', this.lastLogger) + console.log('line', chunk) + } +}) ``` -### Discussion: -Defines a new level on the logger instance. -Returns `true` on success and `false` if there was a conflict (level name or -number already exists). + +## Logger Instance -When using this method, the current level of the logger instance does not change. -You must adjust the level with the [level](#level) property after adding your -custom level. +The logger instance is the object returned by the main exported +[`pino`](#export) function. + +The primary purpose of the logger instance is to provide logging methods. + +The default logging methods are `trace`, `debug`, `info`, `warn`, and `fatal`. -If you need a custom level at construction, you can supply the `level` and -`levelVal` options: +Each logging method has the following signature: +`([mergingObject], [message], [...interpolationValues])`. + +The parameters will be explained using `logger.info` but the same applies to all logging methods. + + +#### `mergingObject` (Object) + +An object can optionally be supplied as the first parameter. Each enumerable key and value +of the `mergingObject` is copied in to the JSON log line. ```js -var pino = require('pino') -var log = pino({level: 'myLevel', levelVal: 35}) -log.myLevel('a message') +logger.info({MIX: {IN: true}}) +// {"level":30,"time":1531254555820,"pid":55956,"hostname":"x","MIX":{"IN":true},"v":1} ``` -The level is set to the custom level on construction, i.e. `log.level` does not -need to be set. + +#### `message` (String) - -## .levelVal +A `message` string can optionally be supplied as the first parameter, or +as the second parameter after supplying a `mergingObject`. + +By default, the contents of the `message` parameter will be merged into the +JSON log line under the `msg` key: -### Example: ```js -if (logger.levelVal === 30) { - console.log('logger level is `info`') -} +logger.info('hello world') +// {"level":30,"time":1531257112193,"msg":"hello world","pid":55956,"hostname":"x","v":1} ``` -### Discussion: -Returns the integer value for the logger instance's logging level. +The `message` parameter takes precedence over the `mergedObject`. +That is, if a `mergedObject` contains a `msg` property, and a `message` parameter +is supplied in addition, the `msg` property in the output log will be the value of +the `message` parameter not the value of the `msg` property on the `mergedObject`. - -## .on('level-change', fn) +The `messageKey` option can be used at instantiation time to change the namespace +from `msg` to another string as preferred. + +The `message` string may contain a printf style string with support for +the following placeholders: + +* `%s` – string placeholder +* `%d` – digit placeholder) +* `%O`, `%o` and `%j` – object placeholder + +Values supplied as additional arguments to the logger method will +then be interpolated accordingly. + +* See [`messageKey` pino option](#opt-messageKey) +* See [`...interpolationValues` log method parameter](#interpolatedValues) + + +#### `...interpolationValues` (Any) + +All arguments supplied after `message` are serialized and interpolated according +to any supplied printf-style placeholders (`%s`, `%d`, `%o`|`%O`|`%j`) +or else concatenated together with the `message` string to form the final +output `msg` value for the JSON log line. -### Example: ```js -var listener = function (lvl, val, prevLvl, prevVal) { - console.log(lvl, val, prevLvl, prevVal) -} -logger.on('level-change', listener) -logger.level = 'trace' // trigger console message -logger.removeListener('level-change', listener) -logger.level = 'info' // no message, since listener was removed +logger.info('hello', 'world') +// {"level":30,"time":1531257618044,"msg":"hello world","pid":55956,"hostname":"x","v":1} +``` + +```js +logger.info('hello', {worldly: 1}) +// {"level":30,"time":1531257797727,"msg":"hello {\"worldly\":1}","pid":55956,"hostname":"x","v":1} ``` -### Discussion: -Registers a listener function that is triggered when the level is changed. +```js +logger.info('%o hello', {worldly: 1}) +// {"level":30,"time":1531257826880,"msg":"{\"worldly\":1} hello","pid":55956,"hostname":"x","v":1} +``` + +* See [`message` log method parameter](#message) + + +### `logger.trace([mergingObject], [message], [...interpolationValues])` + +Write a `'trace'` level log, if the configured [`level`](#level) allows for it. -The listener is passed four arguments: `levelLabel`, `levelValue`, -`previousLevelLabel`, `previousLevelValue`. +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) -**Note:** When browserified, this functionality will only be available if the -`events` module has been required elsewhere (e.g. if you're using streams -in the browser). This allows for a trade-off between bundle size and functionality. + +### `logger.debug([mergingObject], [message], [...interpolationValues])` + +Write a `'debug'` level log, if the configured `level` allows for it. + +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) + + +### `logger.info([mergingObject], [message], [...interpolationValues])` + +Write an `'info'` level log, if the configured `level` allows for it. - -## .levels.values +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) + + +### `logger.warn([mergingObject], [message], [...interpolationValues])` + +Write a `'warn'` level log, if the configured `level` allows for it. + +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) + + +### `logger.error([mergingObject], [message], [...interpolationValues])` + +Write a `'error'` level log, if the configured `level` allows for it. + +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) + + +### `logger.fatal([mergingObject], [message], [...interpolationValues])` + +Write a `'fatal'` level log, if the configured `level` allows for it. + +* See [`mergingObject` log method parameter](#mergingObject) +* See [`message` log method parameter](#message) +* See [`...interpolationValues` log method parameter](#interpolationValues) + + + +### `logger.child(bindings) => logger` + +The `logger.child` method allows for the creation of stateful loggers, +where key-value pairs can be pinned to a logger causing them to be output +on every log line. + +Child loggers use the same output stream as the parent and inherit +the current log level of the parent at the time they are spawned. + +The log level of a child is mutable. It can be set independently +of the parent either by setting the [`level`](#level) accessor after creating +the child logger or using the reserved [`bindings.level`](#bindings-level) key. + +#### `bindings` (Object) + +An object of key-value pairs to include in every log line output +via the returned child logger. -### Example: ```js -pino.levels.values.error === 50 // true +const child = logger.child({ MIX: {IN: 'always'} }) +child.info('hello') +// {"level":30,"time":1531258616689,"msg":"hello","pid":64849,"hostname":"x","MIX":{"IN":"always"},"v":1} +child.info('child!') +// {"level":30,"time":1531258617401,"msg":"child!","pid":64849,"hostname":"x","MIX":{"IN":"always"},"v":1} ``` -### Discussion: -Returns the mappings of level names to their respective internal number -representation. This property is available as a static property or as an -instance property. +The `bindings` object may contain any key except for reserved configuration keys `level` and `serializers`. + +##### `bindings.level` (String) - -## .levels.labels +If a `level` property is present in the `bindings` object passed to `logger.child` +it will override the child logger level. -### Example: ```js -pino.levels.labels[50] === 'error' // true +const logger = pino() +logger.debug('nope') // will not log, since default level is info +const child = logger.child({foo: 'bar', level: 'debug'}) +child.debug('debug!') // will log as the `level` property set the level to debug ``` -### Discussion: -Returns the mappings of level internal level numbers to their string -representations. This property is available as a static property or as an -instance property. +##### `bindings.serializers` (Object) - -## .isLevelEnabled(logLevel) +Child loggers inherit the [serializers](#serializers-opt) from the parent logger. + +Setting the `serializers` key of the `bindings` object will override +any configured parent serializers. -### Example: ```js -if (logger.isLevelEnabled('debug')) logger.debug('conditional log') +const logger = require('pino')() +logger.info({test: 'will appear'}) +// {"level":30,"time":1531259759482,"pid":67930,"hostname":"x","test":"will appear","v":1} +const child = logger.child({serializers: {test: () => `child-only serializer`}}) +child.info({test: 'will be overwritten'}) +// {"level":30,"time":1531259784008,"pid":67930,"hostname":"x","test":"child-only serializer","v":1} ``` -### Discussion: -A utility method for determining if a given log level will write to the output -stream. +* See [`serializers` option](#opt-serializers) +* See [pino.stdSerializers](#pino-stdSerializers) - -## .LOG_VERSION + +### `logger.flush()` -### Discussion: -Read only. Holds the current log format version (as output in the `v` -property of each log record). This property is available as a static property -or as an instance property. +Flushes the content of the buffer when using a `pino.extreme` destination. - -## .stdSerializers +It has no effect if extreme mode is not enabled. + +* See [`pino.extreme`](#pino-extreme) +* See [Extreme mode ⇗](extreme.md) -Available as a static property, the `stdSerializers` provide functions for -serializing objects common to many projects. The serializers are directly -imported from [pino-std-serializers](https://github.com/pinojs/pino-std-serializers). + +### `logger.level` (String) [Getter/Setter] + +Set this property to the desired logging level. + +The core levels and their values are as follows: + +| | +|:-------------------------------------------------------------------:| +| **Level:** | trace | debug | info | warn | error | fatal | silent | +| **Value:** | 10 | 20 | 30 | 40 | 50 | 60 | Infinity | + +The logging level is a *minimum* level based on the associated value of that level. + +For instance if `logger.level` is `info` *(30)* then `info` *(30)*, `warn` *(40)*, `error` *(50)* and `fatal` *(60)* log methods will be enabled but the `trace` *(10)* and `debug` *(20)* methods, being less than 30, will not. - -### .req +The `silent` logging level is a specialized level which will disable all logging, +there is no `silent` log method. -Generates a JSONifiable object from the HTTP `request` object passed to -the `createServer` callback of Node's HTTP server. + +### `logger.isLevelEnabled(level)` + +A utility method for determining if a given log level will write to the destination. + +#### `level` (String) -It returns an object in the form: +The given level to check against: ```js -{ - pid: 93535, - hostname: 'your host', - level: 30, - msg: 'my request', - time: '2016-03-07T12:21:48.766Z', - v: 0, - req: { - method: 'GET', - url: '/', - headers: { - host: 'localhost:50201', - connection: 'close' - }, - remoteAddress: '::ffff:127.0.0.1', - remotePort: 50202 - } -} +if (logger.isLevelEnabled('debug')) logger.debug('conditional log') ``` - -### .res + +### `logger.addLevel(levelLabel, levelValue) => Boolean` -Generates a JSONifiable object from the HTTP `response` object passed to -the `createServer` callback of Node's HTTP server. +Defines a new level on the logger instance. -It returns an object in the form: +Returns `true` on success or `false` if there was a conflict (level name or +value already exist). ```js -{ - pid: 93581, - hostname: 'myhost', - level: 30, - msg: 'my response', - time: '2016-03-07T12:23:18.041Z', - v: 0, - res: { - statusCode: 200, - header: 'HTTP/1.1 200 OK\r\nDate: Mon, 07 Mar 2016 12:23:18 GMT\r\nConnection: close\r\nContent-Length: 5\r\n\r\n' - } -} +logger.addLevel('myLevel', 35) +logger.myLevel('a message') +// {"level":35,"time":1531261498686,"msg":"a message","pid":67930,"hostname":"x","v":1} ``` - -### .err +When using this method, the current level of the logger instance does not change. +To do so, use the [loggerlevel](#level) property after adding the custom level. + +* See [`logger.level`](#level) + +#### `levelLabel` (String) + +Defines the method name of the new level. + +* See [`logger.level`](#level) + +#### `levelValue` (Number) + +Defines the associated minimum threshold value for the level, and +therefore where it sits in order of priority among other levels. + +* See [`logger.level`](#level) -Serializes an `Error` object if passed in as an property. + +### `logger.levelVal` (Number) [Getter] + +Supplies the integer value for the current logging level. ```js -{ - "pid": 40510, - "hostname": "MBP-di-Matteo", - "level": 50, - "msg": "an error", - "time": 1459433282301, - "v": 1, - "type": "Error", - "stack": "Error: an error\n at Object. (/Users/matteo/Repositories/pino/example.js:16:7)\n at Module._compile (module.js:435:26)\n at Object.Module._extensions..js (module.js:442:10)\n at Module.load (module.js:356:32)\n at Function.Module._load (module.js:313:12)\n at Function.Module.runMain (module.js:467:10)\n at startup (node.js:136:18)\n at node.js:963:3" +if (logger.levelVal === 30) { + console.log('logger level is `info`') } ``` - -## .wrapRequestSerializer + +### `logger.levels` (Object) -Wraps the standard request serializer such that custom serializers can use -the newly serilized request. An example of using this function can be found -in the [pino-http][https://github.com/pinojs/pino-http] module. +Levels are mapped to values to determine the minimum threshold that a +logging method should be enabled at (see [`logger.level`](#level)). - -## .wrapResponseSerializer +The `logger.levels` property holds the mappings between levels and values, +and vice versa. -Wraps the standard response serializer such that custom serializers can use -the newly serilized response. An example of using this function can be found -in the [pino-http][https://github.com/pinojs/pino-http] module. +```sh +$ node -p "require('pino')().levels" +``` - -## .stdTimeFunctions +```js +{ labels: + { '10': 'trace', + '20': 'debug', + '30': 'info', + '40': 'warn', + '50': 'error', + '60': 'fatal' }, + values: + { fatal: 60, error: 50, warn: 40, info: 30, debug: 20, trace: 10 } } +``` + +* See [`logger.level`](#level) + + +## Event: 'level-change' + +The logger instance is also an [`EventEmitter ⇗`](https://nodejs.org/dist/latest/docs/api/events.html#events_class_eventemitter) -Available as a static property, the `stdTimeFunctions` provide functions for -generating the timestamp property in the log output. You can set the `timestamp` -option during initialization to one of these functions to adjust the output -format. Alternatively, you can specify your own time function. +A listener function can be attached to a logger via the `level-change` event -A time function must synchronously return a string that would be a valid -component of a JSON string. For example, the default function returns -a string like `,"time":1493426328206`. +The listener is passed four arguments: - -### .epochTime +* `levelLabel` – the new level string, e.g `trace` +* `levelValue` – the new level number, e.g `10` +* `previousLevelLabel` – the prior level string, e.g `info` +* `previousLevelValue` – the prior level numbebr, e.g `30` -The default time function for Pino. Returns a string like `,"time":1493426328206`. +```js +const logger = require('pino')() +logger.on('level-change', (lvl, val, prevLvl, prevVal) => { + console.log('%s (%d) was changed to %s (%d)', lvl, val, prevLvl, prevVal) +}) +logger.level = 'trace' // trigger event +``` + + +## `logger.version` (String) + +Exposes the Pino package version. Also available on the exported `pino` function. - -### .unixTime +* See [`pino.version`](#pino-version) -Returns a unix time in seconds, like `,"time":1493426328`. + +## `logger.LOG_VERSION` (Number) + +Holds the current log format version as output in the `v` property of each log record. +Also available on the exported `pino` function. - -### .nullTime +* See [`pino.LOG_VERSION`](#pino-LOG_VERSION) -Returns an empty string. This function is used when the `timestamp` option -is set to `false`. +## Statics - -# .destination(dest?) + +### `pino.destination([dest]) => SonicBoom` Create a pino destination. It returns a stream-like object with significantly more throughput than a @@ -635,12 +596,11 @@ The default `stream` is a destination. `pino.destination()` is implemented on [`sonic-boom`](https://github.com/mcollina/sonic-boom). - -# .extreme(dest?) + +### `pino.extreme([dest]) => SonicBoom` Create an extreme mode destination. This yields an additional 60% performance boost. There are trade-offs that should be understood before usage. -See [Extreme mode explained](extreme.md). ```js const pino = require('pino') @@ -651,34 +611,56 @@ const logger2 = pino(pino.extreme()) `dest` can be either a file or a file descriptor. If it is omitted, it will be `process.stdout.fd`. -`pino.extreme()` is implemented on [`sonic-boom`](https://github.com/mcollina/sonic-boom). +`pino.extreme()` is implemented with the [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) +module. - -# Metadata +* See [Extreme mode ⇗](extreme.md). +* See [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) -A destination stream can have a property `stream[Symbol.for('needsMetadata')] = true` -to indicate that for every log line written, the following properties of the stream -should be set: + +### `pino.stdSerializers` (Object) -* the last logging level as `stream.lastLevel` -* the last logging message as `stream.lastMsg` -* the last logging object as `stream.lastObj` -* the last time as `stream.lastTime`, which will be the partial string returned - by the time function. -* the last logger instance as `stream.lastLogger` (to support child - loggers) +Tthe `pino.stdSerializers` object provides functions for serializing objects common to many projects. The serializers are directly imported from [pino-std-serializers](https://github.com/pinojs/pino-std-serializers). -## Example +* See [pino-std-serializers ⇗](https://github.com/pinojs/pino-std-serializers) -```js -var instance = pino({}, { - [Symbol.for('needsMetadata')]: true, - write: function (chunk) { - console.log('lastLevel', this.lastLevel) - console.log('lastMsg', this.lastMsg) - console.log('lastObj', this.lastObj) - console.log('lastLogger', this.lastLogger) - console.log('line', chunk) - } -}) -``` + +### `pino.stdTimeFunctions` (Object) + +The [`timestamp`](#opt-timestamp) option can accept a function which determines the +`timestamp` value in a log line. + +The `pino.stdTimeFunctions` object provides a very small set of common functions for generating the +`timestamp` property. These consist of the following + +* `pino.stdTimeFunctions.epochTime`: Milliseconds since Unix epoch (Default) +* `pino.stdTimeFunctions.unixTime`: Seconds since Unix epoch +* `pino.stdTimeFunctions.nullTime`: Clears timestamp property (Used when `timestamp: false`) + +* See [`timestamp` option](#opt-timestamp) + + +### `pino.symbols` (Object) + +For integration purposes with ecosystem and third party libraries `pino.symbols` +exposes the symbols used to hold non-public state and methods on the logger instance. + +Access to the symbols allows logger state to be adjusted, and methods to be overriden or +proxied for performant integration where necessary. + +The `pino.symbols` object is intended for library implementers and shouldn't be utilized +for general use. + + +### `pino.version` (String) + +Exposes the Pino package version. Also available on the logger instance. + +* See [`logger.version`](#version) + + +### `pino.LOG_VERSION` (Number) + +Holds the current log format version as output in the `v` property of each log record. Also available on the logger instance. + +* See [`logger.LOG_VERSION`](#log_version) \ No newline at end of file diff --git a/docs/benchmarks.md b/docs/benchmarks.md new file mode 100644 index 000000000..50ce1cdc7 --- /dev/null +++ b/docs/benchmarks.md @@ -0,0 +1,58 @@ +# Benchmarks + +`pino.info('hello world')`: + +``` +BASIC benchmark averages +Bunyan average: 549.042ms +Winston average: 467.873ms +Bole average: 201.529ms +Debug average: 253.724ms +LogLevel average: 282.653ms +Pino average: 188.956ms +PinoExtreme average: 108.809ms +``` + +`pino.info({'hello': 'world'})`: + +``` +OBJECT benchmark averages +BunyanObj average: 564.363ms +WinstonObj average: 464.824ms +BoleObj average: 230.220ms +LogLevelObject average: 474.857ms +PinoObj average: 201.442ms +PinoUnsafeObj average: 202.687ms +PinoExtremeObj average: 108.689ms +PinoUnsafeExtremeObj average: 106.718ms +``` + +`pino.info(aBigDeeplyNestedObject)`: + +``` +DEEPOBJECT benchmark averages +BunyanDeepObj average: 5293.279ms +WinstonDeepObj average: 9020.292ms +BoleDeepObj average: 9169.043ms +LogLevelDeepObj average: 15260.917ms +PinoDeepObj average: 8467.807ms +PinoUnsafeDeepObj average: 6159.227ms +PinoExtremeDeepObj average: 8354.557ms +PinoUnsafeExtremeDeepObj average: 6214.073ms +``` + +`pino.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})`: + +``` +BunyanInterpolateExtra average: 778.408ms +WinstonInterpolateExtra average: 627.956ms +BoleInterpolateExtra average: 429.757ms +PinoInterpolateExtra average: 316.043ms +PinoUnsafeInterpolateExtra average: 316.809ms +PinoExtremeInterpolateExtra average: 218.468ms +PinoUnsafeExtremeInterpolateExtra average: 215.040ms +``` + +For a fair comparison, [LogLevel](http://npm.im/loglevel) was extended +to include a timestamp and [bole](http://npm.im/bole) had +`fastTime` mode switched on. \ No newline at end of file diff --git a/docs/browser.md b/docs/browser.md new file mode 100644 index 000000000..e15be6974 --- /dev/null +++ b/docs/browser.md @@ -0,0 +1,199 @@ +# Browser API + +Pino is compatible with [`browserify`](http://npm.im/browserify) for browser side usage: + +This can be useful with isomorphic/universal JavaScript code. + +By default, in the browser, +`pino` uses corresponding [Log4j](https://en.wikipedia.org/wiki/Log4j) `console` methods (`console.error`, `console.warn`, `console.info`, `console.debug`, `console.trace`) and uses `console.error` for any `fatal` level logs. + +## Options + +Pino can be passed a `browser` object in the options object, +which can have the following properties: + +### `asObject` (Boolean) + +```js +const pino = require('pino')({browser: {asObject: true}}) +``` + +The `asObject` option will create a pino-like log object instead of +passing all arguments to a console method, for instance: + +```js +pino.info('hi') // creates and logs {msg: 'hi', level: 30, time: } +``` + +When `write` is set, `asObject` will always be `true`. + +### `write` (Function | Object) + +Instead of passing log messages to `console.log` they can be passed to +a supplied function. + +If `write` is set to a single function, all logging objects are passed +to this function. + +```js +const pino = require('pino')({ + browser: { + write: (o) => { + // do something with o + } + } +}) +``` + +If `write` is an object, it can have methods that correspond to the +levels. When a message is logged at a given level, the corresponding +method is called. If a method isn't present, the logging falls back +to using the `console`. + + +```js +const pino = require('pino')({ + browser: { + write: { + info: function (o) { + //process info log object + }, + error: function (o) { + //process error log object + } + } + } +}) +``` + +### `serialize`: (Boolean | Array) + +The serializers provided to `pino` are ignored by default in the browser, including +the standard serializers provided with Pino. Since the default destination for log +messages is the console, values such as `Error` objects are enhanced for inspection, +which they otherwise wouldn't be if the Error serializer was enabled. + +We can turn all serializers on, + +```js +const pino = require('pino')({ + browser: { + serialize: true + } +}) +``` + +Or we can selectively enable them via an array: + +```js +const pino = require('pino')({ + serializers: { + custom: myCustomSerializer, + another: anotherSerializer + }, + browser: { + serialize: ['custom'] + } +}) +// following will apply myCustomSerializer to the custom property, +// but will not apply anotherSerizlier to another key +pino.info({custom: 'a', another: 'b'}) +``` + +When `serialize` is `true` the standard error serializer is also enabled (see https://github.com/pinojs/pino/blob/master/docs/api.md#stdSerializers). +This is a global serializer which will apply to any `Error` objects passed to the logger methods. + +If `serialize` is an array the standard error serializer is also automatically enabled, it can +be explicitly disabled by including a string in the serialize array: `!stdSerializers.err`, like so: + +```js +const pino = require('pino')({ + serializers: { + custom: myCustomSerializer, + another: anotherSerializer + }, + browser: { + serialize: ['!stdSerializers.err', 'custom'] //will not serialize Errors, will serialize `custom` keys + } +}) +``` + +The `serialize` array also applies to any child logger serializers (see https://github.com/pinojs/pino/blob/master/docs/api.md#discussion-2 +for how to set child-bound serializers). + +Unlike server pino the serializers apply to every object passed to the logger method, +if the `asObject` option is `true`, this results in the serializers applying to the +first object (as in server pino). + +For more info on serializers see https://github.com/pinojs/pino/blob/master/docs/api.md#parameters. + +### `transmit` (Object) + +An object with `send` and `level` properties. + +The `transmit.level` property specifies the minimum level (inclusive) of when the `send` function +should be called, if not supplied the `send` function be called based on the main logging `level` +(set via `options.level`, defaulting to `info`). + +The `transmit` object must have a `send` function which will be called after +writing the log message. The `send` function is passed the level of the log +message and a `logEvent` object. + +The `logEvent` object is a data structure representing a log message, it represents +the arguments passed to a logger statement, the level +at which they were logged and the heirarchy of child bindings. + +The `logEvent` format is structured like so: + +```js +{ + ts = Number, + messages = Array, + bindings = Array, + level: { label = String, value = Number} +} +``` + +The `ts` property is a unix epoch timestamp in milliseconds, the time is taken from the moment the +logger method is called. + +The `messages` array is all arguments passed to logger method, (for instance `logger.info('a', 'b', 'c')` +would result in `messages` array `['a', 'b', 'c']`). + +The `bindings` array represents each child logger (if any), and the relevant bindings. +For instance given `logger.child({a: 1}).child({b: 2}).info({c: 3})`, the bindings array +would hold `[{a: 1}, {b: 2}]` and the `messages` array would be `[{c: 3}]`. The `bindings` +are ordered according to their position in the child logger hierarchy, with the lowest index +being the top of the hierarchy. + +By default serializers are not applied to log output in the browser, but they will *always* be +applied to `messages` and `bindings` in the `logEvent` object. This allows us to ensure a consistent +format for all values between server and client. + +The `level` holds the label (for instance `info`), and the corresponding numerical value +(for instance `30`). This could be important in cases where client side level values and +labels differ from server side. + +The point of the `send` function is to remotely record log messages: + +```js +const pino = require('pino')({ + browser: { + transmit: { + level: 'warn', + send: function (level, logEvent) { + if (level === 'warn') { + // maybe send the logEvent to a separate endpoint + // or maybe analyse the messages further before sending + } + // we could also use the `logEvent.level.value` property to determine + // numerical value + if (logEvent.level.value >= 50) { // covers error and fatal + + // send the logEvent somewhere + } + } + } + } +}) +``` diff --git a/docs/child-loggers.md b/docs/child-loggers.md new file mode 100644 index 000000000..3dd5af357 --- /dev/null +++ b/docs/child-loggers.md @@ -0,0 +1,95 @@ +# Child loggers + +Let's assume we want to have `"module":"foo"` added to every log within a +module `foo.js`. + +To accomplish this, simply use a child logger: + +```js +'use strict' +// imports a pino logger instance of `require('pino')()` +const parentLogger = require('./lib/logger') +const log = parentLogger.child({module: 'foo'}) + +function doSomething () { + log.info('doSomething invoked') +} + +module.exports = { + doSomething +} +``` + +## Cost of child logging + +Child logger creation is fast: + +``` +benchBunyanCreation*10000: 564.514ms +benchBoleCreation*10000: 283.276ms +benchPinoCreation*10000: 258.745ms +benchPinoExtremeCreation*10000: 150.506ms +``` + +Logging through a child logger has little performance penalty: + +``` +benchBunyanChild*10000: 556.275ms +benchBoleChild*10000: 288.124ms +benchPinoChild*10000: 231.695ms +benchPinoExtremeChild*10000: 122.117ms +``` + +Logging via the child logger of a child logger also has negligible overhead: + +``` +benchBunyanChildChild*10000: 559.082ms +benchPinoChildChild*10000: 229.264ms +benchPinoExtremeChildChild*10000: 127.753ms +``` + +## Duplicate keys caveat + +It's possible for naming conflicts to arise between child loggers and +children of child loggers. + +This isn't as bad as it sounds, even if you do use the same keys between +parent and child loggers Pino resolves the conflict in the sanest way. + +For example, consider the following: + +```js +const pino = require('pino') +pino(pino.destination('./my-log')) + .child({a: 'property'}) + .child({a: 'prop'}) + .info('howdy') +``` + +```sh +$ cat my-log +{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":1459534114473,"a":"property","a":"prop","v":1} +``` + +Notice how there's two key's named `a` in the JSON output. The sub-childs properties +appear after the parent child properties. + +At some point the logs will most likely be processed (for instance with a [transport](transports.md)), +and this generally involves parsing. `JSON.parse` will return an object where the conflicting +namespace holds the final value assigned to it: + +```sh +$ cat my-log | node -e "process.stdin.once('data', (line) => console.log(JSON.stringify(JSON.parse(line))))" +{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":"2016-04-01T18:08:34.473Z","a":"prop","v":1} +``` + +Ultimately the conflict is resolved by taking the last value, which aligns with Bunyans child logging +behavior. + +There may be cases where this edge case becomes problematic if a JSON parser with alternative behavior +is used to process the logs. It's recommended to be conscious of namespace conflicts with child loggers, +in light of an expected log processing approach. + +One of Pino's performance tricks is to avoid building objects and stringifying +them, so we're building strings instead. This is why duplicate keys between +parents and children will end up in log output. \ No newline at end of file diff --git a/docs/ecosystem.md b/docs/ecosystem.md index bff2bf6f5..709925384 100644 --- a/docs/ecosystem.md +++ b/docs/ecosystem.md @@ -1,14 +1,13 @@ # Pino Ecosystem -Are you looking for a transport to accomplish some sort of log processing? -Or maybe a transport to make logs easier to read? This list will help you -with that endeavor. If you cannot find what you are looking for here, write -it and submit a PR adding it to the list 😃. +This is a list of ecosystem modules that integrate with `pino`. Modules listed under [Core](#core) are maintained by the Pino team. Modules listed under [Community](#community) are maintained by independent community members. +Please send a PR to add new modules! + ## Core diff --git a/docs/faq.md b/docs/faq.md deleted file mode 100644 index ea3195372..000000000 --- a/docs/faq.md +++ /dev/null @@ -1,260 +0,0 @@ -# Frequently Asked Questions - -+ [How do I rotate log files?](#rotate) -+ [How do I save to multiple files?](#multiple) -+ [How do I filter logs?](#filter-logs) -+ [How do I automatically add something to every log?](#auto-add) -+ [How do I stop `name` from being overwritten?](#dupe-props) -+ [How do I use a transport with systemd?](#transport-systemd) -+ [How do I make the level show as the name instead of the value?](#level-string) -+ [How do I use Pino with debug?](#debug) -+ [How do I use Pino with Express?](#express) -+ [How do I use Pino with Hapi?](#hapi) -+ [How do I use Pino with Restify?](#restify) -+ [How do I use Pino with Koa?](#koa) - - -## How do I rotate log files? - -Use a separate tool for log rotation: -We recommend [logrotate](https://github.com/logrotate/logrotate). -Consider we output our logs to `/var/log/myapp.log` like so: - -``` -> node server.js > /var/log/myapp.log -``` - -We would rotate our log files with logrotate, by adding the following to `/etc/logrotate.d/myapp`: - -``` -/var/log/myapp.log { - su root - daily - rotate 7 - delaycompress - compress - notifempty - missingok - copytruncate -} -``` - - -## How do I save to multiple files? - -Let's assume you want to store all error messages to a separate log file: - -Install [pino-tee](http://npm.im/pino-tee) with: - -```bash -npm i pino-tee -g -``` - -The following writes the log output of `app.js` to `./all-logs`, while -writing only warnings and errors to `./warn-log: - -```bash -node app.js | pino-tee warn ./warn-logs > ./all-logs -``` - - -## How do I filter logs? -The Pino authors are firm believers in using common, pre-existing, system -utilities. Thus, some recommendations for this are: - -1. Use [`grep`](https://linux.die.net/man/1/grep): - ```sh - $ # View all "INFO" level logs - $ node your_app.js | grep '"level":30' - ``` -1. Use [`jq`](https://stedolan.github.io/jq/): - ```sh - $ # View all "ERROR" level logs - $ node node_app.js | jq 'select(.level == 50)' - ``` - - -## How do I automatically add something to every log? -Let's assume you want to have `"module":"foo"` added to every log within a -module `foo.js`. To accomplish this, simply use a child logger: - -```js -'use strict' -// exports an instance of `require('pino')()` -const log = require('./logger').child({module: 'foo'}) - -function doSomething () { - log.info('doSomething invoked') -} - -module.exports = { - doSomething -} -``` - - -## How do I use a transport with systemd? -`systemd` makes it complicated to use pipes in services. One method for overcoming -this challenge is to use a subshell: - -``` -ExecStart=/bin/sh -c '/path/to/node your_app.js | pino-transport' -``` - - -## How do I stop `name` from being overwritten? -See the documentation on [duplicate keys](https://github.com/pinojs/pino#duplicate-keys). - - -## How do I make the level show as the name instead of the string? -Pino log lines are meant to be parseable. Thus, there isn't any built-in option -to change the level from the integer value to the string name. However, there -are a couple of options: - -1. If the only change desired is the name, i.e. you want to retain the newline -delimited JSON, then you can use a transport to make the change. One such -transport is [`pino-text-level-transport`](https://npm.im/pino-text-level-transport). -1. Use a prettifier like [`pino-pretty`](https://npm.im/pino-pretty) to make -the logs human friendly. - - -## How do I use Pino with debug? -Capture debug logs in JSON format, at 10x-20x the speed: -The popular [`debug`](http://npm.im/debug) which -used in many modules accross the ecosystem. - -The [`pino-debug`](http://github.com/pinojs/pino-debug) -can captures calls to the `debug` loggers and run them -through `pino` instead. This results in a 10x (20x in extreme mode) -performance improvement, while logging out more information, in the -usual JSON format. - -The quick start way to enable this is simply to install [`pino-debug`](http://github.com/pinojs/pino-debug) -and preload it with the `-r` flag, enabling any `debug` logs with the -`DEBUG` environment variable: - -```sh -$ npm i --save pino-debug -$ DEBUG=* node -r pino-debug app.js -``` - -[`pino-debug`](http://github.com/pinojs/pino-debug) also offers fine grain control to map specific `debug` -namespaces to `pino` log levels. See [`pino-debug`](http://github.com/pinojs/pino-debug) -for more. - - - -## How do I use Pino with Express? - -```sh -npm install --save express-pino-logger -``` - -```js -var app = require('express')() -var pino = require('express-pino-logger')() - -app.use(pino) - -app.get('/', function (req, res) { - req.log.info('something') - res.send('hello world') -}) - -app.listen(3000) -``` - -See the [express-pino-logger readme](http://npm.im/express-pino-logger) for more info. - - -## How do I use Pino with Hapi? - -```sh -npm install --save hapi-pino -``` - -```js -'use strict' - -const Hapi = require('hapi') - -const server = new Hapi.Server() -server.connection({ port: 3000 }) - -server.route({ - method: 'GET', - path: '/', - handler: function (request, reply) { - request.logger.info('In handler %s', request.path) - return reply('hello world') - } -}) - -server.register(require('hapi-pino'), (err) => { - if (err) { - console.error(err) - process.exit(1) - } - - server.logger().info('another way for accessing it') - - // Start the server - server.start((err) => { - if (err) { - console.error(err) - process.exit(1) - } - }) -}) -``` - -See the [hapi-pino readme](http://npm.im/hapi-pino) for more info. - - -## How do I use Pino with Restify? - -```sh -npm install --save restify-pino-logger -``` - -```js -var server = require('restify').createServer({name: 'server'}) -var pino = require('restify-pino-logger')() - -server.use(pino) - -server.get('/', function (req, res) { - req.log.info('something') - res.send('hello world') -}) - -server.listen(3000) -``` - -See the [restify-pino-logger readme](http://npm.im/restify-pino-logger) for more info. - - -## How do I use Pino with koa? - -### Koa - -```sh -npm install --save koa-pino-logger -``` - -```js -var Koa = require('koa') -var app = new Koa() -var pino = require('koa-pino-logger')() - -app.use(pino) - -app.use((ctx) => { - ctx.log.info('something else') - ctx.body = 'hello world' -}) - -app.listen(3000) -``` - -See the [koa-pino-logger readme](https://github.com/pinojs/koa-pino-logger) for more info. \ No newline at end of file diff --git a/docs/help.md b/docs/help.md new file mode 100644 index 000000000..72415e4b4 --- /dev/null +++ b/docs/help.md @@ -0,0 +1,119 @@ +# Help + +* [Log rotation](#rotate) +* [Saving to multiple files](#multiple) +* [Log Filtering](#filter-logs) +* [How do I use a transport with systemd?](#transport-systemd) +* [Duplicate keys](#dupe-keys) +* [Log levels as labels instead of numbers](#level-string) +* [Pino with `debug`](#debug) + + +## Log rotation + +Use a separate tool for log rotation: +We recommend [logrotate](https://github.com/logrotate/logrotate). +Consider we output our logs to `/var/log/myapp.log` like so: + +``` +> node server.js > /var/log/myapp.log +``` + +We would rotate our log files with logrotate, by adding the following to `/etc/logrotate.d/myapp`: + +``` +/var/log/myapp.log { + su root + daily + rotate 7 + delaycompress + compress + notifempty + missingok + copytruncate +} +``` + + +## Saving to multiple files + +Let's assume you want to store all error messages to a separate log file: + +Install [pino-tee](http://npm.im/pino-tee) with: + +```bash +npm i pino-tee -g +``` + +The following writes the log output of `app.js` to `./all-logs`, while +writing only warnings and errors to `./warn-log: + +```bash +node app.js | pino-tee warn ./warn-logs > ./all-logs +``` + + +## Log Filtering +The Pino authors are firm believers in using common, pre-existing, system +utilities. Thus, some recommendations for this are: + +1. Use [`grep`](https://linux.die.net/man/1/grep): + ```sh + $ # View all "INFO" level logs + $ node your_app.js | grep '"level":30' + ``` +1. Use [`jq`](https://stedolan.github.io/jq/): + ```sh + $ # View all "ERROR" level logs + $ node node_app.js | jq 'select(.level == 50)' + ``` + + +## How do I use a transport with systemd? +`systemd` makes it complicated to use pipes in services. One method for overcoming +this challenge is to use a subshell: + +``` +ExecStart=/bin/sh -c '/path/to/node your_app.js | pino-transport' +``` + + +## How Pino handles duplicate keys +See the documentation on [duplicate keys](https://github.com/pinojs/pino#duplicate-keys). + + +## Log levels as labels instead of numbers +Pino log lines are meant to be parseable. Thus, there isn't any built-in option +to change the level from the integer value to the string name. However, there +are a couple of options: + +1. If the only change desired is the name, i.e. you want to retain the newline +delimited JSON, then you can use a transport to make the change. One such +transport is [`pino-text-level-transport`](https://npm.im/pino-text-level-transport). +1. Use a prettifier like [`pino-pretty`](https://npm.im/pino-pretty) to make +the logs human friendly. + + +## Pino with `debug` +Capture debug logs in JSON format, at 10x-20x the speed: +The popular [`debug`](http://npm.im/debug) which +used in many modules accross the ecosystem. + +The [`pino-debug`](http://github.com/pinojs/pino-debug) +can captures calls to the `debug` loggers and run them +through `pino` instead. This results in a 10x (20x in extreme mode) +performance improvement, while logging out more information, in the +usual JSON format. + +The quick start way to enable this is simply to install [`pino-debug`](http://github.com/pinojs/pino-debug) +and preload it with the `-r` flag, enabling any `debug` logs with the +`DEBUG` environment variable: + +```sh +$ npm i --save pino-debug +$ DEBUG=* node -r pino-debug app.js +``` + +[`pino-debug`](http://github.com/pinojs/pino-debug) also offers fine grain control to map specific `debug` +namespaces to `pino` log levels. See [`pino-debug`](http://github.com/pinojs/pino-debug) +for more. \ No newline at end of file diff --git a/docs/transports.md b/docs/transports.md index 7cbfdec53..5fc19c5a1 100644 --- a/docs/transports.md +++ b/docs/transports.md @@ -4,11 +4,11 @@ A "transport" for Pino is some other tool into which the output of Pino is piped Consider the following example: ```js -var split = require('split2') -var pump = require('pump') -var through = require('through2') +const split = require('split2') +const pump = require('pump') +const through = require('through2') -var myTransport = through.obj(function (chunk, enc, cb) { +const myTransport = through.obj(function (chunk, enc, cb) { // do whatever you want here! console.log(chunk) cb() @@ -27,6 +27,40 @@ node my-app-which-logs-stuff-to-stdout.js | node my-transport-process.js Using transports in the same process causes unnecessary load and slows down Node's single threaded event loop. +## In-process transports + +> **Pino *does not* natively support in-process transports.** + +Pino does not support in-process transports because Node processes are +single threaded processes (ignoring some technical details). Given this +restriction, one of the methods Pino employs to achieve its speed is to +purposefully offload the handling of logs, and their ultimate destination, to +external processes so that the threading capabilities of the OS can be +used (or other CPUs). + +One consequence of this methodology is that "error" logs do not get written to +`stderr`. However, since Pino logs are in a parseable format, it is possible to +use tools like [pino-tee][pino-tee] or [jq][jq] to work with the logs. For +example, to view only logs marked as "error" logs: + +``` +$ node an-app.js | jq 'select(.level == 50)' +``` + +In short, the way Pino generates logs: + +1. Reduces the impact of logging on your application to an extremely minimal amount. +2. Gives greater flexibility in how logs are processed and stored. + +Given all of the above, Pino recommends out-of-process log processing. + +However, it is possible to wrap Pino and perform processing in-process. +For an example of this, see [pino-multi-stream][pinoms]. + +[pino-tee]: https://npm.im/pino-tee +[jq]: https://stedolan.github.io/jq/ +[pinoms]: https://npm.im/pino-multi-stream + ## Known Transports If you write a transport, let us know and we will add a link here! diff --git a/docs/web.md b/docs/web.md new file mode 100644 index 000000000..c05fb3570 --- /dev/null +++ b/docs/web.md @@ -0,0 +1,170 @@ +# Web Frameworks + +Since HTTP logging is a primary use case, Pino has first class support for the Node.js +web framework ecosystem. + ++ [Pino with Fastify](#fastify) ++ [Pino with Express](#express) ++ [Pino with Hapi](#hapi) ++ [Pino with Restify](#restify) ++ [Pino with Koa](#koa) ++ [Pino with Node core `http`](#http) + + +## Pino with Fastify + +The Fastify web framework comes bundled with Pino by default, simply set Fastify's +`logger` option to `true` and use `reply.log` for log messages that correspond +to each individual request: + +```js +const fastify = require('fastify')({ + logger: true +}) +fastify.get('/', async (request, reply) => { + reply.type('application/json').code(200) + reply.log.info('something') + return { hello: 'world' } +}) +``` + +See the [fastify documentation](https://www.npmjs.com/package/pino-http#pinohttpopts-stream) for more information. + + +## Pino with Express + +```sh +npm install --save express-pino-logger +``` + +```js +const app = require('express')() +const pino = require('express-pino-logger')() + +app.use(pino) + +app.get('/', function (req, res) { + req.log.info('something') + res.send('hello world') +}) + +app.listen(3000) +``` + +See the [express-pino-logger readme](http://npm.im/express-pino-logger) for more info. + + +## Pino with Hapi + +```sh +npm install --save hapi-pino +``` + +```js +'use strict' + +const Hapi = require('hapi') + +const server = new Hapi.Server() +server.connection({ port: 3000 }) + +server.route({ + method: 'GET', + path: '/', + handler: function (request, reply) { + request.logger.info('In handler %s', request.path) + return reply('hello world') + } +}) + +server.register(require('hapi-pino'), (err) => { + if (err) { + console.error(err) + process.exit(1) + } + + server.logger().info('another way for accessing it') + + // Start the server + server.start((err) => { + if (err) { + console.error(err) + process.exit(1) + } + }) +}) +``` + +See the [hapi-pino readme](http://npm.im/hapi-pino) for more info. + + +## Pino with Restify + +```sh +npm install --save restify-pino-logger +``` + +```js +const server = require('restify').createServer({name: 'server'}) +const pino = require('restify-pino-logger')() + +server.use(pino) + +server.get('/', function (req, res) { + req.log.info('something') + res.send('hello world') +}) + +server.listen(3000) +``` + +See the [restify-pino-logger readme](http://npm.im/restify-pino-logger) for more info. + + +## Pino with Koa + +### Koa + +```sh +npm install --save koa-pino-logger +``` + +```js +const Koa = require('koa') +const app = new Koa() +const pino = require('koa-pino-logger')() + +app.use(pino) + +app.use((ctx) => { + ctx.log.info('something else') + ctx.body = 'hello world' +}) + +app.listen(3000) +``` + +See the [koa-pino-logger readme](https://github.com/pinojs/koa-pino-logger) for more info. + + +## Pino with Node core `http` + +```sh +npm install --save pino-http +``` + +```js +const http = require('http') +const server = http.createServer(handle) +const logger = require('pino-http')() + +function handle (req, res) { + logger(req, res) + req.log.info('something else') + res.end('hello world') +} + +server.listen(3000) +``` + +See the [pino-http readme](http://npm.im/pino-http) for more info. \ No newline at end of file diff --git a/docsify/sidebar.md b/docsify/sidebar.md index 9e0aebbf1..05dc9be5a 100644 --- a/docsify/sidebar.md +++ b/docsify/sidebar.md @@ -1,27 +1,19 @@ -- [Home](/) - - [Benchmarks](/#benchmarks) - - [Browser Support](/#pino-in-the-browser) - - [Caveats](/#caveats) - - [The Team](/#the-team) -- [API](/docs/api.md) - - [Constructor](/docs/api.md#constructor) - - [Pretty](/docs/api.md#pretty) - - [Logger](/docs/api.md#logger) - - [Metadata](/docs/api.md#metadata) -- [CLI](/docs/cli.md) -- [Extreme Mode](/docs/extreme.md) -- [Transports](/docs/transports.md) -- [FAQ](/docs/faq.md) - - [Express](/docs/faq.md#Express) - - [Hapi](/docs/faq.md#Hapi) - - [Restify](/docs/faq.md#Restify) - - [Koa](/docs/faq.md#Koa) - - [debug](/docs/faq.md#debug) - - [Log Rotation](/docs/faq.md#rotate) - - [Multiple Files](/docs/faq.md#multiple) - - [Redaction](/docs/faq.md#redact) - - [Log Filtering](/docs/faq.md#filter-logs) - - [Child Loggers](#auto-add) - - [Duplicate Properties](#dupe-props) - - [Systemd](#transport-systemd) - - [Level Labels](#level-string) \ No newline at end of file +* [Readme](/) +* [API](/docs/api.md) +* [Browser API](/docs/browser.md) +* [Redaction](/docs/redaction.md) +* [Child Loggers](/docs/child-loggers.md) +* [Transports](/docs/transports.md) +* [Web Frameworks](/docs/web.md) +* [Pretty Printing](/docs/pretty.md) +* [Extreme Mode](/docs/extreme.md) +* [Ecosystem](/docs/ecosystem.md) +* [Benchmarks](/docs/benchmarks.md) +* [Help](/docs/help.md) + * [Log Rotation](/docs/help.md#rotate) + * [Multiple Files](/docs/help.md#multiple) + * [Log Filtering](/docs/help.md#filter-logs) + * [Systemd](/docs/help.md#transport-systemd) + * [Duplicate Properties](/docs/help.md#dupe-keys) + * [Level Labels](/docs/help.md#level-string) + * [debug](/docs/help.md#debug) diff --git a/index.html b/index.html index e81157af5..e195a28f5 100644 --- a/index.html +++ b/index.html @@ -5,14 +5,35 @@ Pino - Super fast, all natural JSON logger for Node.js - + +
+ diff --git a/pino-tree.png b/pino-tree.png new file mode 100644 index 0000000000000000000000000000000000000000..f517f794eb71999abf657206ddf5e00e92d99440 GIT binary patch literal 13407 zcmZvD2~?9;6X;Dyfw&^EN~tK-CV_~6D6K}(pg}Rj7%+jT2oa0ruhsHj91#2dh1*$ff3*B9dnPhj zeyZ=995Wc*f4a>BaE40j6I{O(Bm}Zi;gw&vA?5c^`*(Sw-~bjXte>ymZD61^(=@2= z)R`v<1C^!D3>17<%w#puP>>TWx!mYTu#of0X~;S2kTgs$LMvx!ko=#a?dcS`4S-Jv zs#IJGPXN%m^}*(ZAxcv+U0M2K9zg>TjtZv7EJHxcVlM$R)xrAVXM(N-iZxGz?5fuh zWcvx>chK^u=@eczAW+6gFaeVeevf@NqiY_D<^#gjb0o4a{GRjjX*!+v1Q6B@&b4JI zsB-smnn@O!-L(wa?-!ze`jv!w7XB=Bap(HUmT0S(g)EH$1av+8zPMxklp*L_(7E(b zFu@K1wYIm8+v%oq_+{cqv2r&1JSa8`hQB*Zk*$MYl4qQ;{%k~@%R=?#X%>hH`zf9Q zct1~EPU8vhL{W6(!>NwDFXoo`nxs!mgx!kCwuZ#E3Hj zVKrUJ1D+F(G+LYXzz@XD!Adz=1Er*vBC7GHaH=j!OG>2lpj4i1nP?$i4?hlz4q`rL z5VP`ROOb_mGyKT8P6Bts?}C;UNXLTh)4d6a%*g=EZdpOmVVdJgN#G6urnju1>b?Ob zW+oDTt^5uU-0nQGR`8@5MBho*Ixb-h~{Ss(fH*? zLQSqth>p2^-b;zt3Dk|=giH}w&=V~ytaMT!lv(nnp*7AqD|D{l534DbKzV-RlsNw+ z)nEmQPT(TYA_GLOVY*r-0@4Z)YV=&@-(oi60GHd@0vAmBJ4~lVsG|UTF=1tciC!yK^row?LPU9Rd zX|YD-5U70un7Kf^5Bw|-U^ZO=lemDaHc~ykiN?bQoS4gB3pA2J?7=$0cpoit0T*}JPKyREh5v2YJq+YHQydDICScFsSmgLfQ0eCsYKyapDrGm< zT}f$&m{<9E`JZ z`)v|}=@1Z~?SVN24yH4jptJop3Bhy-$c1eo#4g<*xwI4+s-P+RIuwIq6*OLfgzj<_ zrO?sPiLqHC_@R7gu$BErabY0WmG4Aa1V4(!Oyhk*kNcb8cmU)OX!ewV)NYzVLIRk^ z76MYe2~HNq@n;&}5s=DFB%MP*r-Oi8wcCj8fqnxzGz)CA%XV8y2<+-dK+5dY1myMs zf!x^=%vq=$%T-X}N1l(`6xmO%K`Y-R4kSz_-oshP{0^*HckY`YLV4X_P~HQZ!>8}^ z1B7B(IkvJrgkrLllL$gCKJDe5_&}C*vd7Q*d77y+X;z2 zWC@g6_E;ib=^}!^akP}`QiHi&pr=55ff;|7(2c)XV8gOxDa5v){F$aB{jsvix_$)z z;A|lDJtpMnJ+Fxd8tpdN%0CgzW*7$$H~^qqVeWjRD*<>Cz%+Rbz+^V)NR%f)IDmjC zb=^2(rYRCb8n~-yMkiw5o3)+S8n@3CB&@PE7Q!*9pw*qTxJn4?m|t-AQ^)4yo1@qi zpN_PE*jIM2Y;*JAiiA%E$v0PssDH2i)O0V@1qYh-m`POG{a4OesoN+ZdPZ^kht!%` zS|yklR_$iQ(2RCc?4~DTw%k7#Yn22idzerSQDItLO_y!pfbW%yAUPZ*_oQ+uR{l(2 z>3*igTE2qV1Dl5sWP%|R#T*b|n?gAeN8p(}?+h{p5_p9otx{{itmW%r^C)7^GQG%j zNP>@-(ILZ27Wu7J87+@I7@Km&yVjO?)_szu zP1x!~{x~EMMsCdhr`VoWJx%St7&B>j66(foqPb*l{EBxpgTPBJ=Fn~ika)8Dv(JWz zs_7Gie$x8L{9D+R!k^P&C1iQzAp3B}# zxg9kX5NtuWa&0g9T|bVGuX1+elddy?BN!)g0+_D*2+YBX*qCU@{AXWJ4b&TG!MuiKewFv!K^p!hRSC|_py z{%;Fs?8G;b>)|Y3EtiJ9t%tZP-80Z25?`^#KEeTI@*9vsm%IF_yL2sNdEj{Lbf7U~ zZVoO+_21_Rg0a$oGVD*&r5hnJf$ms7jN)HJpx7VoL2)dZ{JQmWNPHiAY(CJtimc|V zwgi(_hC~wdVNFM*U{LOc?=0|Ni*XxbvytB#G?GzcMuRsyE?ULjFAG(b>Q(4egUwEV0MghOYJ?W%M) z5QBRV8#V+g+N*@}x~X?sA9jZAuBOLi3%0bLp;XYeWdDmR^9U_x>|!_+pl#>nw5~5h z%l3xnVcy^=AK5k?xP%0wat|8hR=Vdc^)iNJ^A>_Duu3dl7_i8(LU!&nZvV_ztp$=(XIZP z_~K<9VFjY-iiE&(!En!SYKC*R>TUD05{MV+QNiTMj?dSKI5K_X*;16lc;L^x3aLw3 z=$gAB)UDBw!f#=4j1d<#L&(l{2LJC*5-GNb;Jg(Epjcp$KXNn^ewW zLjk@FidtR|lIj!i`9MRfr1xik`{iS_fpIN>SwA5LUjh04%)cl2vkP?s+MZ^}O%J1R zwG+(qo6Gi{rFO>^3s@T(Coz*s28iiGRR5;3S_vKBERL?yuy2nyl^xD35UH&vlO{eJ zlAi&m6JM8?Lbvu>GOs)#CTwzU86pFEMuWa+xFXD@S7iT<+_BJV=}3)6MV1DqbH`dr zN!$6U4Fc_^Ichu79wy&lmu7!<*xYW5NmMKY1Dt7bgD|Mwy1wCSoA^SYO`LaFneET6 z_h*Xn>CY(gJuzLo$w#fb8w^R%Nu-YWhdbymPU$lu29%qE9q(m|%5(zp+Wb-v%HT}g zftk}erEF62k*iiMOXXJmEKOX}U=OLIUZQd}FggR6wG#*fI8ujR{E)+NaAP#=Ng*)8 zB&vMC_#{%x?~y#xikv=7*Sd!`+{K|0v7S@KROm-M!lhDZO}tpDzd=gw73tlwox7;y z>T&E?aVn?EQ=wlAT?eVCS+#l5*=l-gc>XmUIb4a#rdkz~V|z7?ID?fIL(hG=mB)BA z@e8Z5B6u$j`S2Xu3$8SkG{ce^>f)5_qs*> zj?YzcmY|=HR+i53enYD189vj!pCWAECy$y2sGE87a?61KdxLFWH~*v->m=|=`hN(_ z);i5m%iog(Tx0UQwVNh&+tbNU?U=)0!sQ&gdnxI(V6$vJchHKG4i2;tDRjW7ds30j zJzO|nTJJ4*zVYPvSvVmTUOsHA7*&vVWa9@E=a8w5cpoLf?aLZWl%! z^^$$H>I+!(-!dFQ)YAsr_~NImrn1L?L!SS-`ip=Qk8!FA90-qf+_9kY(QbiiW#=Cx z-wawh)qH{3(WP;Vnthnmr8UPkI@0+|@xSBdG9$EDTJzgP--MUxX$}qrojRNZ*9x9z zfvpDnXK@pOznEz@|I_aAK8P)$Uj?yEL#@~FwGjy=S3ToyyoUmEy90Dg@?Udl4k3YY zxr|&I4$HdD7Rz;_V_>vBcSxCH^n%JaS;zn4W(eds^h@09hBWcxASx!3!GddMYH-Mc z{9Y1NXp4`H0}>a=YxBOZ+Od*(;zBP8NBO`eekTaq9V>Nxq>0MZJ1I>YIO~cmD`;(D z%I~V_03$^R5aiM_+>Va{5H+fQ3jOs)WMx+*`Xy?1HDR67Itksf@c!+*UJ1|;_b~0{ zhCOB=0B68E$F^Vel|%l$ra&$c`?))>d1k_;y)K+;nJI9uvpu~;D`vXaK&~6nAvRen zM($lY13RvQ)^D0xUKbv-wMT&|uQPO)iFGZpPRka^b7s5E6`cLH{nvxGyO$b;%7L*m z?`zzh>#wC29ngT75W%=jyjQWYUNOH!1RYw@1rN%UxKfzpZw58-f2vujfP({>9E=qHaY^4>U=5ek;8-iJq&f<;wO@`;cm*w5 zq&D4*J8jVnEmKMe_;md+`^v=xLOO{cfDZQbUX5a!8dbQ-Sg$Dq`ajPBd-gvKmk-#3 zn<P};wLQwB!(+>HRi@Lk%km%t#(a61=9n<**jcrg1&QPQ8J#VTCRFd|L$clE`q#q?t^u1$?llYJqViiAe#>I(gA?_I?5H3_jh5-ZnFb9k{?gX7$~h#L=E6GpmM_6_ z$~A%ZUVpY$P0k>2_cVgAV$_bOoSlFZ) zTlOgG4;LkQkQjY)X@gUjPByo?J^Hc(ipw|C_hD(q1Tb}Zdlct3TJ<4fJMnRjtn zxHh=p`F}VRg@Iv%>k}77zv*gaQ*Q4@romR+yU}}fE^T~f@5Tvma)0k-Xziy~Hb{!9 zq3xM>$%7JQu&o@TpyJYNU3emJj0jZw6_b)02TG}T_ltO>U2T#$lxqhgbAs5WBiq8M zF&P5hy=uBOu1Heor?LgSpMP7}l;G>!`LeAPBP`bocq4MFRgIw~YtsW_pSNX@XVDBA zKe(bE{t*gy$GbQd*XP()4(*lUB}jBA`1z_^WSGf+l2Y4yg{bT=rJhP1?Um0ZL#$=C zT3M3QW0di8)JpfrtV>ch8RS|p{`wwsdLNb0t=U1b!3y%6)HY3kWoWTUYkMDrc=^wA z;T;&1tP(sg*`-`LT$|?LCHw4si|#auPtKg0tF##&9YM9pS{&=pM{@QC>cw&TvZnv#hgfVvp zDT_iuq>>wlh0vW+&Vz}_IFT)YYWhpi0U!%8^iHH!KJHaJk2#6@dZHMc>~$v)4au=J z!RWr*r#E3R&Pf<<09l7u(2D(;%B8(-6Tm}4#M3Ak#XtHeW0`^DGF^|qjmKK7l^3Us z07;9thbP_!qC=W!G~5YR(ERYmcTq5kebj}|2Zz$)t5xC~R<5ZN!;E@s0?d2shAUyC z!Pb=4%dw$+8!|tQnyy73VGeo>u7oAMI@Sio(0IS5k7%M54ux|Ij-Rlj$2O(;pa!>d zm_OUp302f_AUds==n0U<+|deeXdj`|&YP`9Lk{$+0Rwj4jvL=9sP~5&g+>_YIl*kF zThddYqC6eCtHPgw;dodR_N>YOaiG||i-OVeN9d@N^#XXv>2U^(1FgUOnJH4nLFlKz zU~u$Yaw&z5p9YrWDqvUe%FXQ@qr9NQa{Z_IQLm9c91YQ)XxU6SG@ z^^IA0sZazZh@3m&wVm4!6Gohc? z;R}eH_3oS>^6B`br`m4ucpQY3DfeePYuoPAKH9eHgtYwvqy+=A6eAtO&wUtJX%D`d zW8UB~XbXoz19^lAA0dCfa+p4>e8Zs;I-e$5S#-U1m_LgO!7PU;fD4>Iteo!xaktLE zkmvtzpT{6bdNi;=CEN*NVitZ&vi8-YsM+U}RY*d2oS>j4Le8t28a@&#f2FCK?p`xq zpfSTpb?S5XO9(OQ@V5Z{rfHQraL&8g8gnRk2N8I_8Z!)G`_1TH^V68&beed?+6;|3 z8P){dYqKe!0fyJH z5_v*R1SsgfnM?78Ybs)wM^!$I@;^XkDq7-G&R;K~E8&IJCOZF?>Vp&GcR26zpRlB( z{aN;z0t90PLi=Mr8sZ7kYA)Lpe3Tll{{f`YcS|!VS#{zUc(}8}8#g*Lwt|X(8|Ja& z1(H9p2S0U@JKDH3k^`%iy^O3vBSy z81Rd2Jyr(ZLM0G=@DNML1aH38_^IzVyyha*7~nv_Yb?2zA*=?6n3{++UyXqWYu)?u z=4cF97IGh7Bhzpwl{C`ohh4+N@WZSm8w_;OqbhYX=W&gb@~2@nt1IDZ>?DR51AX@4 zNqpL3qmT~*@Wv6XSWxV;M^@q_?jj8_x!(+u9wX`jCD^HgfA!}Rqfi878t9u-R5GX} zhwo1gnLt;vr1*LVV=U6V_W8!df%|8s)+mH|1B%YTWr0%f0@)-~jPgLa)h|ncb?sOg z>l8d4L}!t8!>MrU3c2!2_Z?HgPX)KS5_IMBP73R`_N|;s-Y|GCUuiLD?ZVQt_R91G^SqoTa9wT!)c_kTzd2o5b5I~-PShzZq;tu5*i?C!sP#^TpZmVgSJRh`l+e-qVxnL>DO^2@ z^40Papp@h_r?x}S@@U%#Z2T3Ds9kzgbSAn(yaejRiZYj68XEW1eqcMUK%u3a7{6&; z4d4w!7oSX>)GcufTo<~NWZ74-;pcv+v*$j8FD`7+yI7*=TdsLMgYwl8tKh*=`OvM$ zppO4hW;sNv%~yL;zFMHZ4{VC)36&Mr|8X9E_EHx1F40i?A6+odJp5|nCeNCtvbqY$ z=)8BmLL$@|2T5cwUh6T z@T&I608j1c2|(2+>>c9L9DYdD@2C*$HQvy3hQboS{4gniB5u2cog`xcvVCBWWe!gQ z>hN?9CH>4C#$!T@0o|qfN#U|=-~+GC)a&nIdhm{5yR(<=HJ}tru-z8IKIaO3Epq5R zFl~^ac`Jy}-`UK+91el1TihG_2@vjP$n%s&?r&P_lUQO}_n}$a7CsUZKY2794vRL- z#}ZR>$dfpw#bYP@Sx@v5GY>KrrC_@&yHCf!lfob2Pk3F0o?vGae-mcwXzZ5wybEI% z{0VQv)a#05ZdE7N$6eXI`Z!gELxwn7+-X{KtOjJX^Cdfx_r?l7mhJ)*&jGcabmVfrmD-TjJU3*i_eT;;I6S)so}Y%c~;4~n1>eo1m~@xwXoL8LY! z5?fGyqNk5q>x#{0yZ*|aERUvHz6dxcv?#JVZ0N5+qb zv4>F#6tt7C-BK+fXbkD;#!kH;MTBp1>i?H3I(9;cP(`_Vco3Yhs0R%mtMEf5gpZRq z0QTfC4kfEvyeQ~#$*<5>WvdbnX19B+@@Kw`n~Hd2!DOv9@LDj%(D~zhC&ryP3OX16 zD3@W=HhiIiP|cI@=v{?AMsxY01+w`P2aI$dpZ`WU_#lzMYVsJK75oo(Ello@&I10K zprCm;pbb#DDWeu16jgH=ca{!7x2oHR2eKV&g9}Qq)5I_mg-DyBHTbiR)YzlkgYVbo ziFmrA5Q4StJA(D`=CZrtBjdJGbl)8>Nxen4_NX~H20Ly1OiaCaiB@)0_)EbUG(P+G z$D=^8Ay!Q|Z3%JWYjPP&)v6ZHZhW}Q!cM=e+b+EEpk19g|BoVLgWh9{|In*K+(YcB$wiF zU9pqkzMSChcS{uj!e2wW1;^l>dk{}{yreO7Qfx$A{=g7oe*wJfcxJsLdZJ>!R;C9s-=GbtR&l}ZHCcoKk_ZD# zIVKu5A4EhbX(zczgd@!GVO}w1zi3zht3!a$lPl}JTz5Bj?<88Hv;}Mk|FZ*-sqn3Q zd*6oG96~d)pKh#HO$e?nAL@EzMq2pd|z< zB*Lk9jZx9b8 zqop@bYHVzTLn8hgm*ef9Qdc}mSQ2LiA2_ldUk5+>RFm*|>h@ib36nwj%Azk%6aMFb zkjZsQ6b&JG_(AxqHUwYd0MLVi5X{#R{?zOLT7wb6|91^uDIqKUKWhZ3|96dGquVic zBK5b}4^JP%G-%x}q`bGb>&cBf&Xs$xDx!7sHkz^7(QFFt zh-575<{z`7YsMm;|D8eN^V-(dsBGRK_|7~C43k$sqNM9hC{6_Md-(cjeli^wwLAuZ zGlWK{_E8hYc4D~90PF+sPM<9_;tS<2e2kd|MDT^k%3%!75*ne%M|Yv!VmdR1LGz|O z0N_lak%qz0AZ0l*hCy$pgjdnQ8N!uL7!2P7Go2V$VH(4O4^)R_3s*w5jqnGmesfv7 zv7KFW7%l>hJiovN(xkS<+9<3$Z;f_8sXEFYIARja<|M5xSI$34zPT1GwGcjAld%lW zU|I9+&~&dq+e|P=mn$H4H|%hLC$lwe2t}O{!^qDFy#<;EGbnhOh(^kZ*d=+>f#HrL zqfGGD@I8{lS8^3Jco;=C^J9SQ>mMu-eD?-3r+%;=MgT62x1L(6}5RS9=4i#|A!aj+5YRv8@uJ zhShIC)3|N$Qo3NFL^V?ciD!`p3e$TG-4V0v=(sZu{J>jqQJx^Y>OU zu*NrlshC#5hbcU&w1ZA}-HQ>()Cmw7hB#r!A%J*&Q^CiCDkosb?*Lf~5IYQ^W5^hQ z6mOhL4%i%U0xE_)!=)qLsIIoo?NiUj^jqb`=!7^$ykC!u+T^1#SNf>o_KdFiA41ws zpI;?(d}3d+S?^Jm&Dac7b6TwH#VmM^Lx^Hvc*9<7ohG0Grtpfz6$|4WA%+kn5* z!MiJ21ut%h$7|v@CadD{&+&H#;ZYdOS`h7kC|am7ugA!02k*1VDtM+tFdYedmLJXF#_bO4!xO!5 zrkjuz{b&|K`xnowESWkn@xYp$0quJiBjh_U&FjzAuRf1Rh=1jD_k9;dIW}b4p@JFL Q;6^~Rd_?^GY4XJX16vo_zW@LL literal 0 HcmV?d00001 From 69c98e4edbd98a795222d439b3ac7b84eaba9553 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Wed, 11 Jul 2018 11:01:29 +0200 Subject: [PATCH 02/11] customLevels docs --- docs/api.md | 37 +++++++++++++++++++++++++------------ 1 file changed, 25 insertions(+), 12 deletions(-) diff --git a/docs/api.md b/docs/api.md index 783455a9f..924595c11 100644 --- a/docs/api.md +++ b/docs/api.md @@ -15,7 +15,6 @@ * [logger.level](#level) * [logger.isLevelEnabled()](#isLevelEnabled) * [logger.addLevel()](#addLevel) - * [logger.levelVal](#levelVal) * [logger.levels](#levels) * [Event: 'level-change'](#level-change) * [logger.version](#version) @@ -51,11 +50,32 @@ Default: `'info'` One of `'fatal'`, `'error'`, `'warn'`, `'info`', `'debug'`, `'trace'` or `silent`. -Additional levels can be explicitly added via the `logger.addLevel` method or implicitly -by setting a custom `level` and `levelVal` together. +Additional levels can be added to the instance via the `logger.addLevel` method or +at instantiation time with the `customLevels` property. * See [`logger.addLevel`](#addLevel) -* See [`levelVal option`](#opt-levelVal) +* See [`customLevels` option](#opt-customlevels) + +#### `customLevels` (Object) + +Default: `undefined` + +Use this option to define additional logging levels. +The keys of the object correspond the namespace of the log level, +and the values should be the numerical value of the level. + +```js +const logger = pino({ + customLevels: { + foo: 35 + } +}) +logger.foo('hi') +``` + + + + #### `redact` (Array|Object): @@ -136,13 +156,6 @@ for passing in as a value for this option. **Caution**: attempting to format time in-process will significantly impact logging performance. - -#### `levelVal` (Number) - -Default: `undefined` - -When defining a custom log level via `level`, set to an integer value to define the new level. - #### `messageKey` (String) @@ -500,7 +513,7 @@ therefore where it sits in order of priority among other levels. * See [`logger.level`](#level) -### `logger.levelVal` (Number) [Getter] +### `logger.levelVal` (Number) Supplies the integer value for the current logging level. From dd2f9a6c8a739021da7631ecb8443d2c7655e2dd Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sat, 14 Jul 2018 17:14:39 +0200 Subject: [PATCH 03/11] remove all --save flags from docs --- README.md | 2 +- docs/help.md | 2 +- docs/pretty.md | 2 +- docs/web.md | 10 +++++----- 4 files changed, 8 insertions(+), 8 deletions(-) diff --git a/README.md b/README.md index 5e9fb1984..a3810085d 100644 --- a/README.md +++ b/README.md @@ -21,7 +21,7 @@ ## Install ``` -$ npm install pino --save +$ npm install pino ``` ## Usage diff --git a/docs/help.md b/docs/help.md index 72415e4b4..23c4ef2cd 100644 --- a/docs/help.md +++ b/docs/help.md @@ -110,7 +110,7 @@ and preload it with the `-r` flag, enabling any `debug` logs with the `DEBUG` environment variable: ```sh -$ npm i --save pino-debug +$ npm i pino-debug $ DEBUG=* node -r pino-debug app.js ``` diff --git a/docs/pretty.md b/docs/pretty.md index 6a9337fdd..df6230129 100644 --- a/docs/pretty.md +++ b/docs/pretty.md @@ -62,7 +62,7 @@ will be written to the destination stream. > the prettifier instead. Prettified logs are not easily parsed and cannot > be easily investigated at a later date. -1. Install a prettifier module as a separate dependency, e.g. `npm install --save pino-pretty`. +1. Install a prettifier module as a separate dependency, e.g. `npm install pino-pretty`. 1. Instantiate the logger with pretty printing enabled: ```js const pino = require('pino') diff --git a/docs/web.md b/docs/web.md index c05fb3570..412b08d16 100644 --- a/docs/web.md +++ b/docs/web.md @@ -34,7 +34,7 @@ See the [fastify documentation](https://www.npmjs.com/package/pino-http#pinohttp ## Pino with Express ```sh -npm install --save express-pino-logger +npm install express-pino-logger ``` ```js @@ -57,7 +57,7 @@ See the [express-pino-logger readme](http://npm.im/express-pino-logger) for more ## Pino with Hapi ```sh -npm install --save hapi-pino +npm install hapi-pino ``` ```js @@ -101,7 +101,7 @@ See the [hapi-pino readme](http://npm.im/hapi-pino) for more info. ## Pino with Restify ```sh -npm install --save restify-pino-logger +npm install restify-pino-logger ``` ```js @@ -126,7 +126,7 @@ See the [restify-pino-logger readme](http://npm.im/restify-pino-logger) for more ### Koa ```sh -npm install --save koa-pino-logger +npm install koa-pino-logger ``` ```js @@ -150,7 +150,7 @@ See the [koa-pino-logger readme](https://github.com/pinojs/koa-pino-logger) for ## Pino with Node core `http` ```sh -npm install --save pino-http +npm install pino-http ``` ```js From 8866e6bee29a96d075625e6120b9529393c7493e Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sat, 14 Jul 2018 17:30:56 +0200 Subject: [PATCH 04/11] tweaks, legacy.md outline --- docs/api.md | 17 +++++++--- docs/legacy.md | 21 ++++++++++++ docs/web.md | 88 +++++++++++++++++++++++++++++++------------------- 3 files changed, 88 insertions(+), 38 deletions(-) create mode 100644 docs/legacy.md diff --git a/docs/api.md b/docs/api.md index 924595c11..df43fb683 100644 --- a/docs/api.md +++ b/docs/api.md @@ -73,10 +73,6 @@ const logger = pino({ logger.foo('hi') ``` - - - - #### `redact` (Array|Object): Default: `undefined` @@ -187,7 +183,11 @@ configurations. This may be set to a configuration object as outlined in the The options object may additionally contain a `prettifier` property to define which prettifier module to use. When not present, `prettifier` defaults to `'pino-pretty'`. Regardless of the value, the specified prettifier module -must be installed as a separate dependency. +must be installed as a separate dependency: + +```sh +npm install pino-pretty +``` #### `browser` (Object) @@ -224,6 +224,11 @@ set on the `destination` object: * the last logger instance as `destination.lastLogger` (to support child loggers) +For a full reference for using `Symbol.for('pino.metadata')`, see the [`pino-multi-stream` ⇗](https://github.com/pinojs/pino-multi-stream) +module. + +The following is a succinct usage example: + ```js const logger = pino({}, { [Symbol.for('pino.metadata')]: true, @@ -237,6 +242,8 @@ const logger = pino({}, { }) ``` +* See [`pino-multi-stream` ⇗](https://github.com/pinojs/pino-multi-stream) + ## Logger Instance diff --git a/docs/legacy.md b/docs/legacy.md new file mode 100644 index 000000000..aef4d09cc --- /dev/null +++ b/docs/legacy.md @@ -0,0 +1,21 @@ +# Legacy + +## Documentation + +### Pino v4 + +### Pino v3 + +### Pino v2 + +## Legacy Node Support + +### Node v4 + +### Node 0.10-0.12 + +## Migration + +### Pino v4 to to Pino v5 + + \ No newline at end of file diff --git a/docs/web.md b/docs/web.md index 412b08d16..fd62f6f5c 100644 --- a/docs/web.md +++ b/docs/web.md @@ -22,19 +22,23 @@ const fastify = require('fastify')({ logger: true }) fastify.get('/', async (request, reply) => { - reply.type('application/json').code(200) reply.log.info('something') return { hello: 'world' } }) ``` +The `logger` option can also be set to an object, which will be passed through directly +as the [`pino` options object](api.md#options). + +Note: Fastify v1 uses [Pino v4](legacy.md#pino-v4). The upcoming Fastify v2 will use Pino v5. + See the [fastify documentation](https://www.npmjs.com/package/pino-http#pinohttpopts-stream) for more information. ## Pino with Express ```sh -npm install express-pino-logger +npm install express-pino-logger ``` ```js @@ -57,41 +61,59 @@ See the [express-pino-logger readme](http://npm.im/express-pino-logger) for more ## Pino with Hapi ```sh -npm install hapi-pino +npm install hapi-pino ``` ```js 'use strict' - + +require('make-promises-safe') + const Hapi = require('hapi') - -const server = new Hapi.Server() -server.connection({ port: 3000 }) - -server.route({ - method: 'GET', - path: '/', - handler: function (request, reply) { - request.logger.info('In handler %s', request.path) - return reply('hello world') - } -}) - -server.register(require('hapi-pino'), (err) => { - if (err) { - console.error(err) - process.exit(1) - } - - server.logger().info('another way for accessing it') - - // Start the server - server.start((err) => { - if (err) { - console.error(err) - process.exit(1) + +async function start () { + // Create a server with a host and port + const server = Hapi.server({ + host: 'localhost', + port: 3000 + }) + + // Add the route + server.route({ + method: 'GET', + path: '/', + handler: async function (request, h) { + // request.log is HAPI standard way of logging + request.log(['a', 'b'], 'Request into hello world') + + // you can also use a pino instance, which will be faster + request.logger.info('In handler %s', request.path) + + return 'hello world' } }) + + await server.register({ + plugin: require('.'), + options: { + prettyPrint: process.env.NODE_ENV !== 'production' + } + }) + + // also as a decorated API + server.logger().info('another way for accessing it') + + // and through Hapi standard logging system + server.log(['subsystem'], 'third way for accessing it') + + await server.start() + + return server +} + +start().catch((err) => { + console.log(err) + process.exit(1) }) ``` @@ -101,7 +123,7 @@ See the [hapi-pino readme](http://npm.im/hapi-pino) for more info. ## Pino with Restify ```sh -npm install restify-pino-logger +npm install restify-pino-logger ``` ```js @@ -126,7 +148,7 @@ See the [restify-pino-logger readme](http://npm.im/restify-pino-logger) for more ### Koa ```sh -npm install koa-pino-logger +npm install koa-pino-logger ``` ```js @@ -150,7 +172,7 @@ See the [koa-pino-logger readme](https://github.com/pinojs/koa-pino-logger) for ## Pino with Node core `http` ```sh -npm install pino-http +npm install pino-http ``` ```js From 154110f14e10fd660f05a8b7ca4f126710a89fe7 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sat, 14 Jul 2018 18:36:40 +0200 Subject: [PATCH 05/11] legacy and migration doc --- README.md | 1 + docs/api.md | 5 +- docs/legacy.md | 157 +++++++++++++++++++++++++++++++++++++++++++-- docs/web.md | 2 +- docsify/sidebar.md | 1 + 5 files changed, 156 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index a3810085d..347024a99 100644 --- a/README.md +++ b/README.md @@ -16,6 +16,7 @@ * [Pretty Printing ⇗](/docs/pretty.md) * [Extreme Mode ⇗](/docs/extreme.md) * [Ecosystem ⇗](/docs/ecosystem.md) +* [Legacy](/docs/legacy.md) * [Help ⇗](/docs/help.md) ## Install diff --git a/docs/api.md b/docs/api.md index df43fb683..39320504d 100644 --- a/docs/api.md +++ b/docs/api.md @@ -173,6 +173,7 @@ then exit the process. * See [Extreme mode ⇗](/docs/extreme.md) + #### `prettyPrint` (Boolean|Object) Default: `false` @@ -196,7 +197,7 @@ Browser only, may have `asObject` and `write` keys * See [Browser API](/docs/browser.md) -### `destination` (WritableStream) +### `destination` (SonicBoom | WritableStream) Default: `pino.destination(1)` (STDOUT) @@ -614,7 +615,7 @@ will be `process.stdout.fd`. The default `stream` is a destination. -`pino.destination()` is implemented on [`sonic-boom`](https://github.com/mcollina/sonic-boom). +`pino.destination()` is implemented on [`sonic-boom` ⇗]](https://github.com/mcollina/sonic-boom). ### `pino.extreme([dest]) => SonicBoom` diff --git a/docs/legacy.md b/docs/legacy.md index aef4d09cc..abe26ff44 100644 --- a/docs/legacy.md +++ b/docs/legacy.md @@ -1,21 +1,164 @@ # Legacy +## Legacy Node Support + +### Node v4 + +Node v4 is supported on the [Pino v4](#pino-v4-documentation) line. + +### Node v0.10-v0.12 + +Node v0.10 or Node v0.12 is supported on the [Pino v2](#pino-v2-documentation) line. + ## Documentation -### Pino v4 +### Pino v4 Documentation -### Pino v3 + -### Pino v2 +### Pino v3 Documentation -## Legacy Node Support + -### Node v4 +### Pino v2 Documentation -### Node 0.10-0.12 + ## Migration ### Pino v4 to to Pino v5 - \ No newline at end of file +#### Logging Destination + +In Pino v4 the destination could be set by passing a stream as the +second parameter to the exported `pino` function. This is still the +case in v5. However it's strongly recommended to use `pino.destination` +which will write logs ~30% faster. + +##### v4 + +```js +const stdoutLogger = require('pino')() +const stderrLogger = require('pino')(process.stderr) +const fileLogger = require('pino')(fs.createWriteStream('/log/path')) +``` + +##### v5 + +```js +const stdoutLogger = require('pino')() // pino.destination by default +const stderrLogger = require('pino')(pino.destination(2)) +const fileLogger = require('pino')(pino.destination('/log/path')) +``` + +Note: This is not a breaking change, `WritableStream` instances are still +supported, but are slower than `pino.destination` which +uses the high speed [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) library. + +* See [`destination` parameter](/docs/api.md#destination) + +#### Extreme Mode + +The `extreme` setting does not exist as an option in Pino v5, instead use +a `pino.extreme` destination. + +##### v4 + +```js +const stdoutLogger = require('pino')({extreme: true}) +const stderrLogger = require('pino')({extreme: true}, process.stderr) +const fileLogger = require('pino')({extreme: true}, fs.createWriteStream('/log/path')) +``` + +##### v5 + +```js +const stdoutLogger = require('pino')(pino.extreme()) +const stderrLogger = require('pino')(pino.extreme(2)) +const fileLogger = require('pino')(pino.extreme('/log/path')) +``` + +* See [pino.extreme](/docs/api.md#pino-extreme) +* See [Extreme mode ⇗](/docs/extreme.md) + + +#### Pino CLI is now pino-pretty CLI + +The Pino CLI is provided with Pino v4 for basic log prettification. + +From Pino v5 the CLI is installed separately with `pino-pretty`. + +##### v4 +```sh +$ npm install -g pino +$ node app.js | pino +``` + +##### v5 +```sh +$ npm install -g pino-pretty +$ node app.js | pino-pretty +``` + +#### Programmatic Pretty Printing + +The [`pino.pretty()`](https://github.com/pinojs/pino/blob/v4.x.x/docs/API.md#prettyoptions) +method has also been removed from Pino v5. + +##### v4 + +```js +var pino = require('pino') +var pretty = pino.pretty() +pretty.pipe(process.stdout) +``` + +##### v5 + +Instead use the `prettyPrint` option (also available in v4): + +```js +const logger = require('pino')({ + prettyPrint: process.env.NODE_ENV !== 'production' +}) +``` + +In v5 the `pretty-print` module must be installed to use the `prettyPrint` option: + +```sh +npm install --save-dev pino-pretty +``` + +* See [prettyPrint option](/docs/api.md#prettyPrint) + +#### Slowtime + +In Pino v4 a `slowtime` option was supplied, which allowed for full ISO dates +in the timestamps instead of milliseconds since the Epoch. In Pino v5 this +has been completely removed, along with the `pino.stdTimeFunctions.slowTime` +function. In order to achieve the equivalent in v5, a custom +time function should be supplied: + +##### v4 + +```js +const pino = require('pino') +const logger = pino({slowtime: true}) +// following avoids deprecation warning in v4: +const loggerAlt = pino({timestamp: pino.stdTimeFunctions.slowTime}) +``` + +##### v5 + +```js +const logger = require('pino')({ + timestamp: () => ',"time":"' + (new Date()).toISOString() + '"' +}) +``` + +The practice of creating ISO dates in-process for logging purposes is strongly +recommended against. Instead consider post-processing the logs or using a transport +to convert the timestamps. + + +* See [timestamp option](/docs/api.md#timestamp) \ No newline at end of file diff --git a/docs/web.md b/docs/web.md index fd62f6f5c..22df0b105 100644 --- a/docs/web.md +++ b/docs/web.md @@ -30,7 +30,7 @@ fastify.get('/', async (request, reply) => { The `logger` option can also be set to an object, which will be passed through directly as the [`pino` options object](api.md#options). -Note: Fastify v1 uses [Pino v4](legacy.md#pino-v4). The upcoming Fastify v2 will use Pino v5. +Note: Fastify v1 uses [Pino v4](legacy.md#pino-v4-documentation). The upcoming Fastify v2 will use Pino v5. See the [fastify documentation](https://www.npmjs.com/package/pino-http#pinohttpopts-stream) for more information. diff --git a/docsify/sidebar.md b/docsify/sidebar.md index 05dc9be5a..d2b0ad863 100644 --- a/docsify/sidebar.md +++ b/docsify/sidebar.md @@ -9,6 +9,7 @@ * [Extreme Mode](/docs/extreme.md) * [Ecosystem](/docs/ecosystem.md) * [Benchmarks](/docs/benchmarks.md) +* [Legacy](/docs/legacy.md) * [Help](/docs/help.md) * [Log Rotation](/docs/help.md#rotate) * [Multiple Files](/docs/help.md#multiple) From a4c92abdf26cbe5ce5b801902b3b7e82b469486b Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sat, 14 Jul 2018 20:38:34 +0200 Subject: [PATCH 06/11] corrections --- docs/api.md | 166 +++++++++++++++++++++++------------------- docs/child-loggers.md | 4 +- docs/extreme.md | 15 ++-- docs/help.md | 44 ++++++----- docs/legacy.md | 3 + docs/pretty.md | 4 +- docs/redaction.md | 16 ++-- docs/transports.md | 73 ++++++++++--------- docs/web.md | 2 +- 9 files changed, 182 insertions(+), 145 deletions(-) diff --git a/docs/api.md b/docs/api.md index 39320504d..31b006318 100644 --- a/docs/api.md +++ b/docs/api.md @@ -13,8 +13,8 @@ * [logger.child()](#child) * [logger.flush()](#flush) * [logger.level](#level) - * [logger.isLevelEnabled()](#isLevelEnabled) - * [logger.addLevel()](#addLevel) + * [logger.isLevelEnabled()](#islevelenabled) + * [logger.addLevel()](#addlevel) * [logger.levels](#levels) * [Event: 'level-change'](#level-change) * [logger.version](#version) @@ -22,8 +22,8 @@ * [Statics](#statics) * [pino.destination()](#pino-destination) * [pino.extreme()](#pino-extreme) - * [pino.stdSerializers](#pino-stdSerializers) - * [pino.stdTimeFunctions](#pino-stdTimeFunctions) + * [pino.stdSerializers](#pino-stdserializers) + * [pino.stdTimeFunctions](#pino-stdtimefunctions) * [pino.symbols](#pino-symbols) * [pino.version](#pino-version) * [pino.LOG_VERSION](#pino-LOG_VERSION) @@ -56,6 +56,7 @@ at instantiation time with the `customLevels` property. * See [`logger.addLevel`](#addLevel) * See [`customLevels` option](#opt-customlevels) + #### `customLevels` (Object) Default: `undefined` @@ -73,7 +74,7 @@ const logger = pino({ logger.foo('hi') ``` -#### `redact` (Array|Object): +#### `redact` (Array | Object): Default: `undefined` @@ -89,7 +90,7 @@ If an object is supplied, three options can be specified: **WARNING**: Never allow user input to define redacted paths. -* See the [redaction ⇗](redaction.md) documentation. +* See the [redaction ⇗](/docs/redaction.md) documentation. * See [fast-redact#caveat ⇗](http://github.com/davidmarkclements/fast-redact#caveat) @@ -102,7 +103,7 @@ These functions should return an JSONifiable object and they should never throw. When logging an object, each top-level property matching the exact key of a serializer will be serialized using the defined serializer. -* See [pino.stdSerializers](#pino-stdSerializers) +* See [pino.stdSerializers](#pino-stdserializers) ##### `serializers[Symbol.for('pino.*')]` (Function) @@ -137,8 +138,8 @@ Default: `false` Set to `true` to logs newline delimited JSON with `\r\n` instead of `\n`. - -#### `timestamp` (Boolean|Function) + +#### `timestamp` (Boolean | Function) Default: `true` @@ -147,12 +148,12 @@ log message. If a function is supplied, it must synchronously return a JSON stri representation of the time, e.g. `,"time":1493426328206` (which is the default). If set to `false`, no timestamp will be included in the output. -See [stdTimeFunctions](#stdTimeFunctions) for a set of available functions +See [stdTimeFunctions](#pino-stdtimefunctions) for a set of available functions for passing in as a value for this option. **Caution**: attempting to format time in-process will significantly impact logging performance. - + #### `messageKey` (String) Default: `'msg'` @@ -163,24 +164,30 @@ The string key for the 'message' in the JSON object. Default: `(evt, err) => err ? process.exit(1) : process.exit(0)` -This function will be invoked during process shutdown when `extreme` is set to `true`. +This function will be invoked during process shutdown when +the supplied destination is an instance of [`pino.extreme`](#pino-extreme) + +The signature of the function is `onTerminated(eventName, err)`. -The signature of the function is `onTerminated(eventName, err)`. If you do not specify a function, Pino will -invoke `process.exit(0)` when no error has occurred, and `process.exit(1)` otherwise. +By default, when `pino.extreme` is used, the `onTerminated` function +is set to call `process.exit(1)` on error or else `process.exit(0)`. -If a function is specified it **must** perform only synchronous operations at this point and -then exit the process. +If a function is specified it **must** perform only synchronous operations +at this point and then exit the process (there are no ticks left for +asynchronous activity at this point in the process lifetime). +* See [pino.extreme](#pino-extreme) * See [Extreme mode ⇗](/docs/extreme.md) -#### `prettyPrint` (Boolean|Object) +#### `prettyPrint` (Boolean | Object) Default: `false` Enables pretty printing log logs. This is intended for non-production configurations. This may be set to a configuration object as outlined in the [`pino-pretty` documentation](https://github.com/pinojs/pino-pretty). + The options object may additionally contain a `prettifier` property to define which prettifier module to use. When not present, `prettifier` defaults to `'pino-pretty'`. Regardless of the value, the specified prettifier module @@ -192,9 +199,10 @@ npm install pino-pretty #### `browser` (Object) -Browser only, may have `asObject` and `write` keys +Browser only, may have `asObject` and `write` keys. This option is separately +documented in the [Browser API ⇗](/docs/browser.md) documentation. -* See [Browser API](/docs/browser.md) +* See [Browser API ⇗](/docs/browser.md) ### `destination` (SonicBoom | WritableStream) @@ -206,6 +214,19 @@ An ordinary Node.js `stream` can be passed as the destination (such as the resul of `fs.createWriteStream`) but for peak log writing performance it is strongly recommended to use `pino.destination` or `pino.extreme` to create the destination stream. +```js +// pino.destination(1) by default +const stdoutLogger = require('pino')() + +// destination param may be in first position when no options: +const fileLogger = require('pino')( pino.destination('/log/path')) + +// use the stderr file handle to log to stderr: +const opts = {name: 'my-logger'} +const stderrLogger = require('pino')(opts, pino.destination(2)) + +``` + * See [`pino.destination`](#pino-destination) * See [`pino.extreme`](#pino-extreme) @@ -213,9 +234,9 @@ recommended to use `pino.destination` or `pino.extreme` to create the destinatio Default: `false` -Assigning the `pino.metadata` symbol key to `true` on the `destination` parameter -indicates after each log line is written, the following properties should be -set on the `destination` object: +Using the global symbol `Symbol.for('pino.metadata')` as a key on the `destination` parameter and +setting the key it to `true`, indicates that the following properties should be +set on the `destination` object after each log line is written: * the last logging level as `destination.lastLevel` * the last logging message as `destination.lastMsg` @@ -231,16 +252,15 @@ module. The following is a succinct usage example: ```js -const logger = pino({}, { - [Symbol.for('pino.metadata')]: true, - write: function (chunk) { - console.log('lastLevel', this.lastLevel) - console.log('lastMsg', this.lastMsg) - console.log('lastObj', this.lastObj) - console.log('lastLogger', this.lastLogger) - console.log('line', chunk) - } -}) +const dest = pino.destination('/dev/null') +dest[Symbol.for('pino.metadata')] = true +const logger = pino(dest) +logger.info({a: 1}, 'hi') +const { lastMsg, lastLevel, lastObj, lastTime} = dest +console.log( + 'Logged message "%s" at level %d with object %o at time %s', + lastMsg, lastLevel, lastObj, lastTime +) // Logged message "hi" at level 30 with object { a: 1 } at time 1531590545089 ``` * See [`pino-multi-stream` ⇗](https://github.com/pinojs/pino-multi-stream) @@ -258,9 +278,9 @@ The default logging methods are `trace`, `debug`, `info`, `warn`, and `fatal`. Each logging method has the following signature: `([mergingObject], [message], [...interpolationValues])`. -The parameters will be explained using `logger.info` but the same applies to all logging methods. +The parameters are explained below using the `logger.info` method but the same applies to all logging methods. - + #### `mergingObject` (Object) An object can optionally be supplied as the first parameter. Each enumerable key and value @@ -303,10 +323,10 @@ the following placeholders: Values supplied as additional arguments to the logger method will then be interpolated accordingly. -* See [`messageKey` pino option](#opt-messageKey) -* See [`...interpolationValues` log method parameter](#interpolatedValues) +* See [`messageKey` pino option](#opt-messagekey) +* See [`...interpolationValues` log method parameter](#interpolationvalues) - + #### `...interpolationValues` (Any) All arguments supplied after `message` are serialized and interpolated according @@ -336,54 +356,54 @@ logger.info('%o hello', {worldly: 1}) Write a `'trace'` level log, if the configured [`level`](#level) allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) ### `logger.debug([mergingObject], [message], [...interpolationValues])` Write a `'debug'` level log, if the configured `level` allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) ### `logger.info([mergingObject], [message], [...interpolationValues])` Write an `'info'` level log, if the configured `level` allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) ### `logger.warn([mergingObject], [message], [...interpolationValues])` Write a `'warn'` level log, if the configured `level` allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) ### `logger.error([mergingObject], [message], [...interpolationValues])` Write a `'error'` level log, if the configured `level` allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) ### `logger.fatal([mergingObject], [message], [...interpolationValues])` Write a `'fatal'` level log, if the configured `level` allows for it. -* See [`mergingObject` log method parameter](#mergingObject) +* See [`mergingObject` log method parameter](#mergingobject) * See [`message` log method parameter](#message) -* See [`...interpolationValues` log method parameter](#interpolationValues) +* See [`...interpolationValues` log method parameter](#interpolationvalues) @@ -398,7 +418,7 @@ the current log level of the parent at the time they are spawned. The log level of a child is mutable. It can be set independently of the parent either by setting the [`level`](#level) accessor after creating -the child logger or using the reserved [`bindings.level`](#bindings-level) key. +the child logger or using the reserved [`bindings.level`](#bindingslevel-string) key. #### `bindings` (Object) @@ -429,7 +449,7 @@ child.debug('debug!') // will log as the `level` property set the level to debug ##### `bindings.serializers` (Object) -Child loggers inherit the [serializers](#serializers-opt) from the parent logger. +Child loggers inherit the [serializers](#opt-serializers) from the parent logger. Setting the `serializers` key of the `bindings` object will override any configured parent serializers. @@ -454,7 +474,7 @@ Flushes the content of the buffer when using a `pino.extreme` destination. It has no effect if extreme mode is not enabled. * See [`pino.extreme`](#pino-extreme) -* See [Extreme mode ⇗](extreme.md) +* See [Extreme mode ⇗](/docs/extreme.md) ### `logger.level` (String) [Getter/Setter] @@ -475,8 +495,8 @@ For instance if `logger.level` is `info` *(30)* then `info` *(30)*, `warn` *(40) The `silent` logging level is a specialized level which will disable all logging, there is no `silent` log method. - -### `logger.isLevelEnabled(level)` + +### `logger.islevelenabled(level)` A utility method for determining if a given log level will write to the destination. @@ -488,13 +508,12 @@ The given level to check against: if (logger.isLevelEnabled('debug')) logger.debug('conditional log') ``` - + ### `logger.addLevel(levelLabel, levelValue) => Boolean` Defines a new level on the logger instance. -Returns `true` on success or `false` if there was a conflict (level name or -value already exist). +If the level name or value already exist the `addLevel` function will throw. ```js logger.addLevel('myLevel', 35) @@ -598,11 +617,10 @@ Also available on the exported `pino` function. ## Statics -### `pino.destination([dest]) => SonicBoom` +### `pino.destination([target]) => SonicBoom` -Create a pino destination. -It returns a stream-like object with significantly more throughput than a -standard Node.js stream. +Create a Pino Destination instance: a stream-like object with +significantly more throughput (over 30%) than a standard Node.js stream. ```js const pino = require('pino') @@ -610,15 +628,16 @@ const logger = pino(pino.destination('./my-file')) const logger2 = pino(pino.destination()) ``` -`dest` could be either a file or a file descriptor. If it is omitted, it -will be `process.stdout.fd`. +The `pino.destination` method may be passed a file path or a numerical file descriptor. +By default, `pino.destination` will use `process.stdout.fd` (1) as the file descriptor. -The default `stream` is a destination. +`pino.destination` is implemented on [`sonic-boom` ⇗]](https://github.com/mcollina/sonic-boom). -`pino.destination()` is implemented on [`sonic-boom` ⇗]](https://github.com/mcollina/sonic-boom). +* See [`destination` parameter](#destination) +* See [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom). -### `pino.extreme([dest]) => SonicBoom` +### `pino.extreme([target]) => SonicBoom` Create an extreme mode destination. This yields an additional 60% performance boost. There are trade-offs that should be understood before usage. @@ -629,23 +648,24 @@ const logger = pino(pino.extreme('./my-file')) const logger2 = pino(pino.extreme()) ``` -`dest` can be either a file or a file descriptor. If it is omitted, it -will be `process.stdout.fd`. +The `pino.extreme` method may be passed a file path or a numerical file descriptor. +By default, `pino.destination` will use `process.stdout.fd` (1) as the file descriptor. -`pino.extreme()` is implemented with the [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) +`pino.extreme` is implemented with the [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) module. -* See [Extreme mode ⇗](extreme.md). +* See [`destination` parameter](#destination) * See [`sonic-boom` ⇗](https://github.com/mcollina/sonic-boom) +* See [Extreme mode ⇗](/docs/extreme.md) - + ### `pino.stdSerializers` (Object) -Tthe `pino.stdSerializers` object provides functions for serializing objects common to many projects. The serializers are directly imported from [pino-std-serializers](https://github.com/pinojs/pino-std-serializers). +The `pino.stdSerializers` object provides functions for serializing objects common to many projects. The standard serializers are directly imported from [pino-std-serializers](https://github.com/pinojs/pino-std-serializers). * See [pino-std-serializers ⇗](https://github.com/pinojs/pino-std-serializers) - + ### `pino.stdTimeFunctions` (Object) The [`timestamp`](#opt-timestamp) option can accept a function which determines the diff --git a/docs/child-loggers.md b/docs/child-loggers.md index 3dd5af357..1f7dafb70 100644 --- a/docs/child-loggers.md +++ b/docs/child-loggers.md @@ -53,8 +53,8 @@ benchPinoExtremeChildChild*10000: 127.753ms It's possible for naming conflicts to arise between child loggers and children of child loggers. -This isn't as bad as it sounds, even if you do use the same keys between -parent and child loggers Pino resolves the conflict in the sanest way. +This isn't as bad as it sounds, even if the same keys between +parent and child loggers are used, Pino resolves the conflict in the sanest way. For example, consider the following: diff --git a/docs/extreme.md b/docs/extreme.md index 92974f35b..0483ce4c7 100644 --- a/docs/extreme.md +++ b/docs/extreme.md @@ -26,19 +26,19 @@ This has a couple of important caveats: + `SIGTERM` In all of these cases, except `SIGHUP`, the process is in a state that it - *must* terminate. Thus, if you do not register an `onTerminated` function when - constructing your Pino instance (see [pino#constructor](api.md#constructor)), + *must* terminate. Thus, if an `onTerminated` function isn't registered when + constructing a Pino instance (see [pino#constructor](api.md#constructor)), then Pino will invoke `process.exit(0)` when no error has occurred, or - `process.exit(1)` otherwise. If you do supply an `onTerminated` function, it - is left up to you to fully terminate the process. + `process.exit(1)` otherwise. If an `onTerminated` function is supplied, it + us the responsibility of the `onTerminated` function to manually exit the process. In the case of `SIGHUP`, we will look to see if any other handlers are registered for the event. If not, we will proceed as we do with all other signals. If there are more handlers registered than just our own, we will simply flush the extreme mode buffer. -So in summary, only use extreme mode if you're doing an extreme amount of -logging, and you're happy in some scenarios to lose the most recent logs. +So in summary, only use extreme mode when performing an extreme amount of +logging and it is acceptable to potentially lose the most recent logs. ## Usage @@ -67,3 +67,6 @@ buffering. In case a synchronous flush is needed, `dest.flushSync()` can be called. This method might cause some data loss if a write was already in progress, so use it only if truly needed. + +* See [`pino.extreme` api](/docs/api.md#pino-extreme) +* See [`destination` parameter](/docs/api.md#destination) diff --git a/docs/help.md b/docs/help.md index 23c4ef2cd..76c39731c 100644 --- a/docs/help.md +++ b/docs/help.md @@ -3,7 +3,7 @@ * [Log rotation](#rotate) * [Saving to multiple files](#multiple) * [Log Filtering](#filter-logs) -* [How do I use a transport with systemd?](#transport-systemd) +* [Transports and systemd](#transport-systemd) * [Duplicate keys](#dupe-keys) * [Log levels as labels instead of numbers](#level-string) * [Pino with `debug`](#debug) @@ -16,7 +16,7 @@ We recommend [logrotate](https://github.com/logrotate/logrotate). Consider we output our logs to `/var/log/myapp.log` like so: ``` -> node server.js > /var/log/myapp.log +$ node server.js > /var/log/myapp.log ``` We would rotate our log files with logrotate, by adding the following to `/etc/logrotate.d/myapp`: @@ -37,7 +37,7 @@ We would rotate our log files with logrotate, by adding the following to `/etc/l ## Saving to multiple files -Let's assume you want to store all error messages to a separate log file: +Let's assume we want to store all error messages to a separate log file. Install [pino-tee](http://npm.im/pino-tee) with: @@ -54,32 +54,38 @@ node app.js | pino-tee warn ./warn-logs > ./all-logs ## Log Filtering -The Pino authors are firm believers in using common, pre-existing, system -utilities. Thus, some recommendations for this are: +The Pino philosophy advocates common, pre-existing, system utilities. + +Some recommendations in line with this philosophy are: 1. Use [`grep`](https://linux.die.net/man/1/grep): ```sh $ # View all "INFO" level logs - $ node your_app.js | grep '"level":30' + $ node app.js | grep '"level":30' ``` 1. Use [`jq`](https://stedolan.github.io/jq/): ```sh $ # View all "ERROR" level logs - $ node node_app.js | jq 'select(.level == 50)' + $ node app.js | jq 'select(.level == 50)' ``` -## How do I use a transport with systemd? +## Transports and systemd `systemd` makes it complicated to use pipes in services. One method for overcoming this challenge is to use a subshell: ``` -ExecStart=/bin/sh -c '/path/to/node your_app.js | pino-transport' +ExecStart=/bin/sh -c '/path/to/node app.js | pino-transport' ``` ## How Pino handles duplicate keys -See the documentation on [duplicate keys](https://github.com/pinojs/pino#duplicate-keys). + +Duplicate keys are possibly when a child logger logs an object with a key that +collides with a key in the child loggers bindings. + +See the [child logger duplicate keys caveat](/docs/child-loggers.md#duplicate-keys-caveat) +for information on this is handled. ## Log levels as labels instead of numbers @@ -87,25 +93,23 @@ Pino log lines are meant to be parseable. Thus, there isn't any built-in option to change the level from the integer value to the string name. However, there are a couple of options: -1. If the only change desired is the name, i.e. you want to retain the newline -delimited JSON, then you can use a transport to make the change. One such +1. If the only change desired is the name then a transport can be used. One such transport is [`pino-text-level-transport`](https://npm.im/pino-text-level-transport). 1. Use a prettifier like [`pino-pretty`](https://npm.im/pino-pretty) to make the logs human friendly. ## Pino with `debug` -Capture debug logs in JSON format, at 10x-20x the speed: -The popular [`debug`](http://npm.im/debug) which -used in many modules accross the ecosystem. -The [`pino-debug`](http://github.com/pinojs/pino-debug) -can captures calls to the `debug` loggers and run them +The popular [`debug`](http://npm.im/debug) is used in many modules across the ecosystem. + +The [`pino-debug`](http://github.com/pinojs/pino-debug) module +can capture calls to `debug` loggers and run them through `pino` instead. This results in a 10x (20x in extreme mode) -performance improvement, while logging out more information, in the -usual JSON format. +performance improvement - event though `pino-debug` is logging additional +data and wrapping it in JSON. -The quick start way to enable this is simply to install [`pino-debug`](http://github.com/pinojs/pino-debug) +To quickly enable this install [`pino-debug`](http://github.com/pinojs/pino-debug) and preload it with the `-r` flag, enabling any `debug` logs with the `DEBUG` environment variable: diff --git a/docs/legacy.md b/docs/legacy.md index abe26ff44..6177e4b35 100644 --- a/docs/legacy.md +++ b/docs/legacy.md @@ -100,6 +100,8 @@ $ npm install -g pino-pretty $ node app.js | pino-pretty ``` +* See [Pretty Printing documentation](/docs/pretty.md) + #### Programmatic Pretty Printing The [`pino.pretty()`](https://github.com/pinojs/pino/blob/v4.x.x/docs/API.md#prettyoptions) @@ -130,6 +132,7 @@ npm install --save-dev pino-pretty ``` * See [prettyPrint option](/docs/api.md#prettyPrint) +* See [Pretty Printing documentation](/docs/pretty.md) #### Slowtime diff --git a/docs/pretty.md b/docs/pretty.md index df6230129..a15d91a09 100644 --- a/docs/pretty.md +++ b/docs/pretty.md @@ -49,7 +49,7 @@ module.exports = function myPrettifier (options) { ``` The reference implementation of such a module is the [`pino-pretty`][pp] module. -To learn more about creating your own prettifier module, learn from the +To learn more about creating a custom prettifier module, refer to the `pino-pretty` source code. Note: if the prettifier returns `undefined`, instead of a formatted line, nothing @@ -58,7 +58,7 @@ will be written to the destination stream. ### API Example > #### NOTE: -> For general usage, it is highly recommended that you pipe logs into +> For general usage, it is highly recommended that logs are piped into > the prettifier instead. Prettified logs are not easily parsed and cannot > be easily investigated at a later date. diff --git a/docs/redaction.md b/docs/redaction.md index b8751e641..db99e4d7a 100644 --- a/docs/redaction.md +++ b/docs/redaction.md @@ -4,11 +4,11 @@ To redact sensitive information, supply paths to keys that hold sensitive data using the `redact` option: ```js -var pino = require('.')({ +const logger = require('.')({ redact: ['key', 'path.to.key', 'stuff.thats[*].secret'] }) -pino.info({ +logger.info({ key: 'will be redacted', path: { to: {key: 'sensitive', another: 'thing'} @@ -34,14 +34,14 @@ an object. This allows control over *how* information is redacted. For instance, setting the censor: ```js -var pino = require('.')({ +const logger = require('.')({ redact: { paths: ['key', 'path.to.key', 'stuff.thats[*].secret'], censor: '**GDPR COMPLIANT**' } }) -pino.info({ +logger.info({ key: 'will be redacted', path: { to: {key: 'sensitive', another: 'thing'} @@ -64,14 +64,14 @@ This will output: The `redact.remove` option also allows for the key and value to be removed from output: ```js -var pino = require('.')({ +const logger = require('.')({ redact: { paths: ['key', 'path.to.key', 'stuff.thats[*].secret'], remove: true } }) -pino.info({ +logger.info({ key: 'will be redacted', path: { to: {key: 'sensitive', another: 'thing'} @@ -98,8 +98,8 @@ See [pino options in API](api.md#pino) for `redact` API details. Pino's redaction functionality is built on top of [`fast-redact`](http://github.com/davidmarkclements/fast-redact) which adds about 2% overhead to `JSON.stringify` when using paths without wildcards. -When used with pino logger with a single redacted path, any overhead is within noise - we haven't found -a way to deterministically measure it's effect. This is because its not a bottleneck. +When used with pino logger with a single redacted path, any overhead is within noise - +a way to deterministically measure it's effect has not been found. This is because its not a bottleneck. However, wildcard redaction does carry a non-trivial cost relative to explicitly declaring the keys (50% in a case where four keys are redacted across two objects). See diff --git a/docs/transports.md b/docs/transports.md index 5fc19c5a1..cd0bf3d1e 100644 --- a/docs/transports.md +++ b/docs/transports.md @@ -1,6 +1,7 @@ # Transports -A "transport" for Pino is some other tool into which the output of Pino is piped. +A "transport" for Pino is supplementary tool which consumes Pino logs. + Consider the following example: ```js @@ -9,7 +10,7 @@ const pump = require('pump') const through = require('through2') const myTransport = through.obj(function (chunk, enc, cb) { - // do whatever you want here! + // do the necessary console.log(chunk) cb() }) @@ -18,12 +19,14 @@ pump(process.stdin, split(JSON.parse), myTransport) ``` The above defines our "transport" as the file `my-transport-process.js`. -Now we can get the log data by: + +Logs can now be consumed using shell piping: ```sh node my-app-which-logs-stuff-to-stdout.js | node my-transport-process.js ``` +Ideally, a transport should consume logs in a separate process to the application, Using transports in the same process causes unnecessary load and slows down Node's single threaded event loop. @@ -49,7 +52,7 @@ $ node an-app.js | jq 'select(.level == 50)' In short, the way Pino generates logs: -1. Reduces the impact of logging on your application to an extremely minimal amount. +1. Reduces the impact of logging on an application to the absolute minimum. 2. Gives greater flexibility in how logs are processed and stored. Given all of the above, Pino recommends out-of-process log processing. @@ -63,7 +66,7 @@ For an example of this, see [pino-multi-stream][pinoms]. ## Known Transports -If you write a transport, let us know and we will add a link here! +PR's to this document are welcome for any new transports! + [pino-couch](#pino-couch) + [pino-elasticsearch](#pino-elasticsearch) @@ -79,7 +82,7 @@ If you write a transport, let us know and we will add a link here! [pino-couch][pino-couch] uploads each log line as a [CouchDB][CouchDB] document. ```sh -$ node yourapp.js | pino-couch -U https://your-server -d mylogs +$ node app.js | pino-couch -U https://couch-server -d mylogs ``` [pino-couch]: https://github.com/IBM/pino-couch @@ -95,30 +98,29 @@ to [Elasticsearch][elasticsearch], to be displayed in [Kibana][kibana]. It is extremely simple to use and setup ```sh -$ node yourapp.js | pino-elasticsearch +$ node app.js | pino-elasticsearch ``` Assuming Elasticsearch is running on localhost. -If you wish to connect to an external elasticsearch instance (recommended for production): +To connect to an external elasticsearch instance (recommended for production): -* Check that you defined `network.host` in your `elasticsearch.yml` configuration file. See [elasticsearch Network Settings documentation](https://www.elastic.co/guide/en/elasticsearch/reference/current/modules-network.html#common-network-settings) for more details. +* Check that `network.host` is defined in the `elasticsearch.yml` configuration file. See [elasticsearch Network Settings documentation](https://www.elastic.co/guide/en/elasticsearch/reference/current/modules-network.html#common-network-settings) for more details. * Launch: ```sh -$ node yourapp.js | pino-elasticsearch --host 192.168.1.42 +$ node app.js | pino-elasticsearch --host 192.168.1.42 ``` Assuming Elasticsearch is running on `192.168.1.42`. -If you wish to connect to AWS Elasticsearch: +To connect to AWS Elasticsearch: + ```sh -$ node yourapp.js | pino-elasticsearch --host https://your-url.us-east-1.es.amazonaws.com --port 443 -c ./aws_config.json +$ node app.js | pino-elasticsearch --host https://es-url.us-east-1.es.amazonaws.com --port 443 -c ./aws_config.json ``` -Then, head to your -Kibana instance, and [create an index pattern](https://www.elastic.co/guide/en/kibana/current/setup.html) on `'pino'`, -the default for `pino-elasticsearch`. +Then [create an index pattern](https://www.elastic.co/guide/en/kibana/current/setup.html) on `'pino'` (the default index key for `pino-elasticsearch`) on the Kibana instance. [pino-elasticsearch]: https://github.com/pinojs/pino-elasticsearch [elasticsearch]: https://www.elastic.co/products/elasticsearch @@ -126,26 +128,31 @@ the default for `pino-elasticsearch`. ### pino-mq -pino-mq will take all messages received on process.stdin and send them over a message bus using JSON serialization; this is more a transform for pino messages because you will need some processing on the other end of the queue(s) to process message and store them in a backend; it is useful for : -* moving your backpressure from your application to broker + +The `pino-mq` transport will take all messages received on `process.stdin` and send them over a message bus using JSON serialization. + +This useful for: + +* moving backpressure from application to broker * transforming messages pressure to another component ``` node app.js | pino-mq -u "amqp://guest:guest@localhost/" -q "pino-logs" ``` -or (recomended) +Alternatively a configuration file can be used: ``` node app.js | pino-mq -c pino-mq.json ``` -you can get a sample of configuration file by running: +A base configuration file can be initialized with: + ``` pino-mq -g ``` -for full documentation of command line switches and pino-mq.json read [readme](https://github.com/itavy/pino-mq#readme) +For full documentation of command line switches and configuration see [the `pino-mq` readme](https://github.com/itavy/pino-mq#readme) ### pino-redis @@ -153,7 +160,7 @@ for full documentation of command line switches and pino-mq.json read [readme](h [pino-redis][pino-redis] loads pino logs into [Redis][Redis]. ```sh -$ node yourapp.js | pino-redis -U redis://username:password@localhost:6379 +$ node app.js | pino-redis -U redis://username:password@localhost:6379 ``` [pino-redis]: https://github.com/buianhthang/pino-redis @@ -171,26 +178,26 @@ As an example, use `socat` to fake a listener: $ socat -v udp4-recvfrom:6000,fork exec:'/bin/cat' ``` -And then run an application that uses `pino` for logging: +Then run an application that uses `pino` for logging: ```sh -$ node yourapp.js | pino-socket -p 6000 +$ node app.js | pino-socket -p 6000 ``` -You should see the logs from your application on both consoles. +Logs from the application should be observed on both consoles. [pino-socket]: https://www.npmjs.com/package/pino-socket #### Logstash -You can also use [pino-socket][pino-socket] to upload logs to +The [pino-socket][pino-socket] module can also be used to upload logs to [Logstash][logstash] via: ``` -$ node yourapp.js | pino-socket -a 127.0.0.1 -p 5000 -m tcp +$ node app.js | pino-socket -a 127.0.0.1 -p 5000 -m tcp ``` -Assuming your logstash is running on the same host and configured as +Assuming logstash is running on the same host and configured as follows: ``` @@ -213,22 +220,22 @@ output { } ``` -See https://www.elastic.co/guide/en/kibana/current/setup.html to learn +See to learn how to setup [Kibana][kibana]. -If you are a Docker fan, you can use +For Docker users, see https://github.com/deviantony/docker-elk to setup an ELK stack. ### pino-syslog -[pino-syslog][pino-syslog] is a transport, really a "transform," that converts -*pino's* logs to [RFC3164][rfc3164] compatible log messages. *pino-syslog* does not +[pino-syslog][pino-syslog] is a transforming transport that converts +`pino` NDJSON logs to [RFC3164][rfc3164] compatible log messages. The `pino-syslog` module does not forward the logs anywhere, it merely re-writes the messages to `stdout`. But -in combination with *pino-socket*, you can relay logs to a syslog server: +when used in combination with `pino-socket` the log messages can be relayed to a syslog server: ```sh -$ node yourapp.js | pino-syslog | pino-socket -a syslog.example.com +$ node app.js | pino-syslog | pino-socket -a syslog.example.com ``` Example output for the "hello world" log: diff --git a/docs/web.md b/docs/web.md index 22df0b105..09b88ab69 100644 --- a/docs/web.md +++ b/docs/web.md @@ -86,7 +86,7 @@ async function start () { // request.log is HAPI standard way of logging request.log(['a', 'b'], 'Request into hello world') - // you can also use a pino instance, which will be faster + // a pino instance can also be used, which will be faster request.logger.info('In handler %s', request.path) return 'hello world' From 6faecd4e4095bc3d77735bd55cf9c6803217ee84 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sat, 14 Jul 2018 20:45:27 +0200 Subject: [PATCH 07/11] header level corrections --- README.md | 2 ++ docs/api.md | 8 +++++--- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index 347024a99..32d7f69f3 100644 --- a/README.md +++ b/README.md @@ -118,6 +118,8 @@ See the [Benchmarks](docs/benchmarks.md) document for comparisons. +## Communication + ### Chat on Gitter diff --git a/docs/api.md b/docs/api.md index 31b006318..1a1950d93 100644 --- a/docs/api.md +++ b/docs/api.md @@ -280,6 +280,8 @@ Each logging method has the following signature: The parameters are explained below using the `logger.info` method but the same applies to all logging methods. +### Logging Method Parameters + #### `mergingObject` (Object) @@ -578,7 +580,7 @@ $ node -p "require('pino')().levels" * See [`logger.level`](#level) -## Event: 'level-change' +### Event: 'level-change' The logger instance is also an [`EventEmitter ⇗`](https://nodejs.org/dist/latest/docs/api/events.html#events_class_eventemitter) @@ -600,14 +602,14 @@ logger.level = 'trace' // trigger event ``` -## `logger.version` (String) +### `logger.version` (String) Exposes the Pino package version. Also available on the exported `pino` function. * See [`pino.version`](#pino-version) -## `logger.LOG_VERSION` (Number) +### `logger.LOG_VERSION` (Number) Holds the current log format version as output in the `v` property of each log record. Also available on the exported `pino` function. From 9e2854a6db625afe2119e144fb9420b05d2362a2 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sun, 15 Jul 2018 23:06:10 +0200 Subject: [PATCH 08/11] rm addLevel --- docs/api.md | 23 +---------------------- 1 file changed, 1 insertion(+), 22 deletions(-) diff --git a/docs/api.md b/docs/api.md index 1a1950d93..da7b205eb 100644 --- a/docs/api.md +++ b/docs/api.md @@ -14,7 +14,6 @@ * [logger.flush()](#flush) * [logger.level](#level) * [logger.isLevelEnabled()](#islevelenabled) - * [logger.addLevel()](#addlevel) * [logger.levels](#levels) * [Event: 'level-change'](#level-change) * [logger.version](#version) @@ -50,10 +49,8 @@ Default: `'info'` One of `'fatal'`, `'error'`, `'warn'`, `'info`', `'debug'`, `'trace'` or `silent`. -Additional levels can be added to the instance via the `logger.addLevel` method or -at instantiation time with the `customLevels` property. +Additional levels can be added to the instance via the `customLevels` option. -* See [`logger.addLevel`](#addLevel) * See [`customLevels` option](#opt-customlevels) @@ -510,24 +507,6 @@ The given level to check against: if (logger.isLevelEnabled('debug')) logger.debug('conditional log') ``` - -### `logger.addLevel(levelLabel, levelValue) => Boolean` - -Defines a new level on the logger instance. - -If the level name or value already exist the `addLevel` function will throw. - -```js -logger.addLevel('myLevel', 35) -logger.myLevel('a message') -// {"level":35,"time":1531261498686,"msg":"a message","pid":67930,"hostname":"x","v":1} -``` - -When using this method, the current level of the logger instance does not change. -To do so, use the [loggerlevel](#level) property after adding the custom level. - -* See [`logger.level`](#level) - #### `levelLabel` (String) Defines the method name of the new level. From 2439cdae5e41ee916f4a35263a7524bfa423b7d2 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Sun, 15 Jul 2018 23:08:20 +0200 Subject: [PATCH 09/11] typo --- docs/extreme.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/extreme.md b/docs/extreme.md index 0483ce4c7..0cccf6f82 100644 --- a/docs/extreme.md +++ b/docs/extreme.md @@ -30,7 +30,7 @@ This has a couple of important caveats: constructing a Pino instance (see [pino#constructor](api.md#constructor)), then Pino will invoke `process.exit(0)` when no error has occurred, or `process.exit(1)` otherwise. If an `onTerminated` function is supplied, it - us the responsibility of the `onTerminated` function to manually exit the process. + is the responsibility of the `onTerminated` function to manually exit the process. In the case of `SIGHUP`, we will look to see if any other handlers are registered for the event. If not, we will proceed as we do with all other From 86f341e65f561c5ca971257178cb0ffd24010834 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Wed, 18 Jul 2018 12:30:01 +0200 Subject: [PATCH 10/11] bench doc updater --- benchmarks/utils/generate-benchmark-doc.js | 36 ++++++++++++++++++++++ benchmarks/utils/runbench.js | 23 +++++++++----- package.json | 3 +- 3 files changed, 53 insertions(+), 9 deletions(-) create mode 100644 benchmarks/utils/generate-benchmark-doc.js diff --git a/benchmarks/utils/generate-benchmark-doc.js b/benchmarks/utils/generate-benchmark-doc.js new file mode 100644 index 000000000..4007d5f4f --- /dev/null +++ b/benchmarks/utils/generate-benchmark-doc.js @@ -0,0 +1,36 @@ +'use strict' +const { join } = require('path') +const { execSync } = require('child_process') + +const run = (type) => { + process.stderr.write(`benchmarking ${type}\n`) + return execSync(`node ${join(__dirname, 'runbench')} ${type} -q`) +} + +console.log(` +# Benchmarks + +\`pino.info('hello world')\`: + +\`\`\` +${run('basic')} +\`\`\` + +\`pino.info({'hello': 'world'})\`: + +\`\`\` +${run('object')} +\`\`\` + +\`pino.info(aBigDeeplyNestedObject)\`: + +\`\`\` +${run('deep-object')} +\`\`\` + +\`pino.info('hello %s %j %d', 'world', {obj: true}, 4, {another: 'obj'})\`: + +For a fair comparison, [LogLevel](http://npm.im/loglevel) was extended +to include a timestamp and [bole](http://npm.im/bole) had +\`fastTime\` mode switched on. +`) \ No newline at end of file diff --git a/benchmarks/utils/runbench.js b/benchmarks/utils/runbench.js index 10ba392b5..93e28f354 100644 --- a/benchmarks/utils/runbench.js +++ b/benchmarks/utils/runbench.js @@ -34,6 +34,8 @@ if (!process.argv[2]) { process.exit() } +const quiet = process.argv[3] === '-q' + const selectedBenchmark = process.argv[2].toLowerCase() const benchmarkDir = resolve(__dirname, '..') const benchmarks = { @@ -66,14 +68,17 @@ function runBenchmark (name, done) { cb() }) - console.log(`Running ${name.toUpperCase()} benchmark\n`) + if (quiet === false) console.log(`Running ${name.toUpperCase()} benchmark\n`) const benchmark = spawn( process.argv[0], [join(benchmarkDir, benchmarks[name])] ) - benchmark.stdout.pipe(process.stdout) + if (quiet === false) { + benchmark.stdout.pipe(process.stdout) + } + pump(benchmark.stdout, split(), processor) benchmark.on('exit', () => { @@ -91,7 +96,7 @@ function sum (arr) { } function displayResults (results) { - console.log('==========') + if (quiet === false) console.log('==========') const benchNames = Object.keys(results) for (var i = 0; i < benchNames.length; i += 1) { console.log(`${benchNames[i].toUpperCase()} benchmark averages`) @@ -103,11 +108,13 @@ function displayResults (results) { console.log(`${loggers[j]} average: ${average.toFixed(3)}ms`) } } - console.log('==========') - console.log( - `System: ${type()}/${platform()} ${arch()} ${release()}`, - `~ ${cpus()[0].model} (cores/threads: ${cpus().length})` - ) + if (quiet === false) { + console.log('==========') + console.log( + `System: ${type()}/${platform()} ${arch()} ${release()}`, + `~ ${cpus()[0].model} (cores/threads: ${cpus().length})` + ) + } } function toBench (done) { diff --git a/package.json b/package.json index 0fd34dcc7..f9bac2e6e 100644 --- a/package.json +++ b/package.json @@ -28,7 +28,8 @@ "bench-longs-tring": "node benchmarks/utils/runbench long-string", "bench-child": "node benchmarks/utils/runbench child", "bench-child-child": "node benchmarks/utils/runbench child-child", - "bench-child-creation": "node benchmarks/utils/runbench child-creation" + "bench-child-creation": "node benchmarks/utils/runbench child-creation", + "update-bench-doc": "node benchmarks/utils/generate-benchmark-doc > docs/benchmarks.md" }, "bin": { "pino": "./bin.js" From f4683d2f19f839ea005adcbeb4e90a171642ee04 Mon Sep 17 00:00:00 2001 From: davidmarkclements Date: Wed, 18 Jul 2018 12:30:21 +0200 Subject: [PATCH 11/11] flush and flushSync --- benchmarks/utils/generate-benchmark-doc.js | 2 +- benchmarks/utils/runbench.js | 2 +- docs/api.md | 10 +++++++++- 3 files changed, 11 insertions(+), 3 deletions(-) diff --git a/benchmarks/utils/generate-benchmark-doc.js b/benchmarks/utils/generate-benchmark-doc.js index 4007d5f4f..44bd5d8aa 100644 --- a/benchmarks/utils/generate-benchmark-doc.js +++ b/benchmarks/utils/generate-benchmark-doc.js @@ -33,4 +33,4 @@ ${run('deep-object')} For a fair comparison, [LogLevel](http://npm.im/loglevel) was extended to include a timestamp and [bole](http://npm.im/bole) had \`fastTime\` mode switched on. -`) \ No newline at end of file +`) diff --git a/benchmarks/utils/runbench.js b/benchmarks/utils/runbench.js index 93e28f354..0aa7a2a96 100644 --- a/benchmarks/utils/runbench.js +++ b/benchmarks/utils/runbench.js @@ -78,7 +78,7 @@ function runBenchmark (name, done) { if (quiet === false) { benchmark.stdout.pipe(process.stdout) } - + pump(benchmark.stdout, split(), processor) benchmark.on('exit', () => { diff --git a/docs/api.md b/docs/api.md index da7b205eb..89b182c83 100644 --- a/docs/api.md +++ b/docs/api.md @@ -157,6 +157,7 @@ Default: `'msg'` The string key for the 'message' in the JSON object. + #### `onTerminated` (Function) Default: `(evt, err) => err ? process.exit(1) : process.exit(0)` @@ -470,9 +471,16 @@ child.info({test: 'will be overwritten'}) Flushes the content of the buffer when using a `pino.extreme` destination. -It has no effect if extreme mode is not enabled. +This is an asynchronous, fire and forget, operation. + +The use case is primarily for Extreme mode logging, which may hold up to +4KiB of logs. The `logger.flush` method can be used to flush the logs +on an long interval, say ten seconds. Such a strategy can provide an +optimium balanace between extremely efficient logging at high demand periods +and safer logging at low demand periods. * See [`pino.extreme`](#pino-extreme) +* See [`destination` parameter](#destination) * See [Extreme mode ⇗](/docs/extreme.md)