Skip to content

[준섭] 1130(목) 개발 기록 ‐ NestJS Interceptor와 로거

송준섭 edited this page Nov 30, 2023 · 2 revisions

Interceptor

1

Interceptor는 Guard와 Pipe 사이, Exception Filter와 클라이언트로 나가는 Response 사이에 존재한다.

즉, Guard를 넘어서 오는 요청을 변경하거나 Exception Filter를 거쳐 나가는 응답을 변경할 수 있는 것

NestJS Lifecycle에서 유일하게 요청과 응답 모두를 핸들링할 수 있음

기능

  • 우리가 짠 메소드들(Controller, Service 등)을 실행하기 전과 후에 추가 로직을 적용할 수 있음
  • 함수에서 반환된 결과를 변형할 수 있음
  • 함수에서 던진 에러를 변형할 수 있음
  • 기본 함수 로직에 추가 기능을 넣을 수 있음
  • 특정한 상황에 어떠한 함수를 완전히 오버라이드 할 수 있음 (캐싱 등�� 목적으로 사용)

→ 원한다면 Interceptor를 적용한 함수에 거의 무엇이든 할 수 있음

Interceptor 예시

RxJS라는 stream을 extend하는 패키지를 사용하여 Interceptor 사용

import ...

@Injectable()
export class InterceptorExample implements NestInterceptor {
	// 요청이 들어올 때와 응답이 나갈 때 타임스탬프를 찍는 로그 기능
	intercept(context: ExecutionContext, next: CallHandler<any>): Observable<any> {
		const now = new Date();  // 현재 시각
		const req = context.switchToHttp().getRequest();  // req 객체 가져오기
		const path = req.originalUrl;  // 요청이 들어온 url

		// 요청 로그 형식: [REQ] {요청 path} {요청 시간}
		console.log(`[REQ] ${path} ${now.toLocaleString('kr')}`);
		// 이 위에까지는 서버 라우트(Controller) 메소드들이 실행되기 전에, 즉 요청이 들어오자마자 실행됨

		// return next.handle()을 실행하는 순간 라우트의 로직이 전부 실행되고 응답이 Observable로 반환
		return next
			.handle()
			.pipe(  // pipe에는 우리가 원하는 RxJS에서 지원하는 모든 함수를 넣어줄 수 있고 함수들은 순서대로 실행
				tap(  // pipe 함수 안에서 순서가 tab() 함수를 지나갈 때마다 전달되는 값들을 모니터링 할 수 있음
					(observable) => {  // 가장 처음에 한 tap의 파라미터로 들어온 observable은 응답
						console.log(observable);  // 라우트 로직을 지나서 생성된 응답이 console.log()로 출력됨
					}
				), 
				map(  // 응답 내용을 변형할 때 사용하는 map (tap은 변형은 못함)
					(observable) => {
						return {  // return 해주는 것이 실제 응답으로 들어가는 것
							message: "응답이 변경 됐습니다."
							response: observable
					}
				), 
				tap(  // 응답이 변형된 후 다시 출력
					(observable) => {
						console.log(observable);
					}
				),
			);
	}
}

Interceptor 예시 사용

@Get()
@UseInterceptors(InterceptorExample)
getPosts() {
	return this.postsService.findAll();
}

위처럼 @UesInterceptors(LogInterceptor)로 사용 가능

이제 Postman으로 Api 콜을 해보면, 다음과 같이 서버 로그에 찍힘

[REQ] /posts 11/30/2023, 1:14:10 AM  # next.handle() 하기 전(라우트 로직 실행 전)에 찍힌 로그
{  # next.handle().pipe() 안의 첫 함수인 tap의 console.log(observable);의 결과
	data: [
		PostsModel {
			id: 1,
			updatedAt: 2023-11-29T23:01:34.750Z,
			
# 생략.. (map으로 응답 변환)

{  # 두 번째 tap의 결과
	message: "응답이 변경 됐습니다.",
	response: {
		data: [ [PostsModel] ],
		cursor: { after: 135 },
		count: 1,
		next: "~~"
	}
}

map()의 결과로 다음과 같이 응답도 바뀜 (message 추가, 원래 응답이 response안에 들어간 모습

2

LogInterceptor 생성

// interceptor/log.interceptor.ts
import ...

@Injectable()
export class LogInterceptor implements NestInterceptor {
	intercept(
		context: ExecutionContext,
		next: CallHandler<any>,
	): Observable<any> {
		const now = new Date();
		const req = context.switchToHttp().getRequest();
		const path = req.originalUrl;
		const method = req.method;

		const randomId = getRandomId();
		const reqString = `${LogColorCode.blue}[REQ - ${randomId}]${LogColorCode.reset}`;
		const pathString = `${LogColorCode.leaf}[${method} ${path}]${LogColorCode.reset}`;
		const reqTimeString = `${LogColorCode.warmgray}[${now.toLocaleString(
			'kr',
		)}]${LogColorCode.reset}`;
		let userString: string;

		let reqLog = `${reqString} ${pathString} ${reqTimeString}`;
		if (req.user) {
			userString = `${LogColorCode.purple}[${req.user.username}]${LogColorCode.reset}`;
			reqLog += ` ${userString}`;
		}
		Logger.log(reqLog);

		return next.handle().pipe(
			catchError((error) => {
				const errTime = new Date();
				const errString = `${LogColorCode.red}[ERR - ${randomId}]${LogColorCode.reset}`;
				const errTimeString = `${
					LogColorCode.warmgray
				}[${errTime.toLocaleString('kr')} - ${
					errTime.getMilliseconds() - now.getMilliseconds()
				}ms]${LogColorCode.reset}`;

				let errLog = `${errString} ${pathString} ${errTimeString}`;
				if (req.user) {
					errLog += ` ${userString}`;
				}
				Logger.error(errLog);
				Logger.error(error);
				throw error;
			}),
			tap(() => {
				const resTime = new Date();
				const resString = `${LogColorCode.orange}[RES - ${randomId}]${LogColorCode.reset}`;
				const resTimeString = `${
					LogColorCode.warmgray
				}[${resTime.toLocaleString('kr')} - ${
					resTime.getMilliseconds() - now.getMilliseconds()
				}ms]${LogColorCode.reset}`;

				let resLog = `${resString} ${pathString} ${resTimeString}`;
				if (req.user) {
					resLog += ` ${userString}`;
				}
				Logger.log(resLog);
			}),
		);
	}
}

이제 이 LogInterceptor를 사용하여 api콜을 하면

Untitled

위와 같이 로그가 찍힘

이렇게 요청과 응답을 모두 만질 수 있는 것은 Interceptor밖에 없어서 많이 사용되는 것

Transaction Interceptor

트랜잭션은 queryRunner를 생성하고, 성공하면 커밋, 실패하면 롤백하는 과정을 가짐

→ Interceptor를 활용해서 쿼리러너 생성, 응답이 성공적으로 나오면 커밋, 중간 과정에서 에러가 발생하면 롤백을 하게 하고자 함

// interceptor/transaction.interceptor.ts
import ...

@Injectable()
export class TransactionInterceptor implements NestInterceptor {
	constructor(private readonly dataSource: DataSource) {}

	async intercept(
		context: ExecutionContext,
		next: CallHandler<any>,
	): Promise<Observable<any>> {
		const req = context.switchToHttp().getRequest();
		const path = req.originalUrl;
		const method = req.method;

		const queryRunner: QueryRunner = this.dataSource.createQueryRunner();
		await queryRunner.connect();
		await queryRunner.startTransaction();

		const startTime = new Date();
		const randomId = getRandomId();

		const transactionString = `${LogColorCode.orange}[Transaction - ${randomId}]${LogColorCode.reset}`;
		const pathString = `${LogColorCode.leaf}[${method} ${path}]${LogColorCode.reset}`;
		const startTimeString = `${
			LogColorCode.warmgray
		}[${startTime.toLocaleString('kr')}]${LogColorCode.reset}`;
		const transactionMentString = `- ${LogColorCode.orange}Transaction Start${LogColorCode.reset}`;

		const transactionStartLog = `${transactionString} ${pathString} ${startTimeString} ${transactionMentString}`;
		Logger.log(transactionStartLog);
		req.queryRunner = queryRunner;

		return next.handle().pipe(
			catchError(async (error) => {
				await queryRunner.rollbackTransaction();
				await queryRunner.release();

				const rollbackTime = new Date();
				const rollbackString = `${LogColorCode.red}[Transaction - ${randomId}]${LogColorCode.reset}`;
				const rollbackTimeString = `${
					LogColorCode.warmgray
				}[${rollbackTime.toLocaleString('kr')}]${LogColorCode.reset}`;
				const rollbackMentString = `- ${LogColorCode.red}Transaction Rollback${LogColorCode.reset}`;

				const rollbackLog = `${rollbackString} ${pathString} ${rollbackTimeString} ${rollbackMentString}`;
				Logger.error(rollbackLog);
				Logger.error(error);
				throw new InternalServerErrorException("Can't process your request");
			}),
			tap(async () => {
				await queryRunner.commitTransaction();
				await queryRunner.release();

				const commitTime = new Date();
				const commitString = `${LogColorCode.aqua}[Transaction - ${randomId}]${LogColorCode.reset}`;
				const commitTimeString = `${
					LogColorCode.warmgray
				}[${commitTime.toLocaleString('kr')} - ${
					startTime.getMilliseconds() - commitTime.getMilliseconds()
				}ms]${LogColorCode.reset}`;
				const commitMentString = `- ${LogColorCode.aqua}Transaction Commit${LogColorCode.reset}`;

				const commitLog = `${commitString} ${pathString} ${commitTimeString} ${commitMentString}`;
				Logger.log(commitLog);
			}),
		);
	}
}

3

RxJS

를 더 파보고 싶다면

RxJS

사실 tap과 map만 알아도 많은 일을 할 수 있음

소개

규칙

학습 기록

[공통] 개발 기록

[재하] 개발 기록

[준섭] 개발 기록

회의록

스크럼 기록

팀 회고

개인 회고

멘토링 일지

Clone this wiki locally