feat: create new service for logging metadata from filter

The new `OgmaFilterLogger` an be injected into a service and take in an
exception and an arguments host object from Nest and print out metadata
according to how the request failed. This will **only** happen, however, if the
request has not been logged by an interceptor, meaning there will not be double
logging of requests which would make logs noiser.

This is done by checking for the existence of the `requestId` added by the
interceptor earlier in the call, and the major gain here is that now errors
caused by guards or middleware can be caught can logged just as other requests
are properly automatically logged as well, making Ogma now fully capable of
logging **any** request type into Nest! This feature is opt-in, just as the
interceptor is, but the power it brings is major due to now not leaving any
requests unlogged.

The only downside at the moment is not being able to determing the time length
of the request as most underlying transports don't grab the metadata of the
start time, but there will be mentions of how users can implement such a
feature to allow for that if they so choose.

integration/src/gql/exception.filter.ts

@@ -0,0 +1,16 @@
+import {
+  ArgumentsHost,
+  Catch,
+  ExceptionFilter as NestExceptionFilter,
+  HttpException,
+} from '@nestjs/common';
+import { OgmaFilterLogger } from '@ogma/nestjs-module';
+
+@Catch()
+export class ExceptionFilter implements NestExceptionFilter {
+  constructor(private readonly service: OgmaFilterLogger) {}
+  catch(exception: HttpException, host: ArgumentsHost) {
+    this.service.log(exception, host);
+    return exception;
+  }
+}

integration/src/gql/gql.resolver.ts

@@ -1,11 +1,14 @@
-import { BadRequestException } from '@nestjs/common';
+import { BadRequestException, UseFilters, UseGuards } from '@nestjs/common';
 import { Mutation, Query, Resolver } from '@nestjs/graphql';
 import { OgmaSkip } from '@ogma/nestjs-module';
 
 import { AppService } from '../app.service';
+import { FailGuard } from '../shared/fail.guard';
+import { ExceptionFilter } from './exception.filter';
 import { SimpleObject } from './simple-object.model';
 
 @Resolver(() => SimpleObject)
