This commit is contained in:
davidmarkclements 2018-07-10 13:09:50 +02:00
parent 807798787b
commit bb31ed7756
13 changed files with 1335 additions and 1263 deletions

438
README.md
View File

@ -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.
[Very low overhead](#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)
## 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'
const logger = require('pino')()
var pino = require('pino')()
logger.info('hello world')
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' })
const child = logger.child({ a: 'property' })
child.info('hello child!')
var childsChild = child.child({ another: 'property' })
childsChild.info('hello baby..')
```
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.<anonymous> (/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}
{"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}
```
If you have the [`pino-pretty`](https://github.com/pinojs/pino-pretty) module
installed then you can make these logs easier to read:
For using Pino with a web framework see:
* [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)
<a name="essentials"></a>
## Essentials
### Development Formatting
The [`pino-pretty`](https://github.com/pinojs/pino-pretty) module can be used to
format logs during development:
![pretty demo](pretty-demo.png)
<a name="benchmarks"></a>
## Benchmarks
### Transports & Log Processing
As far as we know, it is one of the fastest loggers in town:
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.
`pino.info('hello world')`:
For more details see our [Transports⇗](docs/transports.md) document.
```
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
```
### Low overhead
`pino.info({'hello': 'world'})`:
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.
```
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
```
In many cases, Pino is over 5x faster than alternatives.
`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.
<a name="transports"></a>
## 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)'
```
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].
[pino-tee]: https://npm.im/pino-tee
[jq]: https://stedolan.github.io/jq/
[pinoms]: https://npm.im/pino-multi-stream
<a name="browser"></a>
## 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: <ts>}
```
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
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
}
}
}
}
})
```
<a name="caveats"></a>
## 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.
For example, consider the following:
```js
var pino = require('pino')
var fs = require('fs')
pino(fs.createWriteStream('./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. 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:
```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}
```
This equates to the same log output that Bunyan supplies.
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.
<a name="team"></a>
## The Team

File diff suppressed because it is too large Load Diff

58
docs/benchmarks.md Normal file
View File

@ -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.

199
docs/browser.md Normal file
View File

@ -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: <ts>}
```
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
}
}
}
}
})
```

95
docs/child-loggers.md Normal file
View File

@ -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.

View File

@ -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!
<a id="core"></a>
## Core

View File

@ -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)
<a id="rotate"></a>
## 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
}
```
<a id="multiple"></a>
## 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
```
<a id="filter-logs"></a>
## 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)'
```
<a id="auto-add"></a>
## 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
}
```
<a id="transport-systemd"></a>
## 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'
```
<a id="dupe-props"></a>
## How do I stop `name` from being overwritten?
See the documentation on [duplicate keys](https://github.com/pinojs/pino#duplicate-keys).
<a id="level-string"></a>
## 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.
<a id="debug"></a>
## 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.
<a id="express"></a>
## 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.
<a id="hapi"></a>
## 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.
<a id="restify"></a>
## 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.
<a id="koa"></a>
## 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.

119
docs/help.md Normal file
View File

@ -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)
<a id="rotate"></a>
## 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
}
```
<a id="multiple"></a>
## 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
```
<a id="filter-logs"></a>
## 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)'
```
<a id="transport-systemd"></a>
## 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'
```
<a id="dupe-keys"></a>
## How Pino handles duplicate keys
See the documentation on [duplicate keys](https://github.com/pinojs/pino#duplicate-keys).
<a id="level-string"></a>
## 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.
<a id="debug"></a>
## 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.

View File

@ -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!

170
docs/web.md Normal file
View File

@ -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)
<a id="fastify"></a>
## 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.
<a id="express"></a>
## 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.
<a id="hapi"></a>
## 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.
<a id="restify"></a>
## 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.
<a id="koa"></a>
## 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.
<a id="http"></a>
## 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.

View File

@ -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)
* [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)

View File

@ -5,14 +5,35 @@
<title>Pino - Super fast, all natural JSON logger for Node.js</title>
<meta name="description" content="Super fast, all natural JSON logger for Node.js">
<meta name="viewport" content="width=device-width, user-scalable=no, initial-scale=1.0, maximum-scale=1.0, minimum-scale=1.0">
<link rel="stylesheet" href="//unpkg.com/docsify/lib/themes/vue.css">
<link rel="stylesheet" href="//unpkg.com/docsify-themeable/dist/css/theme-simple.css">
<style>
:root {
--base-font-size: 16px;
--theme-color: rgb(104, 118, 52);
--link-color: rgb(104, 118, 52);
--link-color--hover: rgb(137, 152, 100);
--sidebar-name-margin: 0;
--sidebar-name-padding: 0;
--code-font-size: .9em;
}
.sidebar > h1 {
margin-bottom: -.75em;
margin-top: .75em;
}
.markdown-section a code {
color: var(--link-color)!important;
}
.markdown-section code:not([class*="lang-"]):not([class*="language-"]) {
white-space: unset
}
</style>
</head>
<body>
<div id="app"></div>
</body>
<script>
window.$docsify = {
name: 'pino',
name: '<img src=pino-tree.png style="height:4em;"><div style="margin-top:-.65em">pino</div>',
loadSidebar: 'docsify/sidebar.md',
repo: 'https://github.com/pinojs/pino',
auto2top: true,
@ -22,4 +43,5 @@
<script src="//unpkg.com/docsify/lib/docsify.min.js"></script>
<script src="//unpkg.com/docsify/lib/plugins/search.min.js"></script>
<script src="//unpkg.com/docsify/lib/plugins/ga.min.js"></script>
</html>

BIN
pino-tree.png Normal file

Binary file not shown.

After

Width:  |  Height:  |  Size: 13 KiB