pino-http
High-speed HTTP logger for Node.js
To our knowledge, pino-http
is the fastest HTTP logger in town.
Benchmarks
Benchmarks log each request/response pair while returning
'hello world'
, using
autocannon with 100
connections and 10 pipelined requests.
http-ndjson
(equivalent info): 7730.73 req/sechttp-ndjson
(standard minimum info): 9522.37 req/secpino-http
: 21496 req/secpino-http
(extreme): 25770.91 req/sec- no logger: 46139.64 req/sec
All benchmarks where taken on a Macbook Pro 2013 (2.6GHZ i7, 16GB of RAM).
Install
npm i pino-http --save
Example
'use strict'
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)
$ node example.js | pino-pretty
[2016-03-31T16:53:21.079Z] INFO (46316 on MBP-di-Matteo): something else
req: {
"id": 1,
"method": "GET",
"url": "/",
"headers": {
"host": "localhost:3000",
"user-agent": "curl/7.43.0",
"accept": "*/*"
},
"remoteAddress": "::1",
"remotePort": 64386
}
[2016-03-31T16:53:21.087Z] INFO (46316 on MBP-di-Matteo): request completed
res: {
"statusCode": 200,
"header": "HTTP/1.1 200 OK\r\nX-Powered-By: restify\r\nContent-Type: text/html; charset=utf-8\r\nContent-Length: 11\r\nETag: W/\"b-XrY7u+Ae7tCTyyK7j1rNww\"\r\nDate: Thu, 31 Mar 2016 16:53:21 GMT\r\nConnection: keep-alive\r\n\r\n"
}
responseTime: 10
req: {
"id": 1,
"method": "GET",
"url": "/",
"headers": {
"host": "localhost:3000",
"user-agent": "curl/7.43.0",
"accept": "*/*"
},
"remoteAddress": "::1",
"remotePort": 64386
}
API
pinoHttp([opts], [stream])
opts
: it has all the options as pino and
logger
: parent pino instance for a child logger instance, which will be used by pino-http
. To refer to this child instance, use pinoHttp.loggergenReqId
: you can pass a function which gets used to generate a request id. The first argument is the request itself. As fallback pino-http
is just using an integer. This default might not be the desired behavior if you're running multiple instances of the appuseLevel
: the logger level pino-http
is using to log out the response. default: info
customLogLevel
: set to a function (req, res, err) => { /* returns level name string */ }
. This function will be invoked to determine the level at which the log should be issued (silent
will prevent logging). This option is mutually exclusive with the useLevel
option. The first two arguments are the HTTP request and response. The third argument is an error object if an error has occurred in the request.autoLogging
: set to false
, to disable the automatic "request completed" and "request errored" logging. Defaults to true
. If set to an object, you can provide more options.autoLogging.ignore
: set to a function (req) => { /* returns boolean */ }
. Useful for defining logic based on req properties (such as a user-agent header) to ignore successful requests.stream
: same as the second parametercustomReceivedMessage
: set to a function (req, res) => { /* returns message string */ }
This function will be invoked at each request received, setting "msg" property to returned string. If not set, nothing value will be used.customReceivedObject
: set to a function (req, res, loggableObject) => { /* returns loggable object */ }
This function will be invoked at each request received, replacing the base loggable received object. When set, it is up to the reponsibility of the caller to merge with the loggableObject
parameter. If not set, default value will be used.customSuccessMessage
: set to a function (req, res) => { /* returns message string */ }
This function will be invoked at each successful response, setting "msg" property to returned string. If not set, default value will be used.customSuccessObject
: set to a function (req, res, loggableObject) => { /* returns loggable object */ }
This function will be invoked at each successful response, replacing the base loggable success object. When set, it is up to the reponsibility of the caller to merge with the loggableObject
parameter. If not set, default value will be used.customErrorMessage
: set to a function (req, res, err) => { /* returns message string */ }
This function will be invoked at each failed response, setting "msg" property to returned string. If not set, default value will be used.customErrorObject
: set to a function (req, res, err, loggableObject) => { /* returns loggable object */ }
This function will be invoked at each failed response, the base loggable error object. When set, it is up to the reponsibility of the caller to merge with the loggableObject
parameter. If not set, default value will be used.customAttributeKeys
: allows the log object attributes added by pino-http
to be given custom keys. Accepts an object of format { [original]: [override] }
. Attributes available for override are req
, res
, err
, responseTime
and, when using quietReqLogger, reqId
.wrapSerializers
: when false
, custom serializers will be passed the raw value directly. Defaults to true
.customProps
: set to a function (req, res) => { /* returns on object */ }
or { /* returns on object */ }
This function will be invoked for each request with req
and res
where we could pass additional properties that need to be logged outside the req
.quietReqLogger
: when true
, the child logger available on req.log
will no longer contain the full bindings and will now only have the request id bound at reqId
(note: the autoLogging messages and the logger available on res.log
will remain the same except they will also have the additional reqId
property). default: false
quietResLogger
: when true
, the child logger available on res.log
will no longer contain the full bindings and will now only have the request id bound at reqId
(note: the autoLogging message sent on request completion will only contain req
). default: false
stream
: the destination stream. Could be passed in as an option too.
Examples
Use as Express middleware
const express = require('express')
const logger = require('pino-http')
const app = express()
app.use(logger())
function handle (req, res) {
req.log.info('something else')
res.end('hello world')
}
app.listen(3000)
Logger options
'use strict'
const http = require('http')
const server = http.createServer(handle)
const { randomUUID } = require('node:crypto')
const pino = require('pino')
const logger = require('pino-http')({
logger: pino(),
genReqId: function (req, res) {
const existingID = req.id ?? req.headers["x-request-id"]
if (existingID) return existingID
const id = randomUUID()
res.setHeader('X-Request-Id', id)
return id
},
serializers: {
err: pino.stdSerializers.err,
req: pino.stdSerializers.req,
res: pino.stdSerializers.res
},
wrapSerializers: true,
useLevel: 'info',
customLogLevel: function (req, res, err) {
if (res.statusCode >= 400 && res.statusCode < 500) {
return 'warn'
} else if (res.statusCode >= 500 || err) {
return 'error'
} else if (res.statusCode >= 300 && res.statusCode < 400) {
return 'silent'
}
return 'info'
},
customSuccessMessage: function (req, res) {
if (res.statusCode === 404) {
return 'resource not found'
}
return `${req.method} completed`
},
customReceivedMessage: function (req, res) {
return 'request received: ' + req.method
},
customErrorMessage: function (req, res, err) {
return 'request errored with status code: ' + res.statusCode
},
customAttributeKeys: {
req: 'request',
res: 'response',
err: 'error',
responseTime: 'timeTaken'
},
customProps: function (req, res) {
return {
customProp: req.customProp,
customProp2: res.locals.myCustomData
}
}
})
function handle (req, res) {
logger(req, res)
req.log.info('something else')
res.log.info('just in case you need access to logging when only the response is in scope')
res.end('hello world')
}
server.listen(3000)
Structured Object Hooks
It is possible to override the default structured object with your own. The hook is provided with the
pino-http base object so that you can merge in your own keys.
This is useful in scenarios where you want to augment core pino-http logger object with your own event
labels.
If you simply want to change the message which is logged then check out the custom[Received|Error|Success]Message
hooks e.g. customReceivedMessage
const logger = require('pino-http')({
customReceivedObject: (req, res, val) => {
return {
category: 'ApplicationEvent',
eventCode: 'REQUEST_RECEIVED'
};
},
customSuccessObject: (req, res, val) => {
return {
...val,
category: 'ApplicationEvent',
eventCode:
res.statusCode < 300
? 'REQUEST_PROCESSED'
: 'REQUEST_FAILED'
};
},
customErrorObject: (req, res, error, val) => {
const store = storage.getStore();
const formattedBaggage = convertBaggageToObject(store?.baggage);
return {
...val,
category: 'ApplicationEvent',
eventCode: 'REQUEST_FAILED'
};
}
})
PinoHttp.logger (P.Logger)
The pinoHttp
instance has a property logger
, which references to an actual logger instance, used
by pinoHttp. This instance will be a child of an instance, passed as opts.logger
, or a fresh one,
if no opts.logger
is passed. It can be used, for example, for doing most of the things, possible
to do with any pino
instance, for example changing logging level in runtime, like so:
const pinoHttp = require('pinoHttp')();
pinoHttp.logger.level = 'silent';
pinoHttp.startTime (Symbol)
The pinoHttp
function has a property called startTime
which contains a symbol
that is used to attach and reference a start time on the HTTP res
object. If the function
returned from pinoHttp
is not the first function to be called in an HTTP servers request
listener function then the responseTime
key in the log output will be offset by any
processing that happens before a response is logged. This can be corrected by manually attaching
the start time to the res
object with the pinoHttp.startTime
symbol, like so:
const http = require('http')
const logger = require('pino-http')()
const someImportantThingThatHasToBeFirst = require('some-important-thing')
http.createServer((req, res) => {
res[logger.startTime] = Date.now()
someImportantThingThatHasToBeFirst(req, res)
logger(req, res)
res.log.info('log is available on both req and res');
res.end('hello world')
}).listen(3000)
Custom formatters
You can customize the format of the log output by passing a Pino transport.
const logger = require('pino-http')({
quietReqLogger: true,
transport: {
target: 'pino-http-print',
options: {
destination: 1,
all: true,
translateTime: true
}
}
})
Default serializers
pinoHttp.stdSerializers.req
Generates a JSONifiable object from the HTTP request
object passed to
the createServer
callback of Node's HTTP server.
It returns an object in the form:
{
pid: 93535,
hostname: 'your host',
level: 30,
msg: 'my request',
time: '2016-03-07T12:21:48.766Z',
v: 0,
req: {
id: 42,
method: 'GET',
url: '/',
headers: {
host: 'localhost:50201',
connection: 'close'
},
remoteAddress: '::ffff:127.0.0.1',
remotePort: 50202
}
}
pinoHttp.stdSerializers.res
Generates a JSONifiable object from the HTTP response
object passed to
the createServer
callback of Node's HTTP server.
It returns an object in the form:
{
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'
}
}
Custom serializers
Each of the standard serializers can be extended by supplying a corresponding
custom serializer. For example, let's assume the request
object has custom
properties attached to it, and that all of the custom properties are prefixed
by foo
. In order to show these properties, along with the standard serialized
properties, in the resulting logs, we can supply a serializer like:
const logger = require('pino-http')({
serializers: {
req (req) {
Object.keys(req.raw).forEach((k) => {
if (k.startsWith('foo')) {
req[k] = req.raw[k]
}
})
return req
}
}
})
If you prefer to work with the raw value directly, or you want to honor the custom
serializers already defined by opts.logger
, you can pass in opts.wrapSerializers
as false
:
const logger = require('pino-http')({
wrapSerializers: false,
serializers: {
req (req) {
return {
message: req.foo
};
}
}
})
Logging request body
Logging of requests' bodies is disabled by default since it can cause security risks such as having private user information (password, other GDPR-protected data, etc.) logged (and persisted in most setups). However if enabled, sensitive information can be redacted as per redaction documentation.
Furthermore, logging more bytes does slow down throughput. This video by pino maintainers Matteo Collina & David Mark Clements goes into this in more detail.
After considering these factors, logging of the request body can be achieved as follows:
const http = require('http')
const logger = require('pino-http')({
serializers: {
req(req) {
req.body = req.raw.body;
return req;
},
},
});
Custom serializers + custom log attribute keys
If custom attribute keys for req
, res
, or err
log keys have been provided, serializers will be applied with the following order of precedence:
serializer matching custom key
> serializer matching default key
> default pino serializer
Team
Matteo Collina
https://github.com/mcollina
https://www.npmjs.com/~matteo.collina
https://twitter.com/matteocollina
David Mark Clements
https://github.com/davidmarkclements
https://www.npmjs.com/~davidmarkclements
https://twitter.com/davidmarkclem
Acknowledgements
This project was kindly sponsored by nearForm.
Logo and identity designed by Beibhinn Murphy O'Brien: https://www.behance.net/BeibhinnMurphyOBrien.
License
MIT