UNPKG

7.13 kBMarkdownView Raw
1# Help
2
3* [Exit logging](#exit-logging)
4* [Log rotation](#rotate)
5* [Reopening log files](#reopening)
6* [Saving to multiple files](#multiple)
7* [Log filtering](#filter-logs)
8* [Transports and systemd](#transport-systemd)
9* [Duplicate keys](#dupe-keys)
10* [Log levels as labels instead of numbers](#level-string)
11* [Pino with `debug`](#debug)
12* [Unicode and Windows terminal](#windows)
13
14<a id="exit-logging"></a>
15## Exit logging
16
17When a Node process crashes from uncaught exception, exits due to a signal,
18or exits of it's own accord we may want to write some final logs – particularly
19in cases of error.
20
21Writing to a Node.js stream on exit is not necessarily guaranteed, and naively writing
22to an Extreme Mode logger on exit will definitely lead to lost logs.
23
24To write logs in an exit handler, create the handler with [`pino.final`](/docs/api.md#pino-final):
25
26```js
27process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
28 finalLogger.error(err, 'uncaughtException')
29 process.exit(1)
30}))
31
32process.on('unhandledRejection', pino.final(logger, (err, finalLogger) => {
33 finalLogger.error(err, 'unhandledRejection')
34 process.exit(1)
35}))
36```
37
38The `finalLogger` is a special logger instance that will synchronously and reliably
39flush every log line. This is important in exit handlers, since no more asynchronous
40activity may be scheduled.
41
42<a id="rotate"></a>
43## Log rotation
44
45Use a separate tool for log rotation:
46We recommend [logrotate](https://github.com/logrotate/logrotate).
47Consider we output our logs to `/var/log/myapp.log` like so:
48
49```
50$ node server.js > /var/log/myapp.log
51```
52
53We would rotate our log files with logrotate, by adding the following to `/etc/logrotate.d/myapp`:
54
55```
56/var/log/myapp.log {
57 su root
58 daily
59 rotate 7
60 delaycompress
61 compress
62 notifempty
63 missingok
64 copytruncate
65}
66```
67
68The `copytruncate` configuration has a very slight possibility of lost log lines due
69to a gap between copying and truncating - the truncate may occur after additional lines
70have been written. To perform log rotation without `copytruncate`, see the [Reopening log files](#reopening)
71help.
72
73<a id="reopening"></a>
74## Reopening log files
75
76In cases where a log rotation tool doesn't offer a copy-truncate capabilities,
77or where using them is deemed inappropriate `pino.destination` and `pino.extreme`
78destinations are able to reopen file paths after a file has been moved away.
79
80One way to use this is to set up a `SIGUSR2` or `SIGHUP` signal handler that
81reopens the log file destination, making sure to write the process PID out
82somewhere so the log rotation tool knows where to send the signal.
83
84```js
85// write the process pid to a well known location for later
86const fs = require('fs')
87fs.writeFileSync('/var/run/myapp.pid', process.pid)
88
89const dest = pino.destination('/log/file') // pino.extreme will also work
90const logger = require('pino')(dest)
91process.on('SIGHUP', () => dest.reopen())
92```
93
94The log rotation tool can then be configured to send this signal to the process
95after a log rotation event has occurred.
96
97Given a similar scenario as in the [Log rotation](#rotate) section a basic
98`logrotate` config that aligns with this strategy would look similar to the following:
99
100```
101/var/log/myapp.log {
102 su root
103 daily
104 rotate 7
105 delaycompress
106 compress
107 notifempty
108 missingok
109 postrotate
110 kill -HUP `cat /var/run/myapp.pid`
111 endscript
112}
113```
114
115<a id="multiple"></a>
116## Saving to multiple files
117
118Let's assume we want to store all error messages to a separate log file.
119
120Install [pino-tee](http://npm.im/pino-tee) with:
121
122```bash
123npm i pino-tee -g
124```
125
126The following writes the log output of `app.js` to `./all-logs`, while
127writing only warnings and errors to `./warn-log:
128
129```bash
130node app.js | pino-tee warn ./warn-logs > ./all-logs
131```
132
133<a id="filter-logs"></a>
134## Log Filtering
135The Pino philosophy advocates common, pre-existing, system utilities.
136
137Some recommendations in line with this philosophy are:
138
1391. Use [`grep`](https://linux.die.net/man/1/grep):
140 ```sh
141 $ # View all "INFO" level logs
142 $ node app.js | grep '"level":30'
143 ```
1441. Use [`jq`](https://stedolan.github.io/jq/):
145 ```sh
146 $ # View all "ERROR" level logs
147 $ node app.js | jq 'select(.level == 50)'
148 ```
149
150<a id="transport-systemd"></a>
151## Transports and systemd
152`systemd` makes it complicated to use pipes in services. One method for overcoming
153this challenge is to use a subshell:
154
155```
156ExecStart=/bin/sh -c '/path/to/node app.js | pino-transport'
157```
158
159<a id="dupe-keys"></a>
160## How Pino handles duplicate keys
161
162Duplicate keys are possibly when a child logger logs an object with a key that
163collides with a key in the child loggers bindings.
164
165See the [child logger duplicate keys caveat](/docs/child-loggers.md#duplicate-keys-caveat)
166for information on this is handled.
167
168<a id="level-string"></a>
169## Log levels as labels instead of numbers
170Pino log lines are meant to be parseable. Thus, Pino's default mode of operation
171is to print the level value instead of the string name. However, while it is
172possible to set the `useLevelLabels` option, we recommend using one of these
173options instead if you are able:
174
1751. If the only change desired is the name then a transport can be used. One such
176transport is [`pino-text-level-transport`](https://npm.im/pino-text-level-transport).
1771. Use a prettifier like [`pino-pretty`](https://npm.im/pino-pretty) to make
178the logs human friendly.
179
180<a id="debug"></a>
181## Pino with `debug`
182
183The popular [`debug`](http://npm.im/debug) is used in many modules across the ecosystem.
184
185The [`pino-debug`](http://github.com/pinojs/pino-debug) module
186can capture calls to `debug` loggers and run them
187through `pino` instead. This results in a 10x (20x in extreme mode)
188performance improvement - even though `pino-debug` is logging additional
189data and wrapping it in JSON.
190
191To quickly enable this install [`pino-debug`](http://github.com/pinojs/pino-debug)
192and preload it with the `-r` flag, enabling any `debug` logs with the
193`DEBUG` environment variable:
194
195```sh
196$ npm i pino-debug
197$ DEBUG=* node -r pino-debug app.js
198```
199
200[`pino-debug`](http://github.com/pinojs/pino-debug) also offers fine grain control to map specific `debug`
201namespaces to `pino` log levels. See [`pino-debug`](http://github.com/pinojs/pino-debug)
202for more.
203
204<a id="windows"></a>
205## Unicode and Windows terminal
206
207Pino uses [sonic-boom](https://github.com/mcollina/sonic-boom) to speed
208up logging. Internally, it uses [`fs.write`](https://nodejs.org/dist/latest-v10.x/docs/api/fs.html#fs_fs_write_fd_string_position_encoding_callback) to write log lines directly to a file
209descriptor. On Windows, unicode output is not handled properly in the
210terminal (both `cmd.exe` and powershell), and as such the output could
211be visualized incorrectly if the log lines include utf8 characters. It
212is possible to configure the terminal to visualize those characters
213correctly with the use of [`chcp`](https://ss64.com/nt/chcp.html) by
214executing in the terminal `chcp 65001`. This is a known limitation of
215Node.js.