GraphQL logging support

packages/logging-interceptor/package.json

@@ -33,9 +33,14 @@
     "access": "public"
   },
   "peerDependencies": {
+    "@nestjs/apollo": ">=5",
     "@nestjs/common": ">=5",
     "@nestjs/core": ">=5",
+    "@nestjs/graphql": ">=5",
+    "apollo-server": ">=2",
+    "apollo-server-express": ">=2",
     "express": ">=4",
+    "graphql": ">=15",
     "rxjs": ">=6"
   }
 }

packages/logging-interceptor/src/logging.interceptor.ts

@@ -7,10 +7,75 @@ import {
   Logger,
   NestInterceptor,
 } from '@nestjs/common';
+import { GqlContextType, GqlExecutionContext } from '@nestjs/graphql';
 import { Request, Response } from 'express';
+import { IncomingHttpHeaders } from 'http';
 import { Observable } from 'rxjs';
 import { tap } from 'rxjs/operators';
 
+/**
+ * Util method, obtains http request metadata from the execution context
+ * @param context details about the current request
+ */
+function getRequestMeta(context: ExecutionContext): {
+  method: string;
+  url: string;
+  body: Record<string, unknown>;
+  headers: IncomingHttpHeaders;
+} {
+  if (context.getType<GqlContextType>() === 'graphql') {
+    const gqlContext: GqlExecutionContext = GqlExecutionContext.create(context);
+    const _req: Request | undefined = gqlContext.getContext().req;
+    if (typeof _req === 'undefined') {
+      throw new Error(
+        `'req' object not found on context, please ensure you have provided a 'req' argument to the context passed to GraphQL execution `,
+      );
+    }
+
+    return {
+      method: _req.method,
+      url: _req.baseUrl,
+      body: _req.body,
+      headers: _req.headers,
+    };
+  }
+  const req: Request = context.switchToHttp().getRequest<Request>();
+
+  return {
+    method: req.method,
+    url: req.url,
+    body: req.body,
+    headers: req.headers,
+  };
+}
+
+/**
+ * Util method, obtains http response metadata from the execution context
+ * @param context details about the current request
+ */
+function getResponseMeta(context: ExecutionContext): {
+  statusCode: number;
+} {
+  if (context.getType<GqlContextType>() === 'graphql') {
+    const gqlContext: GqlExecutionContext = GqlExecutionContext.create(context);
+    const _res: Response | undefined = gqlContext.getContext().res;
+    if (typeof _res === 'undefined') {
+      throw new Error(
+        `'res' object not found on context, please ensure you have provided a 'res' argument to the context passed to GraphQL execution `,
+      );
+    }
+
+    return {
+      statusCode: _res.statusCode,
+    };
+  }
+  const res: Response = context.switchToHttp().getResponse<Response>();
+
+  return {
+    statusCode: res.statusCode,
+  };
+}
+
 /**
  * Interceptor that logs input/output requests
  */
