Merge pull request #2 from well-known-components/breaking/rename-comp…

…onent-creation

BREAKING: Rename component creation into instrumentHttpServerWithRequestLogger

README.md

@@ -9,21 +9,21 @@ This component logs each incoming request and response. When a request is initia
 The HTTP requests logger component is pretty straightforward to use, just import the component and initialize it with the log and the server components before any router:
 
 ```ts
-import { createHttpRequestsLogger } from '@well-known-components/http-requests-logger'
+import { instrumentHttpServerWithRequestLogger } from '@well-known-components/http-requests-logger'
 import { createConfigComponent } from '@well-known-components/env-config-provider'
 import { createServerComponent } from '@well-known-components/http-server'
 import { createLogComponent } from '@well-known-components/logger'
 
 const config = createConfigComponent(process.env, defaultValues)
 const server = await createServerComponent<GlobalContext>({ config, logs }, { cors, compression: {} })
 const logs = await createLogComponent()
-createHttpRequestsLogger({ server, logger: logs })
+instrumentHttpServerWithRequestLogger({ server, logger: logs })
 ```
 
 Although only the server and the log components are required for this component to work, it is recommended to be used alongside the [tracer](https://github.com/well-known-components/tracer-component) and [http-tracer components](https://github.com/well-known-components/http-tracer-component) to make it possible to track and match each of the input and output requests.
 
 ```ts
-import { createHttpRequestsLogger } from '@well-known-components/http-requests-logger'
+import { instrumentHttpServerWithRequestLogger } from '@well-known-components/http-requests-logger'
 import { createConfigComponent } from '@well-known-components/env-config-provider'
 import { createServerComponent } from '@well-known-components/http-server'
 import { createLogComponent } from '@well-known-components/logger'
@@ -35,7 +35,7 @@ const config = createConfigComponent(process.env, defaultValues)
 const server = await createServerComponent<GlobalContext>({ config, logs }, { cors, compression: {} })
 const logs = await createLogComponent()
 createHttpTracerComponent({ server, tracer })
-createHttpRequestsLogger({ server, logger: logs })
+instrumentHttpServerWithRequestLogger({ server, logger: logs })
 ```
 
 This set up, alongside the default configurations, will produce the following logs:

src/component.ts

@@ -3,7 +3,7 @@ import { HEALTH_PATH } from './constants'
 import { shouldSkip } from './logic'
 import { RequestLoggerConfigurations, Verbosity } from './types'
 
-export function createHttRequestsLogger(
+export function instrumentHttpServerWithRequestLogger(
   components: {
     server: IHttpServerComponent<object>
     logger: ILoggerComponent
@@ -15,7 +15,7 @@ export function createHttRequestsLogger(
   const inLogger = logger.getLogger('http-in')
   const outLogger = logger.getLogger('http-out')
 
-  server.use((ctx: IHttpServerComponent.DefaultContext<object>, next) => {
+  server.use(async (ctx: IHttpServerComponent.DefaultContext<object>, next) => {
     const skipInput = config?.skipInput
     const skipOutput = config?.skipOutput
     // Skip health checks by default
@@ -25,13 +25,31 @@ export function createHttRequestsLogger(
     if (!skipInput && !skip) {
       inLogger[verbosity](inLog)
     }
-    return next().then(response => {
-      if (!skipOutput && !skip) {
+    let response: IHttpServerComponent.IResponse | undefined = undefined
+
+    try {
+      response = await next()
+      return response
+    } catch (e) {
+      // Craft a custom response with the purpose of printing the log
+      let statusCode = 200
+      if (typeof e === 'object' && e !== null && e !== undefined) {
+        if ('status' in e && typeof e.status == 'number') {
+          statusCode = e.status
+        } else if ('statusCode' in e && typeof e.statusCode == 'number') {
+          statusCode = e.statusCode
+        }
+      }
+      response = {
+        status: statusCode
+      }
+      throw e
+    } finally {
+      if (!skipOutput && !skip && response) {
         outLogger[verbosity](
           config?.outputLog ? config.outputLog(ctx.request, response) : `[${ctx.request.method}: ${ctx.url.pathname}][${response.status}]`
         )
       }
-      return response
-    })
+    }
   })
 }

test/component.spec.ts

@@ -1,5 +1,5 @@
 import { IHttpServerComponent, ILoggerComponent } from '@well-known-components/interfaces'
-import { createHttRequestsLogger } from '../src/component'
+import { instrumentHttpServerWithRequestLogger } from '../src/component'
 import { RequestLoggerConfigurations, Verbosity } from '../src/types'
 
 let options: RequestLoggerConfigurations
@@ -54,7 +54,7 @@ let response: IHttpServerComponent.IResponse
 
 describe('when initializing the component', () => {
   beforeEach(() => {
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
   })
 
   it('should instantiate the output and the input loggers', () => {
@@ -66,7 +66,7 @@ describe('when initializing the component', () => {
 describe('when the verbosity configuration is set', () => {
   beforeEach(async () => {
     options.verbosity = Verbosity.DEBUG
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
     response = await storedMiddleware(mockedContext, mockedNext)
   })
 
@@ -84,7 +84,7 @@ describe('when the verbosity configuration is set', () => {
 describe('when the verbosity configuration is not set', () => {
   beforeEach(async () => {
     options.verbosity = undefined
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
     response = await storedMiddleware(mockedContext, mockedNext)
   })
 
@@ -103,7 +103,7 @@ describe('when the skip output configuration is set', () => {
   describe('and is set to true', () => {
     beforeEach(async () => {
       options.skipOutput = true
-      createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
       response = await storedMiddleware(mockedContext, mockedNext)
     })
 
@@ -121,7 +121,7 @@ describe('when the skip output configuration is set', () => {
   describe('and is set to false', () => {
     beforeEach(async () => {
       options.skipOutput = false
-      createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
       response = await storedMiddleware(mockedContext, mockedNext)
     })
 
@@ -140,7 +140,7 @@ describe('when the skip output configuration is set', () => {
 describe('when the skip output configuration is not set', () => {
   beforeEach(async () => {
     options.skipOutput = undefined
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
     response = await storedMiddleware(mockedContext, mockedNext)
   })
 
@@ -159,7 +159,7 @@ describe('when the skip input configuration is set', () => {
   describe('and is set to true', () => {
     beforeEach(async () => {
       options.skipInput = true
-      createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
       response = await storedMiddleware(mockedContext, mockedNext)
     })
 
@@ -177,7 +177,7 @@ describe('when the skip input configuration is set', () => {
   describe('and is set to false', () => {
     beforeEach(async () => {
       options.skipInput = false
-      createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
       response = await storedMiddleware(mockedContext, mockedNext)
     })
 
@@ -196,7 +196,7 @@ describe('when the skip input configuration is set', () => {
 describe('when the skip input configuration is not set', () => {
   beforeEach(async () => {
     options.skipInput = undefined
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
     response = await storedMiddleware(mockedContext, mockedNext)
   })
 
@@ -214,7 +214,7 @@ describe('when the skip input configuration is not set', () => {
 describe('when the skip parameter is set', () => {
   beforeEach(() => {
     options.skip = '/v1/endpoint'
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
   })
 
   describe('and the log should be skipped', () => {
@@ -257,7 +257,7 @@ describe('when the skip parameter is not set', () => {
     options.skip = undefined
     mockedContext.request.url = 'http://localhost/health/live'
     mockedContext.url = new URL('http://localhost/health/live')
-    createHttRequestsLogger({ server: serverMock, logger: loggerMock }, options)
+    instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
     response = await storedMiddleware(mockedContext, mockedNext)
   })
 
@@ -271,3 +271,33 @@ describe('when the skip parameter is not set', () => {
     expect(response).toEqual(mockedResponse)
   })
 })
+
+describe('when any of the following middlewares fail', () => {
+  let error: object
+
+  describe('and the failure is caused with an error containing an status code', () => {
+    beforeEach(() => {
+      error = { status: 400, statusCode: 400 }
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
+      mockedNext = jest.fn().mockRejectedValueOnce(error)
+    })
+
+    it('should log the output correctly based on the status code of the exception and propagate the error', async () => {
+      await expect(storedMiddleware(mockedContext, mockedNext)).rejects.toEqual(error)
+      expect(loggers[1]?.info).toHaveBeenCalledWith(`[${mockedContext.request.method}: ${mockedContext.url.pathname}][400]`)
+    })
+  })
+
+  describe('and the failure is caused without an http error', () => {
+    beforeEach(() => {
+      error = { message: 'An error occurred' }
+      instrumentHttpServerWithRequestLogger({ server: serverMock, logger: loggerMock }, options)
+      mockedNext = jest.fn().mockRejectedValueOnce(error)
+    })
+
+    it('should log the output correctly using the status code as 200', async () => {
+      await expect(storedMiddleware(mockedContext, mockedNext)).rejects.toEqual(error)
+      expect(loggers[1]?.info).toHaveBeenCalledWith(`[${mockedContext.request.method}: ${mockedContext.url.pathname}][200]`)
+    })
+  })
+})