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 |
|
17 | When a Node process crashes from uncaught exception, exits due to a signal,
|
18 | or exits of it's own accord we may want to write some final logs – particularly
|
19 | in cases of error.
|
20 |
|
21 | Writing to a Node.js stream on exit is not necessarily guaranteed, and naively writing
|
22 | to an Extreme Mode logger on exit will definitely lead to lost logs.
|
23 |
|
24 | To write logs in an exit handler, create the handler with [`pino.final`](/docs/api.md#pino-final):
|
25 |
|
26 | ```js
|
27 | process.on('uncaughtException', pino.final(logger, (err, finalLogger) => {
|
28 | finalLogger.error(err, 'uncaughtException')
|
29 | process.exit(1)
|
30 | }))
|
31 |
|
32 | process.on('unhandledRejection', pino.final(logger, (err, finalLogger) => {
|
33 | finalLogger.error(err, 'unhandledRejection')
|
34 | process.exit(1)
|
35 | }))
|
36 | ```
|
37 |
|
38 | The `finalLogger` is a special logger instance that will synchronously and reliably
|
39 | flush every log line. This is important in exit handlers, since no more asynchronous
|
40 | activity may be scheduled.
|
41 |
|
42 | <a id="rotate"></a>
|
43 | ## Log rotation
|
44 |
|
45 | Use a separate tool for log rotation:
|
46 | We recommend [logrotate](https://github.com/logrotate/logrotate).
|
47 | Consider we output our logs to `/var/log/myapp.log` like so:
|
48 |
|
49 | ```
|
50 | $ node server.js > /var/log/myapp.log
|
51 | ```
|
52 |
|
53 | We 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 |
|
68 | The `copytruncate` configuration has a very slight possibility of lost log lines due
|
69 | to a gap between copying and truncating - the truncate may occur after additional lines
|
70 | have been written. To perform log rotation without `copytruncate`, see the [Reopening log files](#reopening)
|
71 | help.
|
72 |
|
73 | <a id="reopening"></a>
|
74 | ## Reopening log files
|
75 |
|
76 | In cases where a log rotation tool doesn't offer a copy-truncate capabilities,
|
77 | or where using them is deemed inappropriate `pino.destination` and `pino.extreme`
|
78 | destinations are able to reopen file paths after a file has been moved away.
|
79 |
|
80 | One way to use this is to set up a `SIGUSR2` or `SIGHUP` signal handler that
|
81 | reopens the log file destination, making sure to write the process PID out
|
82 | somewhere 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
|
86 | const fs = require('fs')
|
87 | fs.writeFileSync('/var/run/myapp.pid', process.pid)
|
88 |
|
89 | const dest = pino.destination('/log/file') // pino.extreme will also work
|
90 | const logger = require('pino')(dest)
|
91 | process.on('SIGHUP', () => dest.reopen())
|
92 | ```
|
93 |
|
94 | The log rotation tool can then be configured to send this signal to the process
|
95 | after a log rotation event has occurred.
|
96 |
|
97 | Given 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 |
|
118 | Let's assume we want to store all error messages to a separate log file.
|
119 |
|
120 | Install [pino-tee](http://npm.im/pino-tee) with:
|
121 |
|
122 | ```bash
|
123 | npm i pino-tee -g
|
124 | ```
|
125 |
|
126 | The following writes the log output of `app.js` to `./all-logs`, while
|
127 | writing only warnings and errors to `./warn-log:
|
128 |
|
129 | ```bash
|
130 | node app.js | pino-tee warn ./warn-logs > ./all-logs
|
131 | ```
|
132 |
|
133 | <a id="filter-logs"></a>
|
134 | ## Log Filtering
|
135 | The Pino philosophy advocates common, pre-existing, system utilities.
|
136 |
|
137 | Some recommendations in line with this philosophy are:
|
138 |
|
139 | 1. 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 | ```
|
144 | 1. 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
|
153 | this challenge is to use a subshell:
|
154 |
|
155 | ```
|
156 | ExecStart=/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 |
|
162 | Duplicate keys are possibly when a child logger logs an object with a key that
|
163 | collides with a key in the child loggers bindings.
|
164 |
|
165 | See the [child logger duplicate keys caveat](/docs/child-loggers.md#duplicate-keys-caveat)
|
166 | for information on this is handled.
|
167 |
|
168 | <a id="level-string"></a>
|
169 | ## Log levels as labels instead of numbers
|
170 | Pino log lines are meant to be parseable. Thus, Pino's default mode of operation
|
171 | is to print the level value instead of the string name. However, while it is
|
172 | possible to set the `useLevelLabels` option, we recommend using one of these
|
173 | options instead if you are able:
|
174 |
|
175 | 1. If the only change desired is the name then a transport can be used. One such
|
176 | transport is [`pino-text-level-transport`](https://npm.im/pino-text-level-transport).
|
177 | 1. Use a prettifier like [`pino-pretty`](https://npm.im/pino-pretty) to make
|
178 | the logs human friendly.
|
179 |
|
180 | <a id="debug"></a>
|
181 | ## Pino with `debug`
|
182 |
|
183 | The popular [`debug`](http://npm.im/debug) is used in many modules across the ecosystem.
|
184 |
|
185 | The [`pino-debug`](http://github.com/pinojs/pino-debug) module
|
186 | can capture calls to `debug` loggers and run them
|
187 | through `pino` instead. This results in a 10x (20x in extreme mode)
|
188 | performance improvement - even though `pino-debug` is logging additional
|
189 | data and wrapping it in JSON.
|
190 |
|
191 | To quickly enable this install [`pino-debug`](http://github.com/pinojs/pino-debug)
|
192 | and 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`
|
201 | namespaces to `pino` log levels. See [`pino-debug`](http://github.com/pinojs/pino-debug)
|
202 | for more.
|
203 |
|
204 | <a id="windows"></a>
|
205 | ## Unicode and Windows terminal
|
206 |
|
207 | Pino uses [sonic-boom](https://github.com/mcollina/sonic-boom) to speed
|
208 | up 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
|
209 | descriptor. On Windows, unicode output is not handled properly in the
|
210 | terminal (both `cmd.exe` and powershell), and as such the output could
|
211 | be visualized incorrectly if the log lines include utf8 characters. It
|
212 | is possible to configure the terminal to visualize those characters
|
213 | correctly with the use of [`chcp`](https://ss64.com/nt/chcp.html) by
|
214 | executing in the terminal `chcp 65001`. This is a known limitation of
|
215 | Node.js.
|