+@UseFilters(ExceptionFilter)
 export class GqlResolver {
   constructor(private readonly appService: AppService) {}
 
@@ -29,4 +32,10 @@ export class GqlResolver {
   getSkip(): SimpleObject {
     return this.appService.getHello();
   }
+
+  @Query(() => SimpleObject)
+  @UseGuards(FailGuard)
+  failGuard(): SimpleObject {
+    return this.appService.getHello();
+  }
 }

integration/src/http/error-logging.filter.ts

@@ -0,0 +1,15 @@
+import { ArgumentsHost, Catch } from '@nestjs/common';
+import { BaseExceptionFilter } from '@nestjs/core';
+import { OgmaFilterLogger } from '@ogma/nestjs-module';
+
+@Catch()
+export class ErrorLoggingFilter extends BaseExceptionFilter {
+  constructor(private readonly logger: OgmaFilterLogger) {
+    super();
+  }
+
+  catch(exception: Error, host: ArgumentsHost) {
+    this.logger.log(exception, host);
+    return super.catch(exception, host);
+  }
+}

integration/src/http/http.controller.ts

@@ -7,13 +7,18 @@ import {
   Patch,
   Post,
   Put,
+  UseFilters,
+  UseGuards,
 } from '@nestjs/common';
 import { OgmaSkip } from '@ogma/nestjs-module';
 
 import { AppService } from '../app.service';
+import { FailGuard } from '../shared/fail.guard';
 import { SimpleObject } from '../simple-object.model';
+import { ErrorLoggingFilter } from './error-logging.filter';
 
 @Controller()
+@UseFilters(ErrorLoggingFilter)
 export class HttpController {
   constructor(private readonly appService: AppService) {}
 
@@ -39,6 +44,12 @@ export class HttpController {
     return this.appService.getHello();
   }
 
+  @Get('fail-guard')
+  @UseGuards(FailGuard)
+  failGuard() {
+    /* no op */
+  }
+
   @Post()
   getPost(): SimpleObject {
     return this.appService.getHello();

integration/src/rpc/client/rpc-client.controller.ts

@@ -26,4 +26,10 @@ export class RpcClientController implements OnApplicationBootstrap {
   getSkip() {
     return this.micro.send({ cmd: 'skip' }, { ip: '127.0.0.1' });
   }
+
+  @Get('fail-guard')
+  @UseFilters(ExceptionFilter)
+  failGuard() {
+    return this.micro.send({ cmd: 'fail-guard' }, { ip: '127.0.0.1' });
+  }
 }

integration/src/rpc/server/rpc-server.controller.ts

@@ -1,8 +1,9 @@
-import { BadRequestException, Controller, UseFilters } from '@nestjs/common';
+import { BadRequestException, Controller, UseFilters, UseGuards } from '@nestjs/common';
 import { MessagePattern } from '@nestjs/microservices';
 import { OgmaSkip } from '@ogma/nestjs-module';
 
 import { AppService } from '../../app.service';
+import { FailGuard } from '../../shared/fail.guard';
 import { ExceptionFilter } from './../../shared/server-exception.filter';
 
 @Controller()
@@ -25,4 +26,11 @@ export class RpcServerController {
   getSkip() {
     return this.appService.getHello();
   }
+
+  @MessagePattern({ cmd: 'fail-guard' })
+  @UseFilters(ExceptionFilter)
+  @UseGuards(FailGuard)
+  failGuard() {
+    /* no op */
+  }
 }

integration/src/shared/exception.filter.ts

@@ -1,8 +1,12 @@
-import { ArgumentsHost, Catch, HttpException } from '@nestjs/common';
-import { BaseExceptionFilter } from '@nestjs/core';
+import {
+  ArgumentsHost,
+  Catch,
+  ExceptionFilter as NestExceptionFilter,
+  HttpException,
+} from '@nestjs/common';
 
 @Catch()
-export class ExceptionFilter extends BaseExceptionFilter {
+export class ExceptionFilter implements NestExceptionFilter {
   catch(exception: HttpException, host: ArgumentsHost) {
     const res = host.switchToHttp().getResponse();
     res.send(exception);

integration/src/shared/fail.guard.ts

@@ -0,0 +1,8 @@
+import { CanActivate, Injectable } from '@nestjs/common';
+
+@Injectable()
+export class FailGuard implements CanActivate {
+  canActivate() {
+    return false;
+  }
+}

integration/src/shared/server-exception.filter.ts

@@ -1,10 +1,15 @@
-import { Catch, HttpException } from '@nestjs/common';
+import { ArgumentsHost, Catch, HttpException, Optional } from '@nestjs/common';
 import { BaseRpcExceptionFilter } from '@nestjs/microservices';
+import { OgmaFilterLogger } from '@ogma/nestjs-module';
 import { Observable, throwError } from 'rxjs';
 
 @Catch()
 export class ExceptionFilter extends BaseRpcExceptionFilter {
-  catch(exception: HttpException): Observable<any> {
+  constructor(@Optional() private readonly service?: OgmaFilterLogger) {
+    super();
+  }
+  catch(exception: HttpException, host: ArgumentsHost): Observable<any> {
+    this.service?.log(exception, host);
     return throwError(() => exception);
   }
 }

integration/src/ws/ws.filter.ts

@@ -1,9 +1,16 @@
-import { ArgumentsHost, Catch, HttpException } from '@nestjs/common';
-import { BaseWsExceptionFilter } from '@nestjs/websockets';
+import {
+  ArgumentsHost,
+  Catch,
+  ExceptionFilter as NestExceptionFilter,
+  HttpException,
+} from '@nestjs/common';
+import { OgmaFilterLogger } from '@ogma/nestjs-module';
 
 @Catch()
-export class ExceptionFilter extends BaseWsExceptionFilter {
+export class ExceptionFilter implements NestExceptionFilter {
+  constructor(private readonly service: OgmaFilterLogger) {}
   catch(exception: HttpException, host: ArgumentsHost) {
+    this.service.log(exception, host);
     const client = host.switchToWs().getClient();
     if (client._isServer) {
       return client.send('exception');

integration/src/ws/ws.gateway.ts

@@ -1,8 +1,9 @@
-import { BadRequestException, UseFilters, UseInterceptors } from '@nestjs/common';
+import { BadRequestException, UseFilters, UseGuards, UseInterceptors } from '@nestjs/common';
 import { SubscribeMessage, WebSocketGateway } from '@nestjs/websockets';
 import { OgmaInterceptor, OgmaSkip } from '@ogma/nestjs-module';
 
 import { AppService } from '../app.service';
+import { FailGuard } from '../shared/fail.guard';
 import { SimpleObject } from '../simple-object.model';
 import { ExceptionFilter } from './ws.filter';
 
@@ -27,4 +28,11 @@ export class WsGateway {
   getSkip(): { event: string; data: SimpleObject } {
     return { event: 'message', data: this.appService.getHello() };
   }
+
+  @SubscribeMessage('fail-guard')
+  @UseGuards(FailGuard)
+  @UseFilters(ExceptionFilter)
+  failGuard(): void {
+    /* no op */
+  }
 }

integration/test/gql.spec.ts

@@ -3,7 +3,7 @@ import { INestApplication } from '@nestjs/common';
 import { MercuriusDriver } from '@nestjs/mercurius';
 import { ExpressAdapter } from '@nestjs/platform-express';
 import { FastifyAdapter } from '@nestjs/platform-fastify';
-import { OgmaInterceptor, OgmaService } from '@ogma/nestjs-module';
+import { OgmaFilterLogger, OgmaInterceptor, OgmaService } from '@ogma/nestjs-module';
 import { GraphQLParser } from '@ogma/platform-graphql';
 import { GraphQLFastifyParser } from '@ogma/platform-graphql-fastify';
 import { style } from '@ogma/styler';
@@ -39,11 +39,13 @@ for (const { adapter, server, parser, driver } of [
   const GqlParserSuite = suite<{
     app: INestApplication;
     logSpy: Stub<OgmaInterceptor['log']>;
-    logs: Parameters<OgmaInterceptor['log']>[];
+    logs: Parameters<OgmaInterceptor['log'] | OgmaFilterLogger['doLog']>[];
+    filterSpy: Stub<OgmaFilterLogger['doLog']>;
   }>(`${server} GraphQL server`, {
     app: undefined,
     logSpy: undefined,
     logs: [],
+    filterSpy: undefined,
   });
   GqlParserSuite.before(async (context) => {
     const modRef = await createTestModule(GqlModule.forFeature(driver), {
@@ -54,14 +56,18 @@ for (const { adapter, server, parser, driver } of [
     });
     context.app = modRef.createNestApplication(adapter);
     const interceptor = context.app.get(OgmaInterceptor);
+    const filterService = context.app.get(OgmaFilterLogger);
     await context.app.listen(0);
     const baseUrl = await context.app.getUrl();
     request.setBaseUrl(baseUrl.replace('[::1]', 'localhost'));
     context.logSpy = stubMethod(interceptor, 'log');
+    context.filterSpy = stubMethod(filterService as any, 'doLog');
   });
-  GqlParserSuite.after.each(({ logSpy, logs }) => {
+  GqlParserSuite.after.each(({ logSpy, logs, filterSpy }) => {
     logSpy.firstCall && logs.push(logSpy.firstCall.args);
     logSpy.reset();
+    filterSpy.firstCall && logs.push(filterSpy.firstCall.args);
+    filterSpy.reset();
   });
   GqlParserSuite.after(async ({ app, logs }) => {
     const ogma = app.get(OgmaService);
@@ -97,5 +103,15 @@ for (const { adapter, server, parser, driver } of [
     await spec().post('/graphql').withGraphQLQuery('query getSkip{ getSkip{ hello }}').toss();
     is(logSpy.callCount, 0);
   });
+  GqlParserSuite('it should error at the guard and still log a line', async ({ filterSpy }) => {
+    await spec().post('/graphql').withGraphQLQuery('query failGuard { failGuard { hello }}').toss();
+    toBeALogObject(
+      filterSpy.firstCall.args[0],
+      'query',
+      '/graphql',
+      'HTTP/1.1',
+      style.yellow.apply(403),
+    );
+  });
   GqlParserSuite.run();
 }

integration/test/http.spec.ts

@@ -1,7 +1,7 @@
 import { INestApplication } from '@nestjs/common';
 import { ExpressAdapter } from '@nestjs/platform-express';
 import { FastifyAdapter } from '@nestjs/platform-fastify';
-import { OgmaInterceptor, OgmaService } from '@ogma/nestjs-module';
+import { OgmaFilterLogger, OgmaInterceptor, OgmaService } from '@ogma/nestjs-module';
 import { ExpressParser } from '@ogma/platform-express';
 import { FastifyParser } from '@ogma/platform-fastify';
 import { style } from '@ogma/styler';
@@ -19,13 +19,13 @@ import {
   toBeALogObject,
 } from './utils';
 
-const expectRequestId = (spy: Stub<OgmaInterceptor['log']>) => {
+const expectRequestId = (spy: Stub<OgmaInterceptor['log']> | Stub<OgmaFilterLogger['doLog']>) => {
   is(typeof spy.firstCall.args[2], 'string');
   is(spy.firstCall.args[2].length, 16);
 };
 
 const expectLogObject = (
-  spy: Stub<OgmaInterceptor['log']>,
+  spy: Stub<OgmaInterceptor['log']> | Stub<OgmaFilterLogger['doLog']>,
   method: string,
   endpoint: string,
   status: string,
@@ -49,11 +49,13 @@ for (const { adapter, server, parser } of [
   const HttpSuite = suite<{
     app: INestApplication;
     logSpy: Stub<OgmaInterceptor['log']>;
-    logs: Parameters<OgmaInterceptor['log']>[];
+    logs: Parameters<OgmaInterceptor['log'] | OgmaFilterLogger['doLog']>[];
+    filterSpy: Stub<OgmaFilterLogger['doLog']>;
   }>(`${server} HTTP Log Suite`, {
     app: undefined,
     logSpy: undefined,
     logs: [],
+    filterSpy: undefined,
   });
   HttpSuite.before(async (context) => {
     const modRef = await createTestModule(HttpServerModule, {
@@ -62,18 +64,22 @@ for (const { adapter, server, parser } of [
     });
     context.app = modRef.createNestApplication(adapter);
     const interceptor = context.app.get(OgmaInterceptor);
+    const filterService = context.app.get(OgmaFilterLogger);
     await context.app.listen(0);
     request.setBaseUrl((await context.app.getUrl()).replace('[::1]', 'localhost'));
     context.logSpy = stubMethod(interceptor, 'log');
+    context.filterSpy = stubMethod(filterService as any, 'doLog');
   });
   HttpSuite.after(async ({ app, logs }) => {
     const ogma = app.get(OgmaService);
     await app.close();
     reportValues(ogma, logs);
   });
-  HttpSuite.after.each(({ logSpy, logs }) => {
+  HttpSuite.after.each(({ logSpy, logs, filterSpy }) => {
     logSpy.firstCall && logs.push(logSpy.firstCall.args);
     logSpy.reset();
+    filterSpy.firstCall && logs.push(filterSpy.firstCall.args);
+    filterSpy.reset();
   });
   for (const { method, status } of [
     {
@@ -108,5 +114,9 @@ for (const { adapter, server, parser } of [
     await spec().get('/skip').expectBody(hello).expectStatus(200);
     is(logSpy.callCount, 0);
   });
+  HttpSuite('It should get caught by a guard but still be able to log', async ({ filterSpy }) => {
+    await spec().get('/fail-guard').expectStatus(403);
+    expectLogObject(filterSpy, 'GET', '/fail-guard', style.yellow.apply(403));
+  });
   HttpSuite.run();
 }