코드 : 로그 추적기
강의 : 스프링 핵심 원리 - 고급편
1. 로그 추적기
요구사항 : 어디서 병목이 발생하고, 예외가 발생하는지 확인할 수 있는 로그 추적기를 만들자
- 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
- 애플리케이션의 흐름을 변경하면 안됨
- 메서드 호출에 걸린 시간
- 정상 흐름과 예외 흐름 구분
- 메서드 호출의 깊이 표현
- HTTP 요청을 구분
예시
정상 요청
[796bccd9] OrderController.request()
[796bccd9] |-->OrderService.orderItem()
[796bccd9] | |-->OrderRepository.save()
[796bccd9] | |<--OrderRepository.save() time=1004ms
[796bccd9] |<--OrderService.orderItem() time=1014ms
[796bccd9] OrderController.request() time=1016ms예외 발생
[b7119f27] OrderController.request()
[b7119f27] |-->OrderService.orderItem()
[b7119f27] | |-->OrderRepository.save()
[b7119f27] | |<X-OrderRepository.save() time=0ms
ex=java.lang.IllegalStateException: 예외 발생!
[b7119f27] |<X-OrderService.orderItem() time=10ms
ex=java.lang.IllegalStateException: 예외 발생!
[b7119f27] OrderController.request() time=11ms
ex=java.lang.IllegalStateException: 예외 발생!V1 - 프로토 타입 개발
모든 로직에 직접 로그를 남겨도 되지만, 그것보다 더 효율적인 개발 방법이 필요하다.
트랜잭션 ID와 깊이를 표현하는 방법은 기존 정보를 이어 받아야 하기 대문에 단순히 로그만 남긴다고 해결할 수 있는 것은 아니다.
TraceId
public class TraceId {
private String id;
private int level;
public TraceId() {
this.id = createId();
this.level = 0;
}
private TraceId(String id, int level) {
this.id = id;
this.level = level;
}
private String createId() {
return UUID.randomUUID().toString().substring(0, 8);
}
public TraceId createNextId() {
return new TraceId(id, level + 1);
}
public TraceId createPreviousId() {
return new TraceId(id, level - 1);
}
public boolean isFirstLevel() {
return level == 0;
}
public String getId() {
return id;
}
public int getLevel() {
return level;
}
TraceId 클래스
트랜잭션 ID와 깊이를 표현하는 level을 묶어서 TraceId라는 개념
TraceId는 단순히 id(트랜잭션ID)와 level 정보를 함께 가지고 있다.
UUID
로그를 구분하기 위해 UUID 사용한다. 만들어진 값을 트랜잭션 ID로 사용한다.
TraceStatus
public class TraceStatus {
private TraceId traceId;
private Long startTimeMs;
private String message;
public TraceStatus(TraceId traceId, Long startTimeMs, String message) {
this.traceId = traceId;
this.startTimeMs = startTimeMs;
this.message = message;
}
public Long getStartTimeMs() {
return startTimeMs;
}
public String getMessage() {
return message;
}
public TraceId getTraceId() {
return traceId;
}
}TraceStatus 클래스 : 로그의 상태 정보를 나타낸다.
TraceStatus는 로그를 시작할 때의 상태 정보를 가지고 있다. 이 상태 정보는 로그를 종료할 때 사용
HelloTraceV1
@Slf4j
@Component
public class HelloTraceV1 {
private static final String START_PREFIX = "-->";
private static final String COMPLETE_PREFIX = "<--";
private static final String EX_PREFIX = "<X-";
public TraceStatus begin(String message) {
TraceId traceId = new TraceId();
Long startTimeMs = System.currentTimeMillis();
log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX, traceId.getLevel()), message);
return new TraceStatus(traceId, startTimeMs, message);
}
public void end(TraceStatus status) {
complete(status, null);
}
public void exception(TraceStatus status, Exception e) {
complete(status, e);
}
private void complete(TraceStatus status, Exception e) {
Long stopTimeMs = System.currentTimeMillis();
long resultTimeMs = stopTimeMs - status.getStartTimeMs();
TraceId traceId = status.getTraceId();
if (e == null) {
log.info("[{}] {}{} time={}ms", traceId.getId(), addSpace(COMPLETE_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs);
} else {
log.info("[{}] {}{} time={}ms ex={}", traceId.getId(),
addSpace(EX_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs,
e.toString());
}
}
private static String addSpace(String prefix, int level) {
StringBuilder sb = new StringBuilder();
for (int i = 0; i < level; i++) {
sb.append( (i == level - 1) ? "|" + prefix : "| ");
}
return sb.toString();
}
}테스트 - HelloTraceV1Test
class HelloTraceV1Test {
@Test
void begin_end() {
HelloTraceV1 trace = new HelloTraceV1();
TraceStatus status = trace.begin("hello");
trace.end(status);
}
@Test
void begin_exception() {
HelloTraceV1 trace = new HelloTraceV1();
TraceStatus status = trace.begin("hello");
trace.exception(status, new IllegalStateException());
}
}begin_end() - 실행 로그*
[41bbb3b7] hello
[41bbb3b7] hello time=5msbegin_exception() - 실행 로그
[898a3def] hello
[898a3def] hello time=13ms ex=java.lang.IllegalStateException참고: 이것은 온전한 테스트 코드가 아니다. 일반적으로 테스트라고 하면 자동으로 검증하는 과정이
필요하다. 이 테스트는 검증하는 과정이 없고 결과를 콘솔로 직접 확인해야 한다.
로그 추적기 V1 - 적용
OrderControllerV1
@RestController
@RequiredArgsConstructor
public class OrderControllerV1 {
private final OrderServiceV1 orderService;
private final HelloTraceV1 trace; // 주입
@GetMapping("/v1/request")
public String request(String itemId) {
TraceStatus status = null; // try, catch 모두 값을 넘겨야 함
try {
status = trace.begin("OrderController.request()"); // 수작업
orderService.orderItem(itemId);
trace.end(status);
return "ok";
} catch (Exception e) {
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져주어야 한다.
}
}
}OrderServiceV1
@Service
@RequiredArgsConstructor
public class OrderServiceV1 {
private final OrderRepositoryV1 orderRepository;
private final HelloTraceV1 trace;
public void orderItem(String itemId) {
TraceStatus status = null;
try {
status = trace.begin("OrderService.orderItem()");
orderRepository.save(itemId);
trace.end(status);
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
}OrderRepositoryV1
@Repository
@RequiredArgsConstructor
public class OrderRepositoryV1 {
private final HelloTraceV1 trace;
public void save(String itemId) {
TraceStatus status = null;
try {
status = trace.begin("OrderRepository.save()"); //저장 로직
if (itemId.equals("ex")) {
throw new IllegalStateException("예외 발생!");
}
sleep(1000);
trace.end(status);
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
private void sleep(int millis) {
try {
Thread.sleep(millis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}정상 실행 로그
[11111111] OrderController.request()
[22222222] OrderService.orderItem()
[33333333] OrderRepository.save()
[33333333] OrderRepository.save() time=1000ms
[22222222] OrderService.orderItem() time=1001ms
[11111111] OrderController.request() time=1001ms예외 실행 로그
[5e110a14] OrderController.request()
[6bc1dcd2] OrderService.orderItem()
[48ddffd6] OrderRepository.save()
[48ddffd6] OrderRepository.save() time=0ms ex=java.lang.IllegalStateException:
예외 발생!
[6bc1dcd2] OrderService.orderItem() time=6ms
ex=java.lang.IllegalStateException: 예외 발생!
[5e110a14] OrderController.request() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!남은 문제
- 메서드 호출의 깊이 표현
- HTTP 요청을 구분
- HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야
함 - 트랜잭션 ID (DB 트랜잭션X)
로그 추적기 V2
트랜잭션 ID와 메서드 호출의 깊이를 표현하는 가장 단순한 방법은 첫 로그에서
트랜잭션ID
와level을 다음 로그에 넘겨주는 방법
HelloTraceV2
...
//V2에서 추가
public TraceStatus beginSync(TraceId beforeTraceId, String message) {
TraceId nextId = beforeTraceId.createNextId();
Long startTimeMs = System.currentTimeMillis();
log.info("[" + nextId.getId() + "] " + addSpace(START_PREFIX, nextId.getLevel()) + message);
return new TraceStatus(nextId, startTimeMs, message);
}
...
beginSync(...)
- 기존
TraceId에서createNextId()를 통해 다음 ID를 구한다. createNextId()의TraceId생성 로직
1. 트랜잭션 ID는 기존과 같이 유지한다.- 깊이를 표현하는 Level은 하나 증가한다.
테스트, 적용 생략
요구사항
모두 만족
남은 문제
- HTTP 요청을 구분하고 깊이를 표현하기 위해서
TraceId동기화 필요 TraceId의 동기화를 위해서 관련 메서드의 모든 파라미터를 수정해야 한다.- 만약 인터페이스가 있다면 인터페이스까지 모두 고쳐야 하는 상황이다.
- 로그를 처음 시작할 때는
begin()을 호출하고, 처음이 아닐때는beginSync()를 호출- 만약에 컨트롤러를 통해서 서비스를 호출하는 것이 아니라, 다른 곳에서 서비스를 처음으로 호출하는
상황이라면 파리미터로 넘길TraceId가 없다.
- 만약에 컨트롤러를 통해서 서비스를 호출하는 것이 아니라, 다른 곳에서 서비스를 처음으로 호출하는
2. 쓰레드 로컬
Config
LogTrace 인터페이스
public interface LogTrace {
TraceStatus begin(String message);
void end(TraceStatus status);
void exception(TraceStatus status, Exception e);
}LogTrace 인터페이스에는 로그 추적기를 위한 최소한의 기능인 begin(), end(), exception()을 정의했다.
이제 파라미터를 넘기지 않고 TraceId를 동기화 할 수 있는 FieldLogTrace 구현체를 만들자.
FieldLogTrace
@Slf4j
public class FieldLogTrace implements LogTrace {
private static final String START_PREFIX = "-->";
private static final String COMPLETE_PREFIX = "<--";
private static final String EX_PREFIX = "<X-";
private TraceId traceIdHolder; //traceId 동기화, 동시성 이슈 발생
@Override
public TraceStatus begin(String message) {
syncTraceId();
TraceId traceId = traceIdHolder;
Long startTimeMs = System.currentTimeMillis();
log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX, traceId.getLevel()), message);
return new TraceStatus(traceId, startTimeMs, message);
}
@Override
public void end(TraceStatus status) {
complete(status, null);
}
@Override
public void exception(TraceStatus status, Exception e) {
complete(status, e);
}
private void complete(TraceStatus status, Exception e) {
Long stopTimeMs = System.currentTimeMillis();
long resultTimeMs = stopTimeMs - status.getStartTimeMs();
TraceId traceId = status.getTraceId();
if (e == null) {
log.info("[{}] {}{} time={}ms", traceId.getId(), addSpace(COMPLETE_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs);
} else {
log.info("[{}] {}{} time={}ms ex={}", traceId.getId(), addSpace(EX_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs, e.toString());
}
releaseTraceId();
}
private void syncTraceId() {
if (traceIdHolder == null) {
traceIdHolder = new TraceId();
} else {
traceIdHolder = traceIdHolder.createNextId();
}
}
private void releaseTraceId() {
if (traceIdHolder.isFirstLevel()) {
traceIdHolder = null; //destroy
} else {
traceIdHolder = traceIdHolder.createPreviousId();
}
}
private static String addSpace(String prefix, int level) {
StringBuilder sb = new StringBuilder();
for (int i = 0; i < level; i++) {
sb.append( (i == level - 1) ? "|" + prefix : "| ");
}
return sb.toString();
}
}
직전 로그의 TraceId는 파라미터로 전달되는 것이 아니라 FieldLogTrace의 필드인 traceIdHolder에 저장된다.
중요한 부분은 로그를 시작할 때 호출하는 syncTraceId()와 로그를 종료할 때 호출하는 releaseTraceId()이다.
적용
LogTraceConfig를 통한 LogTrace 스프링 빈 등록
FieldLogTrace를 수동으로 스프링 빈 등록 (향후 구현체 편리하게 변경 가능)
@Configuration
public class LogTraceConfig {
@Bean
public LogTrace logTrace() {
return new FieldLogTrace();
}
}코드 적용 생략
필드 동기화 - 동시성 문제
1초 안에 2번 실행할 경우
기대 결과
[nio-8080-exec-3] [52808e46] OrderController.request()
[nio-8080-exec-3] [52808e46] |-->OrderService.orderItem()
[nio-8080-exec-3] [52808e46] | |-->OrderRepository.save()
[nio-8080-exec-4] [4568423c] OrderController.request()
[nio-8080-exec-4] [4568423c] |-->OrderService.orderItem()
[nio-8080-exec-4] [4568423c] | |-->OrderRepository.save()
[nio-8080-exec-3] [52808e46] | |<--OrderRepository.save() time=1001ms
[nio-8080-exec-3] [52808e46] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-3] [52808e46] OrderController.request() time=1003ms
[nio-8080-exec-4] [4568423c] | |<--OrderRepository.save() time=1000ms
[nio-8080-exec-4] [4568423c] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-4] [4568423c] OrderController.request() time=1001ms[52808e46]
[nio-8080-exec-3] [52808e46] OrderController.request()
[nio-8080-exec-3] [52808e46] |-->OrderService.orderItem()
[nio-8080-exec-3] [52808e46] | |-->OrderRepository.save()
[nio-8080-exec-3] [52808e46] | |<--OrderRepository.save() time=1001ms
[nio-8080-exec-3] [52808e46] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-3] [52808e46] OrderController.request() time=1003ms
[4568423c]
[nio-8080-exec-4] [4568423c] OrderController.request()
[nio-8080-exec-4] [4568423c] |-->OrderService.orderItem()
[nio-8080-exec-4] [4568423c] | |-->OrderRepository.save()
[nio-8080-exec-4] [4568423c] | |<--OrderRepository.save() time=1000ms
[nio-8080-exec-4] [4568423c] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-4] [4568423c] OrderController.request() time=1001ms실제 결과
[nio-8080-exec-3] [aaaaaaaa] OrderController.request()
[nio-8080-exec-3] [aaaaaaaa] |-->OrderService.orderItem()
[nio-8080-exec-3] [aaaaaaaa] | |-->OrderRepository.save()
[nio-8080-exec-4] [aaaaaaaa] | | |-->OrderController.request()
[nio-8080-exec-4] [aaaaaaaa] | | | |-->OrderService.orderItem()
[nio-8080-exec-4] [aaaaaaaa] | | | | |-->OrderRepository.save()
[nio-8080-exec-3] [aaaaaaaa] | |<--OrderRepository.save() time=1005ms
[nio-8080-exec-3] [aaaaaaaa] |<--OrderService.orderItem() time=1005ms
[nio-8080-exec-3] [aaaaaaaa] OrderController.request() time=1005ms
[nio-8080-exec-4] [aaaaaaaa] | | | | |<--OrderRepository.save()
time=1005ms
[nio-8080-exec-4] [aaaaaaaa] | | | |<--OrderService.orderItem()
time=1005ms
[nio-8080-exec-4] [aaaaaaaa] | | |<--OrderController.request() time=1005ms[nio-8080-exec-3]
[nio-8080-exec-3] [aaaaaaaa] OrderController.request()
[nio-8080-exec-3] [aaaaaaaa] |-->OrderService.orderItem()
[nio-8080-exec-3] [aaaaaaaa] | |-->OrderRepository.save()
[nio-8080-exec-3] [aaaaaaaa] | |<--OrderRepository.save() time=1005ms
[nio-8080-exec-3] [aaaaaaaa] |<--OrderService.orderItem() time=1005ms
[nio-8080-exec-3] [aaaaaaaa] OrderController.request() time=1005ms
[nio-8080-exec-4]
[nio-8080-exec-4] [aaaaaaaa] | | |-->OrderController.request()
[nio-8080-exec-4] [aaaaaaaa] | | | |-->OrderService.orderItem()
[nio-8080-exec-4] [aaaaaaaa] | | | | |-->OrderRepository.save()
[nio-8080-exec-4] [aaaaaaaa] | | | | |<--OrderRepository.save()
time=1005ms
[nio-8080-exec-4] [aaaaaaaa] | | | |<--OrderService.orderItem()
time=1005ms
[nio-8080-exec-4] [aaaaaaaa] | | |<--OrderController.request() time=1005ms이 문제는 동시성 문제이다.
FieldLogTrace는 싱글톤으로 등록된 스프링 빈이다. 객체의 인스턴스가 딱 1개 존재하는데 여러 쓰레드가 동시 접근하니 문제가 발생한다.
ThreadLocal
해당 쓰레드만 접근할 수 있는 특별한 저장소
ThreadLocalService
@Slf4j
public class ThreadLocalService {
private ThreadLocal<String> nameStore = new ThreadLocal<>();
public String logic(String name) {
log.info("저장 name={} -> nameStore={}", name, nameStore.get());
nameStore.set(name);
sleep(1000);
log.info("조회 nameStore={}",nameStore.get());
return nameStore.get();
}
private void sleep(int millis) {
try {
Thread.sleep(millis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}ThreadLocalLogTrace
@Slf4j
public class ThreadLocalLogTrace implements LogTrace {
private static final String START_PREFIX = "-->";
private static final String COMPLETE_PREFIX = "<--";
private static final String EX_PREFIX = "<X-";
private ThreadLocal<TraceId> traceIdHolder = new ThreadLocal<>();
@Override
public TraceStatus begin(String message) {
syncTraceId();
TraceId traceId = traceIdHolder.get();
Long startTimeMs = System.currentTimeMillis();
log.info("[{}] {}{}", traceId.getId(), addSpace(START_PREFIX, traceId.getLevel()), message);
return new TraceStatus(traceId, startTimeMs, message);
}
@Override
public void end(TraceStatus status) {
complete(status, null);
}
@Override
public void exception(TraceStatus status, Exception e) {
complete(status, e);
}
private void complete(TraceStatus status, Exception e) {
Long stopTimeMs = System.currentTimeMillis();
long resultTimeMs = stopTimeMs - status.getStartTimeMs();
TraceId traceId = status.getTraceId();
if (e == null) {
log.info("[{}] {}{} time={}ms", traceId.getId(), addSpace(COMPLETE_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs);
} else {
log.info("[{}] {}{} time={}ms ex={}", traceId.getId(), addSpace(EX_PREFIX, traceId.getLevel()), status.getMessage(), resultTimeMs, e.toString());
}
releaseTraceId();
}
private void syncTraceId() {
TraceId traceId = traceIdHolder.get();
if (traceId == null) {
traceIdHolder.set(new TraceId());
} else {
traceIdHolder.set(traceId.createNextId());
}
}
private void releaseTraceId() {
TraceId traceId = traceIdHolder.get();
if (traceId.isFirstLevel()) {
traceIdHolder.remove();//destroy
} else {
traceIdHolder.set(traceId.createPreviousId());
}
}
private static String addSpace(String prefix, int level) {
StringBuilder sb = new StringBuilder();
for (int i = 0; i < level; i++) {
sb.append( (i == level - 1) ? "|" + prefix : "| ");
}
return sb.toString();
}
}ThreadLocal.remove()
쓰레드 로컬을 모두 사용하고 나면 꼭 ThreadLocal.remove()를 호출해서 로컬에 저장된 값을 제거해 주어야 한다.
적용
LogTraceConfig - 수정
@Configuration
public class LogTraceConfig {
@Bean
public LogTrace logTrace() {
//return new FieldLogTrace();
return new ThreadLocalLogTrace();
}
}결과
정상 실행 로그
[f8477cfc] OrderController.request()
[f8477cfc] |-->OrderService.orderItem()
[f8477cfc] | |-->OrderRepository.save()
[f8477cfc] | |<--OrderRepository.save() time=1004ms
[f8477cfc] |<--OrderService.orderItem() time=1006ms
[f8477cfc] OrderController.request() time=1007ms[c426fcfc] OrderController.request()
[c426fcfc] |-->OrderService.orderItem()
[c426fcfc] | |-->OrderRepository.save()
[c426fcfc] | |<X-OrderRepository.save() time=0ms
ex=java.lang.IllegalStateException: 예외 발생!
[c426fcfc] |<X-OrderService.orderItem() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!
[c426fcfc] OrderController.request() time=7ms
ex=java.lang.IllegalStateException: 예외 발생!동시성 문제 확인
[nio-8080-exec-3] [52808e46] OrderController.request()
[nio-8080-exec-3] [52808e46] |-->OrderService.orderItem()
[nio-8080-exec-3] [52808e46] | |-->OrderRepository.save()
[nio-8080-exec-4] [4568423c] OrderController.request()
[nio-8080-exec-4] [4568423c] |-->OrderService.orderItem()
[nio-8080-exec-4] [4568423c] | |-->OrderRepository.save()
[nio-8080-exec-3] [52808e46] | |<--OrderRepository.save() time=1001ms
[nio-8080-exec-3] [52808e46] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-3] [52808e46] OrderController.request() time=1003ms
[nio-8080-exec-4] [4568423c] | |<--OrderRepository.save() time=1000ms
[nio-8080-exec-4] [4568423c] |<--OrderService.orderItem() time=1001ms
[nio-8080-exec-4] [4568423c] OrderController.request() time=1001ms주의사항
쓰레드 로컬의 값을 사용 후 제거하지 않고 그냥 두면 WAS처럼 쓰레드 풀을 사용하는 경우에 심각한 문제가 발생할 수 있다.
템플릿 메서드 패턴
지금까지의 코드는 부가기능이 핵심 기능을 보조하지 못하게 되었다.
효율적으로 처리할 수 있는 방법이 있을까?
좋은 설계? -> 변하지 않는 것과 변하는 것을 분리하는 것
@Slf4j
public abstract class AbstractTemplate {
public void execute() {
long startTime = System.currentTimeMillis();
//비즈니스 로직 실행
call(); //상속
//비즈니스 로직 종료
long endTime = System.currentTimeMillis();
long resultTime = endTime - startTime;
log.info("resultTime={}", resultTime);
}
protected abstract void call();
}익명의 내부 클래스 사용
@Test
void templateMethodV2() {
AbstractTemplate template1 = new AbstractTemplate() {
@Override
protected void call() {
log.info("비즈니스 로직1 실행");
}
};
log.info("클래스 이름1={}", template1.getClass());
template1.execute();
AbstractTemplate template2 = new AbstractTemplate() {
@Override
protected void call() {
log.info("비즈니스 로직1 실행");
}
};
log.info("클래스 이름2={}", template2.getClass());
template2.execute();
}
적용
AbstractTemplate
public abstract class AbstractTemplate<T> {
private final LogTrace trace;
public AbstractTemplate(LogTrace trace) {
this.trace = trace;
}
public T execute(String message) {
TraceStatus status = null;
try {
status = trace.begin(message);
//로직 호출
T result = call();
trace.end(status);
return result;
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
protected abstract T call();
}좋은 설계란?
진정한 좋은 설계는 변경이 일어날 때 드러난다.
단일 책임 원칙(SRP)
v4는 단순히 템플릿 메서드 패턴을 적용해서 소스코드 몇줄을 줄인것이 전부가 아니다.
변경 지점을 하나로 모아서 변경에 쉽게 대처할 수 있는 구조를 만든 것이다.
템플릿 메서드 패턴
템플릿 메서드 디자인 패턴의 목적은 다음과 같습니다.
"작업에서 알고리즘의 골격을 정의하고 일부 단계를 하위 클래스로 연기합니다. 템플릿 메서드를 사용하면 하위 클래스가 알고리즘의 구조를 변경하지 않고도 알고리즘의 특정 단계를 재정의할 수 있습니다."
공통 부분은 상속, 특정 부분만 오버라이딩을 통한 다형성으로 문제를 해결
문제점
상속에서 오는 단점을 그대로 안고 간다. 자식 클래스 입장에서 부모 클래스 기능을 사용하지 않는다.
추가로 별도의 클래스나 익명 내부 클래스를 만들어야 하는 부분도 복잡하다.
전략 패턴
템플릿 메서드 패턴은 부모 클래스에 변하지 않는 템플릿을 두고, 변하는 부분을 자식 클래스에 두어서 문제를 해결했다.
전략 패턴은 변하지 않는 부분을Context라는 곳에 두고, 변하는 부분을Strategy라는 인터페이스를 만들고 해당 인터페이스를 구현하도록 해서 문제를 해결한다. 상속이 아닌 위임으로 문제를 해결한다.
예제
Strategy 인터페이스
인터페이스는 변하는 알고리즘 역할을 한다.
public interface Strategy {
void call();
}StrategyLogic1
변하는 알고리즘은 Strategy 인터페이스를 구현
@Slf4j
public class StrategyLogic1 implements Strategy {
@Override
public void call() {
log.info("비즈니스 로직1 실행");
}
}StrategyLogic2
@Slf4j
public class StrategyLogic2 implements Strategy {
@Override
public void call() {
log.info("비즈니스 로직2 실행");
}
}ContextV1
@Slf4j
public class ContextV1 {
private Strategy strategy;
public ContextV1(Strategy strategy) {
this.strategy = strategy;
}
public void execute() {
long startTime = System.currentTimeMillis();
//비즈니스 로직 실행
strategy.call(); //위임
//비즈니스 로직 종료
long endTime = System.currentTimeMillis();
long resultTime = endTime - startTime;
log.info("resultTime={}", resultTime);
}
}ContextV1Test
전략 패턴 사용
@Test
void strategyV1() {
Strategy strategyLogic1 = new StrategyLogic1();
ContextV1 context1 = new ContextV1(strategyLogic1);
context1.execute();
Strategy strategyLogic2 = new StrategyLogic2();
ContextV1 context2 = new ContextV1(strategyLogic2);
context2.execute();
}ContextV1Test - 익명 내부 클래스 사용
@Test
void strategyV2() {
Strategy strategyLogic1 = new Strategy() {
@Override
public void call() {
log.info("비즈니스 로직1 실행");
}
};
log.info("strategyLogic1={}", strategyLogic1.getClass());
ContextV1 context1 = new ContextV1(strategyLogic1);
context1.execute();
Strategy strategyLogic2 = new Strategy() {
@Override
public void call() {
log.info("비즈니스 로직2 실행");
}
};
log.info("strategyLogic2={}", strategyLogic2.getClass());
ContextV1 context2 = new ContextV1(strategyLogic2);
context2.execute();
}ContextV2Test
@Test
void strategyV3() {
ContextV2 context = new ContextV2();
context.execute(() -> log.info("비즈니스 로직1 실행"));
context.execute(() -> log.info("비즈니스 로직2 실행"));
}정리
ContextV1은 필드에Strategy를 저장하는 방식으로 전략 패턴을 구사했다.- 선 조립, 후 실행 방법에 적합하다.
Context를 실행하는 시점에는 이미 조립이 끝났기 때문에 전략을 신경쓰지 않고 단순히 실행만 하면된다.
ContextV2는 파라미터에 Strategy 를 전달받는 방식으로 전략 패턴을 구사했다.- 실행할 때 마다 전략을 유연하게 변경할 수 있다.
- 단점 역시 실행할 때 마다 전략을 계속 지정해주어야 한다는 점이다.
템플릿
문제는 변하는 부분과 변하지 않는 부분을 분리하는 것이닫.
변하지 않는 부분 -> 템플릿, 변하는 부분에 약간 다른 코드 조각을 넘겨서 실행하는 것이 목적
템플릿 콜백 패턴
ContextV2는 변하지 않는 템플릿 역할을 한다. 그리고 변하ㅏ는 부분은 파라미터로 넘어온Strategy의 코드를 실행해서 처리한다. 이렇게 다른 코드의 인수로서 넘겨주는 실행 가능한 코드를 콜백이라 한다.
콜백
프로그래밍에서 콜백(callback) 또는 콜애프터 함수(call-after function)는 다른 코드의 인수로서
넘겨주는 실행 가능한 코드를 말한다. 콜백을 넘겨받는 코드는 이 콜백을 필요에 따라 즉시 실행할 수도
있고, 아니면 나중에 실행할 수도 있다.
적용
TraceCallback 인터페이스
public interface TraceCallback<T> {
T call();
}- 콜백을 전달하는 인터페이스
<T>제너릭을 사용. 콜백의 반환 타입 정의
한계
아무리 최적화를 해도 결국 로그 추적기를 적용하기 위해서 원본 코드를 수정해야 한다는 점이다. 클래스가 수백개이면 수백개를 더 힘들게 수정하는가 조금 덜 힘들게 수정하는가의 차이가 있을 뿐, 본질적으로 코드를 다 수정해야 하는 것은 마찬가지이다.
원본 코드를 손대지 않고 로그 추적기를 적용할 수 있는 방법을 알아보자. 그러기 위해서 프록시 개념을 먼저 이해해야 한다
