feat: add 'http.request.id' field, @elastic/ecs-helpers@2.1.0, bump ecs.version to 8.10.0 (#163)

Closes: #133
Closes: #76

Author: trentm

docs/intro.asciidoc

@@ -17,7 +17,7 @@ popular web frameworks. A minimal log record includes the following fields:
   "@timestamp": "2021-01-13T21:32:38.095Z",
   "log.level": "info",
   "message": "hi",
-  "ecs.version": "1.6.0"
+  "ecs.version": "8.10.0"
 }
 ----
 

docs/morgan.asciidoc

@@ -86,7 +86,7 @@ similar to the following:
   "@timestamp": "2021-01-16T00:03:23.279Z",
   "log.level": "info",
   "message": "::1 - - [16/Jan/2021:00:03:23 +0000] \"GET / HTTP/1.1\" 200 13 \"-\" \"curl/7.64.1\"",
-  "ecs.version": "1.6.0",
+  "ecs.version": "8.10.0",
   "http": {
     "version": "1.1",
     "request": {

docs/pino.asciidoc

@@ -68,8 +68,8 @@ Running this will produce log output similar to the following:
 
 [source,cmd]
 ----
-{"log.level":"info","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"1.6.0","message":"Hello world"}
-{"log.level":"warn","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"1.6.0","module":"foo","message":"From child"}
+{"log.level":"info","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"8.10.0","message":"Hello world"}
+{"log.level":"warn","@timestamp":"2023-10-14T02:07:47.901Z","process.pid":56645,"host.hostname":"pink.local","ecs.version":"8.10.0","module":"foo","message":"From child"}
 ----
 
 [float]
@@ -162,7 +162,7 @@ For example:
   "@timestamp": "2023-10-14T02:10:14.477Z",
   "process.pid": 56697,
   "host.hostname": "pink.local",
-  "ecs.version": "1.6.0",
+  "ecs.version": "8.10.0",
   "http": {
     "version": "1.1",
     "request": {

docs/winston.asciidoc

@@ -79,8 +79,8 @@ Running this script (available https://github.com/elastic/ecs-logging-nodejs/blo
 [source,cmd]
 ----
 % node examples/basic.js
-{"@timestamp":"2023-10-14T02:14:17.302Z","log.level":"info","message":"hi","ecs.version":"1.6.0"}
-{"@timestamp":"2023-10-14T02:14:17.304Z","log.level":"error","message":"oops there is a problem","ecs.version":"1.6.0","foo":"bar"}
+{"@timestamp":"2023-10-14T02:14:17.302Z","log.level":"info","message":"hi","ecs.version":"8.10.0"}
+{"@timestamp":"2023-10-14T02:14:17.304Z","log.level":"error","message":"oops there is a problem","ecs.version":"8.10.0","foo":"bar"}
 ----
 
 The formatter handles serialization to JSON, so you don't need to add the
@@ -126,7 +126,7 @@ will yield (pretty-printed for readability):
     "message": "boom",
     "stack_trace": "Error: boom\n    at Object.<anonymous> (..."
   },
-  "ecs.version": "1.6.0"
+  "ecs.version": "8.10.0"
 }
 ----
 
@@ -220,7 +220,7 @@ For https://github.com/elastic/ecs-logging-nodejs/blob/main/packages/ecs-winston
   "user_agent": {
     "original": "curl/8.1.2"
   },
-  "ecs.version": "1.6.0"
+  "ecs.version": "8.10.0"
 }
 ----
 

packages/ecs-helpers/CHANGELOG.md

@@ -1,5 +1,21 @@
 # @elastic/ecs-helpers Changelog
 
+## v2.1.0
+
+- Bump the `ecs.version` from "1.6.0" to "8.10.0".
+  (https://github.com/elastic/ecs-logging-nodejs/issues/133)
+
+- `formatHttpRequest()` will now attempt to determine request ID and add it
+  to the [`http.request.id` field](https://www.elastic.co/guide/en/ecs/current/ecs-http.html#field-http-request-id).
+  This first attempts `req.id` (Fastify, express-request-id), `req.id()`
+  (Restify), and then falls back to the `request-id` or `x-request-id` headers.
+  (https://github.com/elastic/ecs-logging-nodejs/issues/76)
+
+  Note: In previous versions a `req.id` value would be added to the `event.id`
+  field. This has been removed. Please [open an issue](https://github.com/elastic/ecs-logging-nodejs/issues/new)
+  if this impacts you.
+
+
 ## v2.0.0
 
 - [Breaking change.] Drop the `serialize` method. Serialization will move to

packages/ecs-helpers/lib/http-formatters.js

@@ -17,6 +17,14 @@
 
 'use strict'
 
+// Likely HTTP request header names that would include a request ID value,
+// drawn from Fastify's [`requestIdHeader`](https://fastify.dev/docs/latest/Reference/Server/#requestidheader)
+// default, Restify's defaults (https://github.com/restify/node-restify/blob/9f1d249/lib/plugins/pre/reqIdHeaders.js#L5).
+const REQUEST_ID_HEADERS = [
+  'request-id',
+  'x-request-id'
+]
+
 // Write ECS fields for the given HTTP request (expected to be
 // `http.IncomingMessage`-y) into the `ecs` object. This returns true iff
 // the given `req` was a request object it could process.
@@ -36,7 +44,6 @@ function formatHttpRequest (ecs, req) {
   }
 
   const {
-    id,
     method,
     url,
     headers,
@@ -45,11 +52,6 @@ function formatHttpRequest (ecs, req) {
     socket
   } = req
 
-  if (id) {
-    ecs.event = ecs.event || {}
-    ecs.event.id = id
-  }
-
   ecs.http = ecs.http || {}
   ecs.http.version = httpVersion
   ecs.http.request = ecs.http.request || {}
@@ -114,6 +116,39 @@ function formatHttpRequest (ecs, req) {
     }
   }
 
+  // Attempt to set `http.request.id` field from well-known web framework APIs
+  // or from some likely headers.
+  // Note: I'm not sure whether to include Hapi's `request.info.id` generated
+  // value (https://hapi.dev/api/?v=21.3.2#-requestinfo). IIUC it does NOT
+  // consider an incoming header.
+  let id = null
+  switch (typeof (req.id)) {
+    case 'string':
+      // Fastify https://fastify.dev/docs/latest/Reference/Request/, also
+      // Express if using https://www.npmjs.com/package/express-request-id.
+      id = req.id
+      break
+    case 'number':
+      id = req.id.toString()
+      break
+    case 'function':
+      // Restify http://restify.com/docs/request-api/#id
+      id = req.id()
+      break
+  }
+  if (!id && hasHeaders) {
+    for (let i = 0; i < REQUEST_ID_HEADERS.length; i++) {
+      const k = REQUEST_ID_HEADERS[i]
+      if (headers[k]) {
+        id = headers[k]
+        break
+      }
+    }
+  }
+  if (id) {
+    ecs.http.request.id = id
+  }
+
   return true
 }
 

packages/ecs-helpers/lib/index.js

@@ -21,7 +21,7 @@ const errorFormatters = require('./error-formatters')
 const httpFormatters = require('./http-formatters')
 
 module.exports = {
-  version: '1.6.0',
+  version: '8.10.0',
   ...errorFormatters,
   ...httpFormatters
 }

packages/ecs-helpers/package.json

@@ -1,6 +1,6 @@
 {
   "name": "@elastic/ecs-helpers",
-  "version": "2.0.0",
+  "version": "2.1.0",
   "description": "ecs-logging-nodejs helpers",
   "main": "lib/index.js",
   "files": [

packages/ecs-helpers/test/express.test.js

@@ -31,7 +31,7 @@ test('express res/req serialization', t => {
   const app = express()
   let server
 
-  app.get('/', (req, res) => {
+  app.get('/apath', (req, res) => {
     const rec = {}
 
     res.setHeader('Foo', 'Bar')
@@ -45,17 +45,20 @@ test('express res/req serialization', t => {
 
     t.same(rec.user_agent, { original: 'cool-agent' })
     t.same(rec.url, {
-      path: '/',
-      full: `http://127.0.0.1:${server.address().port}/`,
+      full: `http://127.0.0.1:${server.address().port}/apath?aquery`,
+      path: '/apath',
+      query: 'aquery',
       domain: '127.0.0.1'
     })
     t.same(rec.http, {
       version: '1.1',
       request: {
+        id: 'arequestid',
         method: 'GET',
         headers: {
           'user-agent': 'cool-agent',
           host: `127.0.0.1:${server.address().port}`,
+          'x-request-id': 'arequestid',
           connection: 'close'
         }
       },
@@ -78,9 +81,13 @@ test('express res/req serialization', t => {
   app.listen(0, '127.0.0.1', function () {
     server = this
     const req = http.get(
-      `http://127.0.0.1:${server.address().port}/`,
+      `http://127.0.0.1:${server.address().port}/apath?aquery#ahash`,
       {
-        headers: { 'user-agent': 'cool-agent', connection: 'close' }
+        headers: {
+          'user-agent': 'cool-agent',
+          connection: 'close',
+          'x-request-id': 'arequestid'
+        }
       },
       function (res) {
         res.on('data', function () {})
@@ -91,6 +98,6 @@ test('express res/req serialization', t => {
         })
       }
     )
-    req.on('error', t.ifErr)
+    req.on('error', t.error)
   })
 })

packages/ecs-helpers/test/hapi.test.js

@@ -65,8 +65,10 @@ test('hapi res/req serialization', testOpts, t => {
         headers: {
           'user-agent': 'cool-agent',
           host: `127.0.0.1:${server.info.port}`,
-          connection: 'close'
-        }
+          connection: 'close',
+          'request-id': 'arequestid'
+        },
+        id: 'arequestid'
       },
       response: {
         status_code: 200,
@@ -98,8 +100,16 @@ test('hapi res/req serialization', testOpts, t => {
     t.comment('hapi server running on %s', server.info.uri)
 
     // Make a request so we trigger a 'response' event above.
-    const req = http.get(`http://127.0.0.1:${server.info.port}/`,
-      { headers: { 'user-agent': 'cool-agent', connection: 'close' } })
+    const req = http.get(
+      `http://127.0.0.1:${server.info.port}/`,
+      {
+        headers: {
+          'user-agent': 'cool-agent',
+          connection: 'close',
+          'request-id': 'arequestid'
+        }
+      }
+    )
     req.on('error', t.ifErr)
   })
 })