From 02eda8772a5546ce8e54c53854361b47b17f0dac Mon Sep 17 00:00:00 2001
From: Jonny Adshead <JAdshead@users.noreply.github.com>
Date: Wed, 21 Jun 2023 08:18:04 -0700
Subject: [PATCH] fix(configureRequestLog): use default when configured with
 undefined (#1029)

* fix(configureRequestLog): use default when configured with undefined

* fix(fastify-plugin): ensure error log in onRequest hook
---
 .../utils/logging/fastifyPlugin.spec.js       | 95 +++++++++++++++++++
 src/server/utils/logging/fastifyPlugin.js     | 22 +++--
 2 files changed, 109 insertions(+), 8 deletions(-)

diff --git a/__tests__/server/utils/logging/fastifyPlugin.spec.js b/__tests__/server/utils/logging/fastifyPlugin.spec.js
index dbc754163..c08502b62 100644
--- a/__tests__/server/utils/logging/fastifyPlugin.spec.js
+++ b/__tests__/server/utils/logging/fastifyPlugin.spec.js
@@ -728,5 +728,100 @@ describe('fastifyPlugin', () => {
         });
       });
     });
+
+    it('catches and logs errors', async () => {
+      const errorSpy = jest.spyOn(console, 'error').mockImplementation(() => {});
+
+      const request = {
+        headers: {},
+      };
+      const reply = {
+        getHeader: jest.fn(),
+        raw: {},
+      };
+
+      const fastify = {
+        decorateRequest: jest.fn((name, fn) => {
+          fastify[name] = fn;
+        }),
+        addHook: jest.fn((name, fn) => {
+          if (!fastify[name]) {
+            fastify[name] = fn;
+          }
+        }),
+      };
+
+      fastifyPlugin(fastify, null, jest.fn());
+      const boomError = new Error('boom');
+      setConfigureRequestLog(() => {
+        throw boomError;
+      });
+      await expect(() => fastify.onResponse(request, reply)).rejects.toEqual(boomError);
+      expect(errorSpy).toHaveBeenCalledWith(boomError);
+    });
+  });
+
+  describe('setConfigureRequestLog', () => {
+    it('resets to default', async () => {
+      const request = {
+        headers: {},
+      };
+      const reply = {
+        getHeader: jest.fn(),
+        raw: {},
+      };
+
+      const fastify = {
+        decorateRequest: jest.fn((name, fn) => {
+          fastify[name] = fn;
+        }),
+        addHook: jest.fn((name, fn) => {
+          if (!fastify[name]) {
+            fastify[name] = fn;
+          }
+        }),
+      };
+
+      fastifyPlugin(fastify, null, jest.fn());
+      setConfigureRequestLog(() => {
+        throw new Error('shh');
+      });
+      setConfigureRequestLog();
+
+      await fastify.onResponse(request, reply);
+
+      expect(logger.info.mock.calls[0][0]).toMatchInlineSnapshot(`
+        {
+          "request": {
+            "address": {
+              "uri": "",
+            },
+            "direction": "in",
+            "metaData": {
+              "correlationId": undefined,
+              "forwarded": null,
+              "forwardedFor": null,
+              "host": null,
+              "locale": undefined,
+              "location": undefined,
+              "method": undefined,
+              "referrer": null,
+              "userAgent": null,
+            },
+            "protocol": undefined,
+            "statusCode": undefined,
+            "statusText": undefined,
+            "timings": {
+              "duration": 0,
+              "requestOverhead": NaN,
+              "responseBuilder": 0,
+              "routeHandler": NaN,
+              "ttfb": 0,
+            },
+          },
+          "type": "request",
+        }
+      `);
+    });
   });
 });
diff --git a/src/server/utils/logging/fastifyPlugin.js b/src/server/utils/logging/fastifyPlugin.js
index 1f8cfc4d9..728f77598 100644
--- a/src/server/utils/logging/fastifyPlugin.js
+++ b/src/server/utils/logging/fastifyPlugin.js
@@ -35,8 +35,9 @@ export const $RequestOverhead = Symbol('$RequestOverhead');
 export const $RouteHandler = Symbol('$RouteHandler');
 export const $ResponseBuilder = Symbol('$ResponseBuilder');
 
+const passThrough = ({ log }) => log;
 const UTILS = {
-  configureRequestLog: ({ log }) => log,
+  configureRequestLog: passThrough,
 };
 
 const getLocale = (req) => {
@@ -137,7 +138,7 @@ const logClientRequest = (request, reply) => {
   logger.info(configuredLog);
 };
 
-export const setConfigureRequestLog = (newConfigureRequestLog) => {
+export const setConfigureRequestLog = (newConfigureRequestLog = passThrough) => {
   UTILS.configureRequestLog = newConfigureRequestLog;
 };
 
@@ -200,12 +201,17 @@ const fastifyPlugin = (fastify, _opts, done) => {
   });
 
   fastify.addHook('onResponse', async (request, reply) => {
-    endTimer(request, $ResponseBuilder);
-    // same as 'reply.getResponseTime()' but our approach
-    // helps us to make the code cleaner
-    endTimer(request, $RequestFullDuration);
-
-    logClientRequest(request, reply);
+    try {
+      endTimer(request, $ResponseBuilder);
+      // same as 'reply.getResponseTime()' but our approach
+      // helps us to make the code cleaner
+      endTimer(request, $RequestFullDuration);
+
+      logClientRequest(request, reply);
+    } catch (error) {
+      console.error(error);
+      throw error;
+    }
   });
 
   done();