test: add tests for request id

jmcdo29 · Sep 4, 2020 · ee60e6a · ee60e6a
1 parent fdf5ef7
commit ee60e6a
Show file tree

Hide file tree

Showing 12 changed files with 136 additions and 77 deletions.
diff --git a/integration/test/gql.spec.ts b/integration/test/gql.spec.ts
@@ -94,12 +94,15 @@ describe.each`
               query: `${type} ${name}{ ${name}{ hello }}`,
             });
             const logObject = logSpy.mock.calls[0][0];
+            const requestId = logSpy.mock.calls[0][2];
             expect(logObject).toBeALogObject(
               type,
               '/graphql',
               'HTTP/1.1',
               status,
             );
+            expect(typeof requestId).toBe('string');
+            expect(requestId).toHaveLength(16);
           });
         },
       );

diff --git a/integration/test/grpc.spec.ts b/integration/test/grpc.spec.ts
@@ -81,7 +81,11 @@ describe('GrpcParser', () => {
         await httpPromise(baseUrl + url);
         expect(logSpy).toBeCalledTimes(1);
         const logObject = logSpy.mock.calls[0][0];
+        const requestId = logSpy.mock.calls[0][2];
+
         expect(logObject).toBeALogObject('gRPC', endpoint, 'grpc', status);
+        expect(typeof requestId).toBe('string');
+        expect(requestId).toHaveLength(16);
       },
     );
 

diff --git a/integration/test/http.spec.ts b/integration/test/http.spec.ts
@@ -76,6 +76,12 @@ describe.each`
         expect(logSpy).toHaveBeenCalledTimes(1);
       }
 
