Guard에서의 uncaughtException
새 프로젝트를 진행중인데, 에러를 캐치하지 못해서 서버가 뻗어버렸다.
바로 본론으로 들어가서, 프로젝트의 에러 핸들링 설계는 아래처럼 구성했었다.
에러 발생 > 인터셉터에서 에러 로깅 및 필요에 따라 WebHook 전송 > 필터에서 클라이언트에 보낼 에러 포맷 정의
이러한 방식의 설계는, NestJS의 요청 응답 사이클과 각 구성요소의 역할에 대해 완전히 이해하지 못했기 때문에 만들어졌다.
NestJs req-res lifecycle
Interceptor에서 간과한 부분이 있었다.
클라이언트에서 보낸 API 요청이 프로젝트 전역에 설정한 Global Interceptor에서 가로채기 전에 가드에서 에러가 발생했다.
그렇기에 Exception Interceptor을 거치지 않고 바로 Filter으로 에러가 전달되게 된다.
실제로 로그를 찍어봐도 아래처럼, Filter로 바로 전달되는 것을 볼 수 있다. 마찬가지로 인터셉터가 동작한 후에는 인터셉터를 거쳐 필터로 향하는 모습도 볼 수 있다.
또한, Guards쪽을 자세히 보니 아래와 같이, 예외 필터에 의해 처리된다고 한다...
그럼 어떻게?
커스텀 에러를, 일전의 프로젝트였던 채팅 서비스의 샌드버드 전환기에서, 샌드버드의 커스텀 에러 타입이 마음에 들었고, 비슷한 형태로 구현해두었다. 클라이언트단에서는 HttpStatus + Custom Code형태로 반환되게 구현해두었다.
import { ArgumentsHost, Catch, ExceptionFilter, Logger } from '@nestjs/common';
import { Response } from 'express';
import { CustomHttpException } from '../error/custom.error';
@Catch(CustomHttpException)
export class CustomHttpExceptionFilter implements ExceptionFilter {
catch(exception: CustomHttpException, host: ArgumentsHost) {
console.log('CustomHttpException filter');
const ctx = host.switchToHttp();
const response = ctx.getResponse<Response>();
const request = ctx.getRequest();
const status = exception.statusCode;
const stack = exception.stack;
let json = {
errorCode: (status * 1000) + exception.errorCode,
message: exception.message,
timestamp: new Date().toISOString(),
path: request.url,
}
if (exception.sql) {
json['sql'] = exception.sql;
}
if (process.env.NODE_ENV !== 'production') json['stack'] = stack;
if (process.env.NODE_ENV === 'local') {
new Logger().log(stack);
}
response
.status(status)
.json(json);
}
}
그렇기 때문에, 클라이언트에게 보여질 에러를 포매팅하는 Filter를 설정해두고, 반환시켰는데 계속해서 uncaughtException이 발생했다.
나의 경우, 포스팅의 주 목적인 라이프사이클의 복습이나, 요청의 위치에 따른 에러 핸들링이 아니라 전혀 다른곳에서 확인되었다.
import { ExecutionContext, Injectable } from '@nestjs/common';
import { AuthGuard } from '@nestjs/passport';
import { UnauthorizeAccessToken } from 'src/common/error/user.error';
@Injectable()
export class JwtAuthGuard extends AuthGuard('jwt') {
canActivate(context: ExecutionContext) {
console.log(super.canActivate(context))
return super.canActivate(context);
}
handleRequest(err, user, info) {
if(err || !user) {
throw new UnauthorizeAccessToken();
}
return user;
}
}
기본적인 Access Token Strategy를 처리하는 Guard를 작성하면서 canActivate 함수에 Promise | Observable타입의 로깅을 시도했던 흔적이 있는데, 이 부분에서 NestJS의 실행 사이클이 올바르게 동작하지 않은 것 같다.
간략하게 설명하자면, 위의 코드에서는 canActivate는 인증처리, handleRequest는 인증 후처리를 담당한다고 보면 되는데, 요청이 들어올 때, 내부적으로 'jwt'로 명시된 Strategy를 활성화하여 요청에 포함된 토큰의 유효성 검사를 실시한다. handleRequest에서는, 유효성 검사 후처리를 진행한다고 보면 된다.
다시 돌아와서, 단순 Promise객체의 로깅을 시도할 때, 결과를 기다리지 않고 로그를 찍어도 Promise객체 자체가 로그에 찍히기 때문에 문제가 없다. 지식이 여기까지밖에 없어서, AI의 힘을 빌려봤다.
왜 로그를 찍었을 때 에러가 발생하는지 > 처리가 완료되지 않은 객체여도 객체 자체가 로그에 찍혀 상관없지 않는지? > Observable의 로깅 시 에러가 발생할 수 있는지의 순서로 물어보면서 대답을 다듬었고 다음과 같은 결론을 받을 수 있었다.
RxJS도 한번 훑어보기라도 해야할 것 같다.
마무리
콘솔 한 줄 때문에 실제 프로덕션에서 전사 시스템이 뻗어버리는 사태가 발생하지 않은 것에 다행이지만(그럴 일이 없겠지..?)
뭔가 마무리 멘트를 정리를 못한 찝찝한 트러블슈팅이었다. 시작은 사용하는 프레임워크의 생명주기를 더 잘 이해하고 적절히 핸들링할 수 있기를 바라면서 작성한 글이었고, 덕분에 관련한 문서를 보며 다시 다잡았다는 긍정적인 결론을 낼 수 있었지만 무언가 찝찝하달까..
참조
2023.04 ~ 백엔드 개발자의 기록
포스팅이 좋았다면 "좋아요❤️" 또는 "구독👍🏻" 해주세요!