하나의 API 요청 안에서 각 기능별 시간을 누적하다가, 요청이 끝날 때 한 번에 로그로 출력하는 구조네요.
ThreadLocal로 컨텍스트를 유지하는 방식이 가장 깔끔합니다.
전체 구조
Request → Filter(시작) → Controller → Service → Repository → Filter(종료+로그출력)
↓ ↓ ↓
AOP가 각 단계 시간을 PerformanceContext에 누적
1. PerformanceContext — ThreadLocal로 요청당 컨텍스트 유지
@Component
public class PerformanceContext {
private static final ThreadLocal<List<StepRecord>> steps =
ThreadLocal.withInitial(ArrayList::new);
private static final ThreadLocal<Long> requestStart = new ThreadLocal<>();
public void startRequest() {
steps.get().clear(); // 이전 요청 데이터 초기화
requestStart.set(System.nanoTime());
}
public void record(String stepName, long elapsedMs) {
steps.get().add(new StepRecord(stepName, elapsedMs));
}
public String buildSummary() {
long totalMs = (System.nanoTime() - requestStart.get()) / 1_000_000;
StringBuilder sb = new StringBuilder("\n==== API Performance Summary ====\n");
for (StepRecord step : steps.get()) {
sb.append(String.format(" %-40s %5dms\n", step.name(), step.elapsedMs()));
}
sb.append("---------------------------------\n");
sb.append(String.format(" %-40s %5dms\n", "TOTAL", totalMs));
sb.append("=================================");
return sb.toString();
}
public void clear() {
steps.remove();
requestStart.remove();
}
public record StepRecord(String name, long elapsedMs) {}
}
2. @TrackTime — 측정할 메서드에 붙이는 어노테이션
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface TrackTime {
String value() default ""; // 로그에 표시할 이름 (비어있으면 메서드명 사용)
}
3. PerformanceAspect — AOP로 시간 측정 후 Context에 기록
@Aspect
@Component
@RequiredArgsConstructor
public class PerformanceAspect {
private final PerformanceContext performanceContext;
@Around("@annotation(trackTime)")
public Object track(ProceedingJoinPoint joinPoint, TrackTime trackTime) throws Throwable {
String stepName = trackTime.value().isBlank()
? joinPoint.getSignature().toShortString()
: trackTime.value();
long start = System.nanoTime();
try {
return joinPoint.proceed();
} finally {
long elapsed = (System.nanoTime() - start) / 1_000_000;
performanceContext.record(stepName, elapsed);
}
}
}
4. PerformanceFilter — 요청 시작/종료 시점 제어
@Component
@RequiredArgsConstructor
public class PerformanceFilter extends OncePerRequestFilter {
private static final Logger log = LoggerFactory.getLogger(PerformanceFilter.class);
private final PerformanceContext performanceContext;
@Override
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response,
FilterChain filterChain) throws ServletException, IOException {
performanceContext.startRequest();
try {
filterChain.doFilter(request, response);
} finally {
log.info("[{} {}]{}",
request.getMethod(),
request.getRequestURI(),
performanceContext.buildSummary());
performanceContext.clear(); // 반드시 ThreadLocal 정리
}
}
}
5. 실제 사용 — 각 레이어에 어노테이션만 붙이면 끝
@RestController
@RequiredArgsConstructor
public class OrderController {
private final OrderService orderService;
@PostMapping("/api/orders")
public ResponseEntity<OrderResponse> createOrder(@RequestBody OrderRequest request) {
return ResponseEntity.ok(orderService.createOrder(request));
}
}
@Service
@RequiredArgsConstructor
public class OrderService {
private final UserService userService;
private final ProductService productService;
private final OrderRepository orderRepository;
@TrackTime("1. 주문 처리 (Service)")
public OrderResponse createOrder(OrderRequest request) {
User user = userService.validateUser(request.getUserId());
Product product = productService.checkStock(request.getProductId());
return orderRepository.save(user, product);
}
}
@Service
public class UserService {
@TrackTime("2. 유저 검증 (UserService)")
public User validateUser(Long userId) {
// DB 조회, 권한 체크 등
}
}
@Service
public class ProductService {
@TrackTime("3. 재고 확인 (ProductService)")
public Product checkStock(Long productId) {
// 재고 조회
}
}
@Repository
public class OrderRepository {
@TrackTime("4. 주문 저장 (Repository)")
public OrderResponse save(User user, Product product) {
// INSERT 쿼리
}
}
출력 결과
INFO [POST /api/orders]
==== API Performance Summary ====
2. 유저 검증 (UserService) 12ms
3. 재고 확인 (ProductService) 8ms
4. 주문 저장 (Repository) 23ms
1. 주문 처리 (Service) 48ms ← 하위 포함한 전체
---------------------------------
TOTAL 51ms ← Filter 기준 전체
=================================
핵심 포인트 정리
| 역할 | 클래스 | 설명 |
|---|---|---|
| 컨텍스트 저장 | PerformanceContext | ThreadLocal로 요청별 격리 |
| 시간 측정 | PerformanceAspect | AOP로 비침투적 측정 |
| 시작/종료 제어 | PerformanceFilter | 로그 출력 + ThreadLocal 정리 |
| 측정 대상 지정 | @TrackTime | 어노테이션만 붙이면 자동 수집 |
ThreadLocal을 쓰므로 멀티스레드 환경에서도 요청끼리 간섭 없이 각자의 데이터를 독립적으로 유지합니다. finally에서 clear()를 반드시 호출해야 스레드 풀 재사용 시 데이터가 오염되지 않습니다.