Repository: pinojs/pino-http
Pull request #103 (2020-05-22 19:24:00)

Feature Request: Able to log additional properties outside req in the log line
**Feature Request:** Able to log additional properties outside `req` in the log line that depends on the request.

https://github.com/pinojs/pino-http/issues/102

A the moment, if one would like to log that is specific to the incoming http request it can only be logged within `req` object in the log line. This is can be achieved by having reqSerializer. 

Example:

```
{
  host: 'xxx',
  pid: 123,
  req: { key1: val1, key2, val2}
}
```

But if you wish to log outside the `req` object, at the moment there is no way.
Eg:
```
{
  host: 'xxx',
  pid: 123,
  req: { key1: val1},
  {key2: val2}
}
```

Please review this feature request and provide feedback. 

Proposing a new option called  `reqCustomProps`  where one could do something like this
```
   reqCustomProps: function (req) { 
     return { customProp` : req.customProp1}
 }
```
This would add `customProp` in the log line outside the `req`

Thank you.


Patch:
diff --git a/README.md b/README.md
index f2eac17..c3440a8 100644
--- a/README.md
+++ b/README.md
@@ -105,7 +105,7 @@ $ node example.js | pino-pretty
 * `customErrorMessage`: set to a `function (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.
 * `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`, and `responseTime`. 
 * `wrapSerializers`: when `false`, custom serializers will be passed the raw value directly. Defaults to `true`.
-
+* `reqCustomProps`: set to a `function (req) => { /* returns on object */ }` or `{ /* returns on object */ }` This function will be invoked for each request with `req` where we could pass additional properties that needs to be logged outside the `req`.   
 `stream`: the destination stream. Could be passed in as an option too.
 
 #### Examples
@@ -160,14 +160,20 @@ var logger = require('pino-http')({
   customErrorMessage: function (error, res) {
     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
+  reqCustomProps: function (req) {
+    return {
+      customProp: req.customProp
+    }
+  } 
 })
 
 function handle (req, res) {
diff --git a/logger.js b/logger.js
index e67e5b7..0ecd958 100644
--- a/logger.js
+++ b/logger.js
@@ -20,6 +20,8 @@ function pinoLogger (opts, stream) {
   var responseTimeKey = opts.customAttributeKeys.responseTime || 'responseTime'
   delete opts.customAttributeKeys
 
+  var reqCustomProps = opts.reqCustomProps || {}
+
   opts.wrapSerializers = 'wrapSerializers' in opts ? opts.wrapSerializers : true
   if (opts.wrapSerializers) {
     opts.serializers = Object.assign({}, opts.serializers)
@@ -88,7 +90,15 @@ function pinoLogger (opts, stream) {
     var shouldLogSuccess = true
 
     req.id = genReqId(req)
-    req.log = res.log = logger.child({ [reqKey]: req })
+
+    var log = logger.child({ [reqKey]: req })
+
+    if (reqCustomProps) {
+      var customPropBindings = (typeof reqCustomProps === 'function') ? reqCustomProps(req) : reqCustomProps
+      log = log.child(customPropBindings)
+    }
+    req.log = res.log = log
+
     res[startTime] = res[startTime] || Date.now()
 
     if (autoLogging) {


Test patch:
diff --git a/test.js b/test.js
index b227b1c..d465428 100644
--- a/test.js
+++ b/test.js
@@ -734,3 +734,69 @@ test('uses custom log object attribute keys when provided, error request', funct
     t.end()
   })
 })
+
+test('uses custom request properties to log additional attributes when provided', function (t) {
+  var dest = split(JSON.parse)
+  function customPropsHandler (req) {
+    if (req) {
+      return {
+        key1: 'value1',
+        key2: 'value2'
+      }
+    }
+  }
+  var logger = pinoHttp({
+    reqCustomProps: customPropsHandler
+  }, dest)
+
+  setup(t, logger, function (err, server) {
+    t.error(err)
+    doGet(server)
+  })
+
+  dest.on('data', function (line) {
+    t.equal(line.key1, 'value1')
+    t.equal(line.key2, 'value2')
+    t.end()
+  })
+})
+
+test('uses custom request properties to log additional attributes; custom props is an object instead of callback', function (t) {
+  var dest = split(JSON.parse)
+  var logger = pinoHttp({
+    reqCustomProps: { key1: 'value1' }
+  }, dest)
+
+  setup(t, logger, function (err, server) {
+    t.error(err)
+    doGet(server)
+  })
+
+  dest.on('data', function (line) {
+    t.equal(line.key1, 'value1')
+    t.end()
+  })
+})
+
+test('dont pass custom request properties to log additional attributes', function (t) {
+  var dest = split(JSON.parse)
+  var logger = pinoHttp({
+    reqCustomProps: undefined
+  }, dest)
+
+  setup(t, logger, function (err, server) {
+    t.error(err)
+    doGet(server)
+  })
+
+  dest.on('data', function (line) {
+    t.ok(line.hostname, 'hostname is defined')
+    t.ok(line.level, 'level is defined')
+    t.ok(line.msg, 'msg is defined')
+    t.ok(line.pid, 'pid is defined')
+    t.ok(line.req, 'req is defined')
+    t.ok(line.res, 'res is defined')
+    t.ok(line.time, 'time is defined')
+    t.end()
+  })
+})