High-speed HTTP logger for Node.js
To our knowledge,pino-httpis thefastestHTTP logger in town.
Benchmarks log each request/response pair while returning
'hello world',using
autocannonwith 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).
npm i pino-http --save
'use strict'
consthttp=require('http')
constserver=http.createServer(handle)
constlogger=require('pino-http')()
functionhandle(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
}
opts:it has all the options aspinoand
logger:parent pino instance for a child logger instance, which will be used bypino-http.To refer to this child instance, usepinoHttp.loggergenReqId:you can pass a function which gets used to generate a request id. The first argument is the request itself. As fallbackpino-httpis just using an integer. This default might not be the desired behavior if you're running multiple instances of the appuseLevel:the logger levelpino-httpis using to log out the response. default:infocustomLogLevel:set to afunction (req, res, err) => { /* returns level name string */ }.This function will be invoked to determine the level at which the log should be issued (silentwill prevent logging). This option is mutually exclusive with theuseLeveloption. 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 tofalse,to disable the automatic "request completed" and "request errored" logging. Defaults totrue.If set to an object, you can provide more options.autoLogging.ignore:set to afunction (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 afunction (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 afunction (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 theloggableObjectparameter. If not set, default value will be used.customSuccessMessage:set to afunction (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 afunction (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 theloggableObjectparameter. If not set, default value will be used.customErrorMessage:set to afunction (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 afunction (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 theloggableObjectparameter. If not set, default value will be used.customAttributeKeys:allows the log object attributes added bypino-httpto be given custom keys. Accepts an object of format{ [original]: [override] }.Attributes available for override arereq,res,err,responseTimeand, when using quietReqLogger,reqId.wrapSerializers:whenfalse,custom serializers will be passed the raw value directly. Defaults totrue.customProps:set to afunction (req, res) => { /* returns on object */ }or{ /* returns on object */ }This function will be invoked for each request withreqandreswhere we could pass additional properties that need to be logged outside thereq.quietReqLogger:whentrue,the child logger available onreq.logwill no longer contain the full bindings and will now only have the request id bound atreqId(note: the autoLogging messages and the logger available onres.logwill remain the same except they will also have the additionalreqIdproperty). default:falsequietResLogger:whentrue,the child logger available onres.logwill no longer contain the full bindings and will now only have the request id bound atreqId(note: the autoLogging message sent on request completion will only containreq). default:false
stream:the destination stream. Could be passed in as an option too.
constexpress=require('express')
constlogger=require('pino-http')
constapp=express()
app.use(logger())
functionhandle(req,res){
req.log.info('something else')
res.end('hello world')
}
app.listen(3000)'use strict'
consthttp=require('http')
constserver=http.createServer(handle)
const{randomUUID}=require('node:crypto')
constpino=require('pino')
constlogger=require('pino-http')({
// Reuse an existing logger instance
logger:pino(),
// Define a custom request id function
genReqId:function(req,res){
constexistingID=req.id??req.headers["x-request-id"]
if(existingID)returnexistingID
constid=randomUUID()
res.setHeader('X-Request-Id',id)
returnid
},
// Define custom serializers
serializers:{
err:pino.stdSerializers.err,
req:pino.stdSerializers.req,
res:pino.stdSerializers.res
},
// Set to `false` to prevent standard serializers from being wrapped.
wrapSerializers:true,
// Logger level is `info` by default
useLevel:'info',
// Define a custom logger level
customLogLevel:function(req,res,err){
if(res.statusCode>=400&&res.statusCode<500){
return'warn'
}elseif(res.statusCode>=500||err){
return'error'
}elseif(res.statusCode>=300&&res.statusCode<400){
return'silent'
}
return'info'
},
// Define a custom success message
customSuccessMessage:function(req,res){
if(res.statusCode===404){
return'resource not found'
}
return`${req.method}completed`
},
// Define a custom receive message
customReceivedMessage:function(req,res){
return'request received: '+req.method
},
// Define a custom error message
customErrorMessage:function(req,res,err){
return'request errored with status code: '+res.statusCode
},
// Override attribute keys for the log object
customAttributeKeys:{
req:'request',
res:'response',
err:'error',
responseTime:'timeTaken'
},
// Define additional custom request properties
customProps:function(req,res){
return{
customProp:req.customProp,
// user request-scoped data is in res.locals for express applications
customProp2:res.locals.myCustomData
}
}
})
functionhandle(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)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
constlogger=require('pino-http')({
//... remaining config omitted for brevity
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)=>{
conststore=storage.getStore();
constformattedBaggage=convertBaggageToObject(store?.baggage);
return{
...val,
category:'ApplicationEvent',
eventCode:'REQUEST_FAILED'
};
}
//...remaining config omitted for brevity
})ThepinoHttpinstance has a propertylogger,which references to an actual logger instance, used
by pinoHttp. This instance will be a child of an instance, passed asopts.logger,or a fresh one,
if noopts.loggeris passed. It can be used, for example, for doing most of the things, possible
to do with anypinoinstance, for example changing logging level in runtime, like so:
constpinoHttp=require('pinoHttp')();
pinoHttp.logger.level='silent';ThepinoHttpfunction has a property calledstartTimewhich contains a symbol
that is used to attach and reference a start time on the HTTPresobject. If the function
returned frompinoHttpis notthe firstfunction to be called in an HTTP servers request
listener function then theresponseTimekey 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 theresobject with thepinoHttp.startTimesymbol, like so:
consthttp=require('http')
constlogger=require('pino-http')()
constsomeImportantThingThatHasToBeFirst=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)You can customize the format of the log output by passing aPino transport.
constlogger=require('pino-http')({
quietReqLogger:true,// turn off the default logging output
transport:{
target:'pino-http-print',// use the pino-http-print transport and its formatting output
options:{
destination:1,
all:true,
translateTime:true
}
}
})Generates a JSONifiable object from the HTTPrequestobject passed to
thecreateServercallback 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
}
}Generates a JSONifiable object from the HTTPresponseobject passed to
thecreateServercallback 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'
}
}Each of the standard serializers can be extended by supplying a corresponding
custom serializer. For example, let's assume therequestobject has custom
properties attached to it, and that all of the custom properties are prefixed
byfoo.In order to show these properties, along with the standard serialized
properties, in the resulting logs, we can supply a serializer like:
constlogger=require('pino-http')({
serializers:{
req(req){
Object.keys(req.raw).forEach((k)=>{
if(k.startsWith('foo')){
req[k]=req.raw[k]
}
})
returnreq
}
}
})If you prefer to work with the raw value directly, or you want to honor the custom
serializers already defined byopts.logger,you can pass inopts.wrapSerializers
asfalse:
constlogger=require('pino-http')({
wrapSerializers:false,
serializers:{
req(req){
// `req` is the raw `IncomingMessage` object, not the already serialized request from `pino.stdSerializers.req`.
return{
message:req.foo
};
}
}
})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 perredaction documentation.
Furthermore, logging more bytes does slow down throughput.This video by pino maintainers Matteo Collina & David Mark Clementsgoes into this in more detail.
After considering these factors, logging of the request body can be achieved as follows:
consthttp=require('http')
constlogger=require('pino-http')({
serializers:{
req(req){
req.body=req.raw.body;
returnreq;
},
},
});If custom attribute keys forreq,res,orerrlog 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
https:// npmjs /~matteo.collina
https://twitter /matteocollina
https://github /davidmarkclements
https:// npmjs /~davidmarkclements
https://twitter /davidmarkclem
This project was kindly sponsored bynearForm.
Logo and identity designed by Beibhinn Murphy O'Brien:https:// behance.net/BeibhinnMurphyOBrien.
MIT
![@dependabot[bot]](https://avatars.githubusercontent.com/in/29110?s=64&v=4){kind=small}