@@ -34,8 +99,7 @@ export class LoggingInterceptor implements NestInterceptor {
    * @param call$ implements the handle method that returns an Observable
    */
   public intercept(context: ExecutionContext, call$: CallHandler): Observable<unknown> {
-    const req: Request = context.switchToHttp().getRequest();
-    const { method, url, body, headers } = req;
+    const { method, url, body, headers } = getRequestMeta(context);
     const ctx: string = `${this.userPrefix}${this.ctxPrefix} - ${method} - ${url}`;
     const message: string = `Incoming request - ${method} - ${url}`;
 
@@ -67,10 +131,8 @@ export class LoggingInterceptor implements NestInterceptor {
    * @param context details about the current request
    */
   private logNext(body: unknown, context: ExecutionContext): void {
-    const req: Request = context.switchToHttp().getRequest<Request>();
-    const res: Response = context.switchToHttp().getResponse<Response>();
-    const { method, url } = req;
-    const { statusCode } = res;
+    const { method, url } = getRequestMeta(context);
+    const { statusCode } = getResponseMeta(context);
     const ctx: string = `${this.userPrefix}${this.ctxPrefix} - ${statusCode} - ${method} - ${url}`;
     const message: string = `Outgoing response - ${statusCode} - ${method} - ${url}`;
 
@@ -89,8 +151,7 @@ export class LoggingInterceptor implements NestInterceptor {
    * @param context details about the current request
    */
   private logError(error: Error, context: ExecutionContext): void {
-    const req: Request = context.switchToHttp().getRequest<Request>();
-    const { method, url, body } = req;
+    const { method, url, body } = getRequestMeta(context);
 
     if (error instanceof HttpException) {
       const statusCode: number = error.getStatus();

packages/logging-interceptor/test/logging.interceptor.test.ts

@@ -149,4 +149,135 @@ describe('Logging interceptor', () => {
 
     expect(warnSpy).not.toHaveBeenCalled();
   });
+
+  // GraphQL Tests
+
+  it('logs the input and output request details (GraphQL) - OK status code', async () => {
+    const logSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'log');
+    const url: string = `/graphql`;
+
+    await request(app.getHttpServer()).post(url).send({ query: '{ok{message}}' }).expect(HttpStatus.OK);
+
+    const ctx: string = `LoggingInterceptor - POST - ${url}`;
+    const resCtx: string = `LoggingInterceptor - 200 - POST - ${url}`;
+    const incomingMsg: string = `Incoming request - POST - ${url}`;
+    const outgoingMsg: string = `Outgoing response - 200 - POST - ${url}`;
+
+    /**
+     * Info level
+     */
+    expect(logSpy).toBeCalledTimes(2);
+    expect(logSpy.mock.calls[0]).toEqual([
+      {
+        body: {
+          query: '{ok{message}}',
+        },
+        headers: expect.any(Object),
+        message: incomingMsg,
+        method: `POST`,
+      },
+      ctx,
+    ]);
+    expect(logSpy.mock.calls[1]).toEqual([
+      {
+        message: outgoingMsg,
+        body: { message: `This action returns all cats` },
+      },
+      resCtx,
+    ]);
+  });
+
+  it('logs the input and output request details (GraphQL) - BAD_REQUEST status code', async () => {
+    const logSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'log');
+    const warnSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'warn');
+    const errorSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'error');
+    const url: string = `/graphql`;
+
+    await request(app.getHttpServer()).post(url).send({ query: '{badRequest{message}}' }).expect(HttpStatus.OK);
+
+    const ctx: string = `LoggingInterceptor - POST - ${url}`;
+    const resCtx: string = `LoggingInterceptor - 400 - POST - ${url}`;
+    const incomingMsg: string = `Incoming request - POST - ${url}`;
+    const outgoingMsg: string = `Outgoing response - 400 - POST - ${url}`;
+
+    /**
+     * Info level
+     */
+    expect(logSpy).toBeCalledTimes(1);
+    expect(logSpy.mock.calls[0]).toEqual([
+      {
+        body: {
+          query: '{badRequest{message}}',
+        },
+        headers: expect.any(Object),
+        message: incomingMsg,
+        method: `POST`,
+      },
+      ctx,
+    ]);
+
+    expect(warnSpy).toBeCalledTimes(1);
+    expect(warnSpy.mock.calls[0]).toEqual([
+      {
+        message: outgoingMsg,
+        method: 'POST',
+        url: url,
+        body: {
+          query: '{badRequest{message}}',
+        },
+        error: expect.any(BadRequestException),
+      },
+      resCtx,
+    ]);
+
+    expect(errorSpy).not.toHaveBeenCalled();
+  });
+
+  it('logs the input and output request details (GraphQL) - INTERNAL_SERVER_ERROR status code', async () => {
+    const logSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'log');
+    const warnSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'warn');
+    const errorSpy: jest.SpyInstance = jest.spyOn(Logger.prototype, 'error');
+    const url: string = '/graphql';
+
+    // await request(app.getHttpServer()).get(url).expect(HttpStatus.INTERNAL_SERVER_ERROR);
+    await request(app.getHttpServer()).post(url).send({ query: '{internalerror{message}}' }).expect(HttpStatus.OK);
+
+    const ctx: string = `LoggingInterceptor - POST - ${url}`;
+    const resCtx: string = `LoggingInterceptor - 500 - POST - ${url}`;
+    const incomingMsg: string = `Incoming request - POST - ${url}`;
+    const outgoingMsg: string = `Outgoing response - 500 - POST - ${url}`;
+
+    /**
+     * Info level
+     */
+    expect(logSpy).toBeCalledTimes(1);
+    expect(logSpy.mock.calls[0]).toEqual([
+      {
+        body: {
+          query: '{internalerror{message}}',
+        },
+        headers: expect.any(Object),
+        message: incomingMsg,
+        method: `POST`,
+      },
+      ctx,
+    ]);
+
+    expect(errorSpy).toBeCalledTimes(1);
+    expect(errorSpy.mock.calls[0]).toEqual([
+      {
+        message: outgoingMsg,
+        method: 'POST',
+        url: url,
+        body: {
+          query: '{internalerror{message}}',
+        },
+        error: expect.any(InternalServerErrorException),
+      },
+      expect.any(String),
+      resCtx,
+    ]);
+
+    expect(warnSpy).not.toHaveBeenCalled();
+  });
 });

