Trace Logging

[Miensoap]

AsyncLocalStorage 이용해 트래이스 ID 관리

nestjs-pino

// app.module.ts
import { Module } from '@nestjs/common';
import { LoggerModule } from 'nestjs-pino';
import { APP_INTERCEPTOR } from '@nestjs/core';
import { PinoLogger, LoggerErrorInterceptor } from 'nestjs-pino';

@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: {
        genReqId: (req) => req.id || require('crypto').randomUUID(), // 요청마다 Trace ID 생성
        customProps: (req) => ({
          traceId: req.id,
        }),
        transport: {
          target: 'pino-pretty', // 개발 환경에서 읽기 쉽게 포맷팅
          options: { colorize: true },
        },
      },
    }),
  ],
  providers: [
    {
      provide: APP_INTERCEPTOR,
      useClass: LoggerErrorInterceptor,
    },
  ],
})
export class AppModule {}

TypeORM 로깅에 적용

// custom-logger.ts
@Injectable()
export class CustomLogger implements Logger {
  constructor(@Inject(PinoLogger) private readonly logger: PinoLogger) {}

  logQuery(query: string, parameters?: any[]) {
    this.logger.info({
      query,
      parameters,
      message: 'Executing query',
      traceId: this.logger.context.req.id, // Trace ID 포함
    });
  }
...
}

[Miensoap]

트래이스 로깅

메서드 호출, fetch 요청, 쿼리 등을 각 요청에 대한 트래이스 로깅

1. TraceService로 Trace ID 관리

// trace.service.ts
import { Injectable } from '@nestjs/common';
import { AsyncLocalStorage } from 'node:async_hooks';
import { v4 as uuidv4 } from 'uuid';

@Injectable()
export class TraceService {
  private readonly asyncLocalStorage = new AsyncLocalStorage<Map<string, any>>();

  run(callback: () => void) {
    const store = new Map<string, any>();
    store.set('traceId', uuidv4());
    this.asyncLocalStorage.run(store, callback);
  }

  get traceId(): string | undefined {
    const store = this.asyncLocalStorage.getStore();
    return store ? store.get('traceId') : undefined;
  }
}

2. NestJS의 글로벌 인터셉터 사용

// trace.interceptor.ts
import { Injectable, NestInterceptor, ExecutionContext, CallHandler } from '@nestjs/common';
import { Observable } from 'rxjs';
import { TraceService } from './trace.service';

@Injectable()
export class TraceInterceptor implements NestInterceptor {
  constructor(private readonly traceService: TraceService) {}

  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
    return new Observable(observer => {
      this.traceService.run(() => {
        next.handle().subscribe({
          next: (val) => observer.next(val),
          error: (err) => observer.error(err),
          complete: () => observer.complete(),
        });
      });
    });
  }
}

3. PinoLogger에 Trace ID 자동 포함 설정

// logger.ts
import pino from 'pino';
import { TraceService } from './trace.service';

export function createLogger(traceService: TraceService) {
  return pino({
    mixin() {
      return { traceId: traceService.traceId };
    },
  });
}

4. TypeORM 커스텀 로거로 Trace ID 포함한 쿼리 로깅 자동화

5. fetch 함수를 래핑해 로깅 추가

6. APP_INTERCEPTOR, 상수 사용해 AppMoule 에서 전역적으로 적용

[Miensoap]

분산 트레이싱 서비스

위의 트레이스 로깅을 모든 메서드 호출에 대해 적용하려면, 프록시 패턴을 사용할 수 있음.
이때 메서드 호출이 지연되고, 로깅 비용이 증가하는 등 성능상 손해를 감수해야 함.

Datadog 과 같은 서비스는 성능 오버헤드를 최소화하기 위해,

1. 트레이스 데이터를 비동기적으로 수집
2. 샘플링 기법 : 대표 요청만 수집하고 나머지는 무시
3. 경량화된 데이터 수집

등의 방법을 사용.

이를 우리 서비스에도 적용하려면,

• 글로벌 인터셉터에서 (20)% 확률로 샘플링된 요청에 대해 메서드 호출을 트레이싱.
• 샘플링된 요청에 한해 모든 메서드 진입 및 종료 시점에서 비동기로 트레이스 로깅.
• 필요하다면 호출 인자나 반환값 추가

// sample-trace.interceptor.ts
import { Injectable, NestInterceptor, ExecutionContext, CallHandler } from '@nestjs/common';
import { Observable } from 'rxjs';
import { tap } from 'rxjs/operators';
import { PinoLogger } from 'nestjs-pino';

@Injectable()
export class SampleTraceInterceptor implements NestInterceptor {
  constructor(private readonly logger: PinoLogger) {}

  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
    const shouldTrace = Math.random() < 0.2; // 20% 샘플링

    if (!shouldTrace) {
      // 샘플링 대상이 아닌 경우, 트레이스하지 않고 바로 처리
      return next.handle();
    }

    const className = context.getClass().name;
    const handlerName = context.getHandler().name;
    const traceId = Math.random().toString(36).substring(2, 15); // Trace ID 생성
    const startTime = Date.now();

    // 비동기 로깅: 메서드 진입 시점 로그
    setTimeout(() => {
      this.logger.info(`[Trace - Entering] ${className}.${handlerName} - traceId: ${traceId}`);
    }, 0);

    return next
      .handle()
      .pipe(
        tap(() => {
          const endTime = Date.now();

          // 비동기 로깅: 메서드 종료 시점 로그
          setTimeout(() => {
            this.logger.info(`[Trace - Exiting] ${className}.${handlerName} - traceId: ${traceId} - ${endTime - startTime}ms`);
          }, 0);
        }),
      );
  }
}

// app.module.ts
@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: {
        transport: {
          target: 'pino-pretty',
          options: { colorize: true },
        },
      },
    }),
  ],
  providers: [
    {
      provide: APP_INTERCEPTOR,
      useClass: SampleTraceInterceptor,
    },
  ],
})
export class AppModule {}

[Miensoap]

메서드 호출 트레이싱 잘 안되서
OpenTelemetry 사용 고려. -> 일단 나중에