UNPKG

2.83 kBMarkdownView Raw
1# Child loggers
2
3Let's assume we want to have `"module":"foo"` added to every log within a
4module `foo.js`.
5
6To accomplish this, simply use a child logger:
7
8```js
9'use strict'
10// imports a pino logger instance of `require('pino')()`
11const parentLogger = require('./lib/logger')
12const log = parentLogger.child({module: 'foo'})
13
14function doSomething () {
15 log.info('doSomething invoked')
16}
17
18module.exports = {
19 doSomething
20}
21```
22
23## Cost of child logging
24
25Child logger creation is fast:
26
27```
28benchBunyanCreation*10000: 564.514ms
29benchBoleCreation*10000: 283.276ms
30benchPinoCreation*10000: 258.745ms
31benchPinoExtremeCreation*10000: 150.506ms
32```
33
34Logging through a child logger has little performance penalty:
35
36```
37benchBunyanChild*10000: 556.275ms
38benchBoleChild*10000: 288.124ms
39benchPinoChild*10000: 231.695ms
40benchPinoExtremeChild*10000: 122.117ms
41```
42
43Logging via the child logger of a child logger also has negligible overhead:
44
45```
46benchBunyanChildChild*10000: 559.082ms
47benchPinoChildChild*10000: 229.264ms
48benchPinoExtremeChildChild*10000: 127.753ms
49```
50
51## Duplicate keys caveat
52
53It's possible for naming conflicts to arise between child loggers and
54children of child loggers.
55
56This isn't as bad as it sounds, even if the same keys between
57parent and child loggers are used, Pino resolves the conflict in the sanest way.
58
59For example, consider the following:
60
61```js
62const pino = require('pino')
63pino(pino.destination('./my-log'))
64 .child({a: 'property'})
65 .child({a: 'prop'})
66 .info('howdy')
67```
68
69```sh
70$ cat my-log
71{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":1459534114473,"a":"property","a":"prop"}
72```
73
74Notice how there's two key's named `a` in the JSON output. The sub-childs properties
75appear after the parent child properties.
76
77At some point the logs will most likely be processed (for instance with a [transport](transports.md)),
78and this generally involves parsing. `JSON.parse` will return an object where the conflicting
79namespace holds the final value assigned to it:
80
81```sh
82$ cat my-log | node -e "process.stdin.once('data', (line) => console.log(JSON.stringify(JSON.parse(line))))"
83{"pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"howdy","time":"2016-04-01T18:08:34.473Z","a":"prop"}
84```
85
86Ultimately the conflict is resolved by taking the last value, which aligns with Bunyans child logging
87behavior.
88
89There may be cases where this edge case becomes problematic if a JSON parser with alternative behavior
90is used to process the logs. It's recommended to be conscious of namespace conflicts with child loggers,
91in light of an expected log processing approach.
92
93One of Pino's performance tricks is to avoid building objects and stringifying
94them, so we're building strings instead. This is why duplicate keys between
95parents and children will end up in log output.