Repository: pinojs/hapi-pino
Pull request #165 (2022-05-26 16:33:22)

Log correct status code on aborted requests
When a request has been [abandoned](https://hapi.dev/api/?v=20.2.2#h.abandon) by hapi.js and ends ultimately aborted, then the `request.raw.res.statusCode` is only valid when headers have been flushed.

coveralls: 
[![Coverage Status](https://coveralls.io/builds/49489098/badge)](https://coveralls.io/builds/49489098)

Coverage decreased (-99.07%) to 0.0% when pulling **ed4ea8bafa81e0e3e039242e35eae0a7c5a0738d on jonathansamines:feature/status-code-aborted-requests** into **27806507920fda5db27c2daca0a99259423ba647 on pinojs:master**.


Patch:
diff --git a/README.md b/README.md
index 227d734..a29321b 100644
--- a/README.md
+++ b/README.md
@@ -101,6 +101,12 @@ events"](#hapievents) section.
 
   When enabled, add the request query as `queryParams` to the `response` event log.
 
+### `options.logPathParams: boolean`
+
+  **Default**: `false`
+
+  When enabled, add the request params as `pathParams` to the `response` event log.
+
 ### `options.logRouteTags: boolean`
 
   **Default**: `false`
diff --git a/index.d.ts b/index.d.ts
index ad0e5eb..e94deb1 100644
--- a/index.d.ts
+++ b/index.d.ts
@@ -18,6 +18,7 @@ declare namespace HapiPino {
   interface Options extends pino.LoggerOptions {
     timestamp?: boolean | (() => string) | undefined;
     logQueryParams?: boolean | undefined;
+    logPathParams?: boolean | undefined;
     logPayload?: boolean | undefined;
     logRouteTags?: boolean | undefined;
     logRequestStart?: boolean | ((req: Request) => boolean) | undefined;
diff --git a/index.js b/index.js
index 6e54cbe..0e313da 100644
--- a/index.js
+++ b/index.js
@@ -95,7 +95,7 @@ async function register (server, options) {
       : () => true
 
   const requestStartMessage = options.customRequestStartMessage || function () { return 'request start' }
-  const requestCompleteMessage = options.customRequestCompleteMessage || function (request, responseTime) { return `[response] ${request.method} ${request.path} ${request.raw.res.statusCode} (${responseTime}ms)` }
+  const requestCompleteMessage = options.customRequestCompleteMessage || function (request, responseTime) { return `[response] ${request.method} ${request.path} ${request.raw.res.headersSent ? request.raw.res.statusCode : '-'} (${responseTime}ms)` }
   const requestErrorMessage = options.customRequestErrorMessage || function (request, error) { return error.message } // Will default to `Internal Server Error` by hapi
 
   // expose logger as 'server.logger'
@@ -177,6 +177,7 @@ async function register (server, options) {
         {
           payload: options.logPayload ? request.payload : undefined,
           queryParams: options.logQueryParams ? request.query : undefined,
+          pathParams: options.logPathParams ? request.params : undefined,
           tags: options.logRouteTags ? request.route.settings.tags : undefined,
           res: request.raw.res,
           responseTime


Test patch:
diff --git a/index.test-d.ts b/index.test-d.ts
index 2612435..6d374cf 100644
--- a/index.test-d.ts
+++ b/index.test-d.ts
@@ -10,6 +10,7 @@ const server = new Server();
 const options: HapiPino.Options = {
   timestamp: () => `,"time":"${new Date(Date.now()).toISOString()}"`,
   logQueryParams: false,
+  logPathParams: false,
   logPayload: false,
   logRouteTags: false,
   logRequestStart: false,
diff --git a/test.js b/test.js
index 1737429..9166ed4 100644
--- a/test.js
+++ b/test.js
@@ -1,5 +1,7 @@
 'use strict'
 
+const net = require('net')
+const stream = require('stream')
 const Code = require('@hapi/code')
 const Lab = require('@hapi/lab')
 const Hoek = require('@hapi/hoek')
@@ -36,6 +38,11 @@ function getServer () {
       path: '/',
       handler: async (request, h) => 'ok'
     },
+    {
+      method: 'POST',
+      path: '/{foo}-{bar}',
+      handler: async (request, h) => 'ok'
+    },
     {
       method: 'GET',
       path: '/error',
@@ -285,6 +292,56 @@ experiment('logs each request', () => {
     await finish
   })
 
+  test('correctly set the status code on requests aborted during response payload processing', async (flags) => {
+    const opts = { host: '127.0.0.1', port: 3000 }
+    const server = Hapi.server(opts)
+
+    let done
+    const finish = new Promise(function (resolve, reject) {
+      done = resolve
+    })
+
+    server.route({
+      path: '/',
+      method: 'GET',
+      handler: (req, h) => {
+        const source = new stream.Readable({
+          read () {
+            if (this.called) {
+              return
+            }
+
+            this.called = true
+            this.push('delayed')
+          }
+        })
+
+        source.pipe(req.raw.res)
+        return h.abandon
+      }
+    })
+    await registerWithSink(server, 'info', (data, enc, cb) => {
+      if (data.res) {
+        expect(data.res.statusCode).to.equal(200)
+        expect(data.msg).to.match(/\[response\] get \/ - \(\d*ms\)/)
+        done()
+      }
+      cb()
+    })
+
+    await server.start()
+    flags.onCleanup = () => server.stop()
+
+    const client = net.connect(server.info.port, server.info.address, () => {
+      client.write('GET / HTTP/1.1\r\n\r\n')
+    })
+
+    client.on('data', () => {
+      client.destroy()
+    })
+    await finish
+  })
+
   test('handles 500s', async () => {
     const server = getServer()
     let count = 0
@@ -2405,3 +2462,34 @@ experiment('logging with request queryParams', () => {
     await done
   })
 })
+
+experiment('logging with request pathParams', () => {
+  test('with pre-defined req serializer', async () => {
+    const server = getServer()
+    let resolver
+    const done = new Promise((resolve, reject) => {
+      resolver = resolve
+    })
+    const stream = sink(data => {
+      expect(data.pathParams).to.equal({ foo: '42', bar: '43' })
+      resolver()
+    })
+    const logger = require('pino')(stream)
+    const plugin = {
+      plugin: Pino,
+      options: {
+        instance: logger,
+        logPathParams: true
+      }
+    }
+
+    await server.register(plugin)
+
+    await server.inject({
+      method: 'POST',
+      url: '/42-43'
+    })
+
+    await done
+  })
+})