+      function expectRequestId() {
+        const requestId = logSpy.mock.calls[0][2];
+        expect(typeof requestId).toBe('string');
+        expect(requestId).toHaveLength(16);
+      }
+
       describe('/', () => {
         it.each`
           method      | status
@@ -97,12 +103,14 @@ describe.each`
           const data = await httpPromise(baseUrl + '/status');
           expect(data).toEqual(hello);
           expectLogObject('GET', '/status', color.green(202));
+          expectRequestId();
         });
       });
       describe('/error', () => {
         it('should log a 400', async () => {
           await httpPromise(baseUrl + '/error');
           expectLogObject('GET', '/error', color.yellow(400));
+          expectRequestId();
         });
       });
       describe('skip', () => {

diff --git a/integration/test/rpc.spec.ts b/integration/test/rpc.spec.ts
@@ -134,12 +134,16 @@ describe.each`
           await httpPromise(baseUrl + url);
           expect(logSpy).toBeCalledTimes(1);
           const logObject = logSpy.mock.calls[0][0];
+          const requestId = logSpy.mock.calls[0][2];
+
           expect(logObject).toBeALogObject(
             server,
             JSON.stringify(endpoint),
             protocol,
             status,
           );
+          expect(typeof requestId).toBe('string');
+          expect(requestId).toHaveLength(16);
         },
       );
 

diff --git a/integration/test/ws.spec.ts b/integration/test/ws.spec.ts
@@ -102,12 +102,16 @@ describe.each`
           await wsPromise(ws, serializer(message), sendMethod);
           expect(logSpy).toHaveBeenCalledTimes(1);
           const logObject = logSpy.mock.calls[0][0];
+          const requestId = logSpy.mock.calls[0][2];
+
           expect(logObject).toBeALogObject(
             server.toLowerCase(),
             message,
             'WS',
             status,
           );
+          expect(typeof requestId).toBe('string');
+          expect(requestId).toHaveLength(16);
         },
       );
       it('should get the data from skip but not log', async () => {

diff --git a/packages/logger/test/ogma.spec.ts b/packages/logger/test/ogma.spec.ts
@@ -34,8 +34,16 @@ describe('Ogma Class', () => {
   function createOgmaInstance(options: Partial<OgmaOptions>): Ogma {
     return new Ogma(options);
   }
-  function mockCallExpectation(ogma: Ogma, expectation: string) {
-    ogma.log('Hello');
+  function mockCallExpectation(
+    ogma: Ogma,
+    expectation: string,
+    options: {
+      context?: string;
+      applicaiton?: string;
+      requestId?: string;
+    } = {},
+  ) {
+    ogma.log('Hello', options.context, options.applicaiton, options.requestId);
     expect(mockStream.write.mock.calls[0][0]).toEqual(
       expect.stringContaining(expectation),
     );
@@ -98,6 +106,26 @@ describe('Ogma Class', () => {
         mockCallExpectation(ogma, expectation));
     },
   );
+  describe.each`
+    requestId             | expectation
+    ${'1598961763272766'} | ${Color.white('1598961763272766')}
+    ${null}               | ${''}
+  `(
+    'requestId: $requestId',
+    ({
+      requestId,
+      expectation,
+    }: {
+      requestId?: string;
+      expectation: string;
+    }) => {
+      beforeEach(() => {
+        ogma = createOgmaInstance({ stream: mockStream });
+      });
+      it('should add the requestId to the log', () =>
+        mockCallExpectation(ogma, expectation, { requestId }));
+    },
+  );
   describe.each`
     application   | expectation
     ${'test app'} | ${Color.yellow('[test app]')}

diff --git a/packages/nestjs-module/src/ogma-core.module.ts b/packages/nestjs-module/src/ogma-core.module.ts
@@ -17,7 +17,6 @@ import {
   OGMA_SERVICE_OPTIONS,
 } from './ogma.constants';
 import {
-  createOgmaInterceptorFactory,
   createOgmaInterceptorOptionsFactory,
   createOgmaProvider,
   createOgmaServiceOptions,

diff --git a/packages/nestjs-module/src/ogma.provider.ts b/packages/nestjs-module/src/ogma.provider.ts
@@ -1,39 +1,22 @@
-import {
-  CallHandler,
-  ExecutionContext,
-  NestInterceptor,
-  Provider,
-  Scope,
-} from '@nestjs/common';
-import { Reflector, REQUEST } from '@nestjs/core';
+import { Provider, Scope } from '@nestjs/common';
+import { REQUEST as CONTEXT, Reflector } from '@nestjs/core';
 import { Ogma, OgmaOptions } from '@ogma/logger';
-import { Observable } from 'rxjs';
 import {
   OGMA_INSTANCE,
   OGMA_REQUEST_SCOPED_SERVICE_TOKEN,
   OGMA_SERVICE_TOKEN,
   OgmaInterceptorProviderError,
 } from './ogma.constants';
 import { OgmaService } from './ogma.service';
-import {
-  AbstractInterceptorService,
-  DelegatorService,
-} from './interceptor/providers';
+import { AbstractInterceptorService } from './interceptor/providers';
 import {
   OgmaInterceptorOptions,
   OgmaModuleOptions,
   OgmaServiceOptions,
   Type,
 } from './interfaces';
-import { OgmaInterceptor } from './interceptor/ogma.interceptor';
 import { RequestContext } from './interfaces/request-context.interface';
 
-export class NoopInterceptor implements NestInterceptor {
-  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
-    return next.handle();
-  }
-}
-
 /**
  * @internal
  */
@@ -73,21 +56,6 @@ export function createOgmaServiceOptions(
   return options.service;
 }
 
-export function createOgmaInterceptorFactory(
-  options: OgmaInterceptorOptions | false,
-  service: OgmaService,
-  delegate: DelegatorService,
-  reflector: Reflector,
-): NestInterceptor {
-  let interceptor: NestInterceptor;
-  if (options) {
-    interceptor = new OgmaInterceptor(options, service, delegate, reflector);
-  } else {
-    interceptor = new NoopInterceptor();
-  }
-  return interceptor;
-}
-
 export function createProviderToken(topic: string): string {
   return OGMA_SERVICE_TOKEN + ':' + topic;
 }
@@ -119,7 +87,7 @@ export function createRequestScopedLoggerProviders(
   const token = createRequestScopedProviderToken(topic);
   return [
     {
-      inject: [OGMA_INSTANCE, REQUEST],
+      inject: [OGMA_INSTANCE, CONTEXT],
       provide: token,
       scope: Scope.REQUEST,
       useFactory: (

diff --git a/packages/nestjs-module/src/ogma.service.ts b/packages/nestjs-module/src/ogma.service.ts
@@ -56,8 +56,8 @@ export class OgmaService implements LoggerService {
    * @param context Optional context if you want to change what the original context was
    * @param requestId Optional id of an request
    */
-  public error(message: any, context?: string, requestId?: string): void {
-    this.printMessage(message, 'error', context, requestId);
+  public error(message: any, context?: string): void {
+    this.printMessage(message, 'error', context);
   }
 
   /**

diff --git a/packages/nestjs-module/test/delegator.service.spec.ts b/packages/nestjs-module/test/delegator.service.spec.ts
@@ -14,13 +14,15 @@ import {
 
 const logProperly = (type: 'http' | 'gql' | 'ws' | 'rpc') =>
   `should log properly for ${type}`;
+const setRequestIdProperly = (type: 'http' | 'gql' | 'ws' | 'rpc') =>
+  `should set request id properly for ${type}`;
 
 const abstractInterceptorServiceMock = () =>
   createMock<AbstractInterceptorService>();
 
 const spyFactory = (
   parser: AbstractInterceptorService,
-  method: 'getSuccessContext' | 'getErrorContext',
+  method: 'getSuccessContext' | 'getErrorContext' | 'setRequestId',
 ): jest.SpyInstance => jest.spyOn(parser, method);
 
 const parserReturn: LogObject = {
@@ -202,6 +204,41 @@ describe('DelegatorService', () => {
       expect(spy).toBeCalledWith(error, ctxMock, startTime, options);
     });
   });
+  describe('setRequestId', () => {
+    const requestId = '1598961763272766';
+    it(setRequestIdProperly('rpc'), () => {
+      const spy = spyFactory(rpc, 'setRequestId');
+      const ctxMock = createMock<ExecutionContext>({
+        getType: () => 'rpc',
+      });
+      delegate.setRequestId(ctxMock, requestId);
+      expect(spy).toBeCalledWith(ctxMock, requestId);
+    });
+    it(setRequestIdProperly('http'), () => {
+      const spy = spyFactory(http, 'setRequestId');
+      const ctxMock = createMock<ExecutionContext>(
+        httpContext as Partial<ExecutionContext>,
+      );
+      delegate.setRequestId(ctxMock, requestId);
+      expect(spy).toBeCalledWith(ctxMock, requestId);
+    });
+    it(setRequestIdProperly('ws'), () => {
+      const spy = spyFactory(ws, 'setRequestId');
+      const ctxMock = createMock<ExecutionContext>({
+        getType: () => 'ws',
+      });
+      delegate.setRequestId(ctxMock, requestId);
+      expect(spy).toBeCalledWith(ctxMock, requestId);
+    });
+    it(setRequestIdProperly('gql'), () => {
+      const spy = spyFactory(gql, 'setRequestId');
+      const ctxMock = createMock<ExecutionContext>({
+        getType: () => 'graphql',
+      });
+      delegate.setRequestId(ctxMock, requestId);
+      expect(spy).toBeCalledWith(ctxMock, requestId);
+    });
+  });
   describe('useJsonFormat', () => {
     it('should return as JSON instead of string', () => {
       const spy = spyFactory(http, 'getSuccessContext').mockReturnValueOnce(

diff --git a/packages/nestjs-module/test/ogma.interceptor.spec.ts b/packages/nestjs-module/test/ogma.interceptor.spec.ts
@@ -238,11 +238,11 @@ describe('OgmaInterceptor', () => {
           name: 'methodName',
         }),
       });
-      interceptor.log('logValue', ctxMock);
+      interceptor.log('logValue', ctxMock, '1598961763272766');
       expect(logSpy).toBeCalledWith(
         'logValue',
         'className#methodName',
-        undefined,
+        '1598961763272766',
       );
     });
   });