packages/logging-interceptor/test/test-app/cats/cats.module.ts

@@ -1,10 +1,12 @@
 import { Module } from '@nestjs/common';
 import { CatsController } from './cats.controller';
+import { CatsResolver } from './cats.resolver';
 
 /**
  * Cats module
  */
 @Module({
+  providers: [CatsResolver],
   controllers: [CatsController],
 })
 export class CatsModule {}

packages/logging-interceptor/test/test-app/cats/cats.resolver.ts

@@ -0,0 +1,30 @@
+import { BadRequestException, InternalServerErrorException } from '@nestjs/common';
+import { Query, Resolver } from '@nestjs/graphql';
+
+/**
+ * Resolver: /cats
+ */
+@Resolver()
+export class CatsResolver {
+  /**
+   * Fetching cats ok
+   */
+  @Query('ok')
+  public ok(): unknown {
+    return { message: 'This action returns all cats' };
+  }
+  /**
+   * Fetching bad request
+   */
+  @Query('badRequest')
+  public badRequest(): unknown {
+    throw new BadRequestException();
+  }
+  /**
+   * Fetching internalerror
+   */
+  @Query('internalerror')
+  public internalerror(): unknown {
+    throw new InternalServerErrorException();
+  }
+}

packages/logging-interceptor/test/test-app/cats/cats.schema.gql

@@ -0,0 +1,9 @@
+type Cat {
+    message: String
+}
+
+type Query {
+  ok: Cat
+  badRequest: Cat
+  internalerror: Cat
+}

packages/logging-interceptor/test/test-app/core/core.module.ts

@@ -1,11 +1,22 @@
+import { ApolloDriver, ApolloDriverConfig } from '@nestjs/apollo';
 import { Module } from '@nestjs/common';
 import { APP_INTERCEPTOR } from '@nestjs/core';
+import { GraphQLModule } from '@nestjs/graphql';
+
 import { LoggingInterceptor } from '../../../src';
 
 /**
  * Core module: This module sets the logging interceptor as a global interceptor
  */
 @Module({
+  imports: [
+    GraphQLModule.forRoot<ApolloDriverConfig>({
+      driver: ApolloDriver,
+      typePaths: ['./**/*.gql'],
+      installSubscriptionHandlers: true,
+      context: ({ req, res }: { req: Request; res: Response }): { req: Request; res: Response } => ({ req, res }),
+    }),
+  ],
   providers: [
     {
       provide: APP_INTERCEPTOR,