검색결과 리스트
Spring 정리에 해당되는 글 68건
- 2022.10.29 스프링 핵심 원리 - 고급편 3
- 2022.10.29 스프링 핵심 원리 - 고급편 2 1
- 2022.09.20 스프링 핵심 원리 - 고급편 1 1
글
스프링 핵심 원리 - 고급편 3
인프런 강의 62일차.
- 스프링 핵심 원리 - 고급편 (김영한 강사님)
- 반드시 한번은 정복해야할 쉽지 않은 내용들
- 크게 3가지 고급 개념을 학습
1. 스프링 핵심 디자인 패턴
> 템플릿 메소드 패턴
> 전략 패턴
> 템플릿 콜백 패턴
> 프록시 패턴
> 데코레이터 패턴
2. 동시성 문제와 쓰레드 로컬
> 웹 애플리케이션
> 멀티쓰레드
> 동시성 문제
3. 스프링 AOP
> 개념, 용어정리
> 프록시 - JDK 동적 프록시, CGLIB
> 동작 원리
> 실전 예제
> 실무 주의 사항
- 기타
> 스프링 컨테이너의 확장 포인트 - 빈 후처리기
> 스프링 애플리케이션을 개발하는 다양한 실무 팁
- 타입 컨버터, 파일 업로드, 활용, 쿠키, 세션, 필터, 인터셉터, 예외 처리, 타임리프, 메시지, 국제화, 검증 등등
2. 쓰레드 로컬 - ThreadLocal
2.1. 필드 동기화 - 개발
- 앞서 로그 추적기를 만들면서 다음 로그를 출력할 때 트랜잭션ID 와 level 을 동기화 하는 문제가 있었다.
- 이 문제를 해결하기 위해 TraceId 를 파라미터로 넘기도록 구현했다.
- 이렇게 해서 동기화는 성공했지만, 로그를 출력하는 모든 메서드에 TraceId 파라미터를 추가해야 하는 문제가 발생했다.
- TraceId 를 파라미터로 넘기지 않고 이 문제를 해결할 수 있는 방법은 없을까?
> 확장성을 고려한 로그 추적기를 개발해보자
package hello.advanced.trace.logtrace;
import hello.advanced.trace.TraceStatus;
public interface LogTrace {
TraceStatus begin(String message);
void end(TraceStatus status);
void exception(TraceStatus status, Exception e);
}
- hello/advanced/trace/logtrace/LogTrace.java
- 로그 추적기를 위한 최소한의 기능인 begin() , end() , exception() 를 정의했다.
package hello.advanced.trace.logtrace;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
@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);
}
private void syncTraceId() {
if(traceIdHolder == null){
traceIdHolder = new TraceId();
} else {
traceIdHolder = traceIdHolder.createNextId();
}
}
@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 releaseTraceId() {
if(traceIdHolder.isFirstLevel()){
traceIdHolder = null; //destory
} 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();
}
}
- hello/advanced/trace/logtrace/FieldLogTrace.java
- FieldLogTrace 는 기존에 만들었던 HelloTraceV2 와 거의 같은 기능을 한다. TraceId 를 동기화 하는 부분만 파라미터를 사용하는 것에서 TraceId traceIdHolder 필드를 사용하도록 변경되었다.
- 이제 직전 로그의 TraceId 는 파라미터로 전달되는 것이 아니라 FieldLogTrace 의 필드인 traceIdHolder 에 저장된다.
- 여기서 중요한 부분은 로그를 시작할 때 호출하는 syncTraceId() 와 로그를 종료할 때 호출하는 releaseTraceId() 이다.
- syncTraceId()
> TraceId 를 새로 만들거나 앞선 로그의 TraceId 를 참고해서 동기화하고, level 도 증가한다.
> 최초 호출이면 TraceId 를 새로 만든다.
> 직전 로그가 있으면 해당 로그의 TraceId 를 참고해서 동기화하고, level 도 하나 증가한다.
> 결과를 traceIdHolder 에 보관한다.
- releaseTraceId()
> 메서드를 추가로 호출할 때는 level 이 하나 증가해야 하지만, 메서드 호출이 끝나면 level 이 하나 감소해야 한다.
> releaseTraceId() 는 level 을 하나 감소한다.
> 만약 최초 호출( level==0 )이면 내부에서 관리하는 traceId 를 제거한다.
package hello.advanced.trace.logtrace;
import hello.advanced.trace.TraceStatus;
import org.junit.jupiter.api.Test;
import static org.junit.jupiter.api.Assertions.*;
class FieldLogTraceTest {
FieldLogTrace trace = new FieldLogTrace();
@Test
void begin_end_level2() {
TraceStatus status1 = trace.begin("hello1");
TraceStatus status2 = trace.begin("hello2");
trace.end(status2);
trace.end(status1);
}
@Test
void begin_exception_level2() {
TraceStatus status1 = trace.begin("hello1");
TraceStatus status2 = trace.begin("hello2");
trace.exception(status2, new IllegalStateException());
trace.exception(status1, new IllegalStateException());
}
}
- hello/advanced/trace/logtrace/FieldLogTraceTest.java
// begin_end_level2() 실행결과
[71ef1c66] hello1
[71ef1c66] |-->hello2
[71ef1c66] |<--hello2 time=10ms
[71ef1c66] hello1 time=30ms
// begin_exception_level2() 실행결과
[737d1363] hello1
[737d1363] |-->hello2
[737d1363] |<X-hello2 time=1ms ex=java.lang.IllegalStateException
[737d1363] hello1 time=2ms ex=java.lang.IllegalStateException
- 실행 결과를 보면 트랜잭션ID 도 동일하게 나오고, level 을 통한 깊이도 잘 표현된다.
- FieldLogTrace.traceIdHolder 필드를 사용해서 TraceId 가 잘 동기화 되는 것을 확인할 수 있다.
- 이제 불필요하게 TraceId 를 파라미터로 전달하지 않아도 되고, 애플리케이션의 메서드 파라미터도 변경하지 않아도 된다
2.2. 필드 동기화 - 개발
- 지금까지 만든 FieldLogTrace 를 애플리케이션에 적용해보자.
- 우선 FieldLogTrace 를 수동으로 스프링 빈으로 등록하자. 수동으로 등록하면 향후 구현체를 편리하게 변경할 수 있다는 장점이 있다.
- v2 -> v3 복사
package hello.advanced;
import hello.advanced.trace.logtrace.LogTrace;
import hello.advanced.trace.logtrace.FieldLogTrace;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
@Configuration
public class LogTraceConfig {
@Bean
public LogTrace logTrace() {
return new FieldLogTrace();
}
}
- hello/advanced/LogTraceConfig.java
package hello.advanced.app.v3;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import hello.advanced.trace.helloTrace.HelloTraceV2;
import lombok.RequiredArgsConstructor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
@RequiredArgsConstructor
public class OrderControllerV3 {
private final OrderServiceV3 orderService;
private final HelloTraceV2 trace;
@GetMapping("/v3/request")
public String request(String itemId) {
TraceStatus status = null;
try {
status = trace.begin("OrderController.request()");
orderService.OrderItem(status.getTraceId(), itemId);
trace.end(status);
return "ok";
}catch (Exception e){
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v3/OrderControllerV3.java
package hello.advanced.app.v3;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV2;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;
@Service
@RequiredArgsConstructor
public class OrderServiceV3 {
private final OrderRepositoryV3 orderRepository;
private final HelloTraceV2 trace;
public void OrderItem(TraceId traceId, String itemId){
TraceStatus status = null;
try {
status = trace.beginSync(traceId, "OrderService.OrderItem()");
orderRepository.save(status.getTraceId(), itemId);
trace.end(status);
}catch (Exception e){
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v3/OrderServiceV3.java
package hello.advanced.app.v3;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV2;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;
@Repository
@RequiredArgsConstructor
public class OrderRepositoryV3 {
private final HelloTraceV2 trace;
public void save(TraceId traceId, String itemId) {
TraceStatus status = null;
try {
status = trace.beginSync(traceId, "OrderRepository.save()");
//저장 로직
if (itemId.equals("ex")) { //상품 ID 가 ex 면 예외 처리
throw new IllegalStateException("예외 발생!");
}
sleep(1000); //상품을 저장하는데 1초가 걸린다고 가정
trace.end(status);
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
private void sleep(int miilis) {
try {
Thread.sleep(miilis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/app/v3/OrderRepositoryV3.java
// 정상 실행 로그
[73088ff4] OrderController.request()
[73088ff4] |-->OrderService.OrderItem()
[73088ff4] | |-->OrderRepository.save()
[73088ff4] | |<--OrderRepository.save() time=1005ms
[73088ff4] |<--OrderService.OrderItem() time=1005ms
[73088ff4] OrderController.request() time=1007ms
// 에러 실행 로그
[69c22a14] OrderController.request()
[69c22a14] |-->OrderService.OrderItem()
[69c22a14] | |-->OrderRepository.save()
[69c22a14] | |<X-OrderRepository.save() time=0ms ex=java.lang.IllegalStateException: 예외 발생!
[69c22a14] |<X-OrderService.OrderItem() time=1ms ex=java.lang.IllegalStateException: 예외 발생!
[69c22a14] OrderController.request() time=2ms ex=java.lang.IllegalStateException: 예외 발생!
- traceIdHolder 필드를 사용한 덕분에 파라미터 추가 없는 깔끔한 로그 추적기를 완성했다.
2.3. 필드 동기화 - 동시성 문제
- FieldLogTrace 는 싱글톤으로 등록된 스프링 빈이다. 이 객체의 인스턴스가 애플리케이션에 딱 1개 존재한다는 뜻이다.
- 이렇게 하나만 있는 인스턴스의 FieldLogTrace.traceIdHolder 필드를 여러 쓰레드가 동시에 접근하기 때문에 문제가 발생한다.
dependencies {
implementation 'org.springframework.boot:spring-boot-starter-web'
compileOnly 'org.projectlombok:lombok'
annotationProcessor 'org.projectlombok:lombok'
testImplementation 'org.springframework.boot:spring-boot-starter-test'
//테스트에서 lombok 사용
testCompileOnly 'org.projectlombok:lombok'
testAnnotationProcessor 'org.projectlombok:lombok'
}
- build.gradle
- test 코드에서 lombok 사용을 위한 dependencies 추가
package hello.advanced.trace.threadlocal.code;
import lombok.extern.slf4j.Slf4j;
@Slf4j
public class FieldService {
private String nameStore;
public String logic(String name) {
log.info("저장 name={} -> nameStore={}", name, nameStore);
nameStore = name;
sleep(1000);
log.info("조회 nameStore={}", nameStore);
return nameStore;
}
private void sleep(int miles) {
try {
Thread.sleep(miles);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/trace/threadlocal/code/FieldService.java
- 파라미터로 넘어온 name 을 필드인 nameStore 에 저장 후 1초간 쉰 다음 필드에 저장된 nameStore 를 반환한다.
package hello.advanced.trace.threadlocal;
import hello.advanced.trace.threadlocal.code.FieldService;
import lombok.extern.slf4j.Slf4j;
import org.junit.jupiter.api.Test;
@Slf4j
public class FieldServiceTest {
private FieldService fieldService = new FieldService();
@Test
void field() {
log.info("main Start");
Runnable userA = () -> {
fieldService.logic("userA");
};
Runnable userB = () -> {
fieldService.logic("userB");
};
Thread threadA = new Thread(userA);
threadA.setName("thread-A");
Thread threadB = new Thread(userB);
threadB.setName("thread-B");
threadA.start(); //A실행
sleep(2000); //동시성 문제 발생X
// sleep(100); //동시성 문제 발생O
threadB.start(); //B실행
sleep(3000); //메인 쓰레드 종료 대기
log.info("main end");
}
private void sleep(int miles) {
try {
Thread.sleep(miles);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/trace/threadlocal/FieldServiceTest.java
- sleep(2000) 을 설정해서 thread-A 의 실행이 끝나고 나서 thread-B 가 실행되도록 해보자. 참고로 FieldService.logic() 메서드는 내부에 sleep(1000) 으로 1초의 지연이 있다. 따라서 1초 이후에 호출하면 순서대로 실행할 수 있다. 여기서는 넉넉하게 2초 (2000ms)를 설정했다
// sleep(2000) 실행 결과
[Test worker] INFO hello.advanced.trace.threadlocal.FieldServiceTest - main Start
[thread-A] INFO hello.advanced.trace.threadlocal.code.FieldService - 저장 name=userA -> nameStore=null
[thread-A] INFO hello.advanced.trace.threadlocal.code.FieldService - 조회 nameStore=userA
[thread-B] INFO hello.advanced.trace.threadlocal.code.FieldService - 저장 name=userB -> nameStore=userA
[thread-B] INFO hello.advanced.trace.threadlocal.code.FieldService - 조회 nameStore=userB
[Test worker] INFO hello.advanced.trace.threadlocal.FieldServiceTest - main end
- 실행 결과를 보면 문제가 없다.
> Thread-A 는 userA 를 nameStore 에 저장했다.
> Thread-A 는 userA 를 nameStore 에서 조회했다.
> Thread-B 는 userB 를 nameStore 에 저장했다.
> Thread-B 는 userB 를 nameStore 에서 조회했다
* 동시성 문제 발생 코드
- 이번에는 sleep(100) 을 설정해서 thread-A 의 작업이 끝나기 전에 thread-B 가 실행되도록 해보자.
- 참고로 FieldService.logic() 메서드는 내부에 sleep(1000) 으로 1초의 지연이 있다.
- 따라서 1초 이후에 호출하면 순서대로 실행할 수 있다.
- 다음에 설정할 100(ms)는 0.1초이기 때문에 thread-A 의 작업이 끝나기 전에 thread-B 가 실행된다.
// sleep(100) 실행 결과
[Test worker] INFO hello.advanced.trace.threadlocal.FieldServiceTest - main Start
[thread-A] INFO hello.advanced.trace.threadlocal.code.FieldService - 저장 name=userA -> nameStore=null
[thread-B] INFO hello.advanced.trace.threadlocal.code.FieldService - 저장 name=userB -> nameStore=userA
[thread-A] INFO hello.advanced.trace.threadlocal.code.FieldService - 조회 nameStore=userB
[thread-B] INFO hello.advanced.trace.threadlocal.code.FieldService - 조회 nameStore=userB
[Test worker] INFO hello.advanced.trace.threadlocal.FieldServiceTest - main end
- 실행 결과를 보면 문제가 있다.
> Thread-A 는 userA 를 nameStore 에 저장했다.
> Thread-B 는 userB 를 nameStore 에 저장했다.
> Thread-A 는 userB 를 nameStore 에서 조회했다.
> Thread-B 는 userB 를 nameStore 에서 조회했다
- 먼저 thread-A 가 userA 값을 nameStore 에 보관한다.
- 0.1초 이후에 thread-B 가 userB 의 값을 nameStore 에 보관한다. 기존에 nameStore 에 보관되어 있던 userA 값은 제거되고 userB 값이 저장된다
- thread-A 의 호출이 끝나면서 nameStore 의 결과를 반환받는데, 이때 nameStore 는 앞의 2번에서 userB 의 값으로 대체되었다. 따라서 기대했던 userA 의 값이 아니라 userB 의 값이 반환된다.
- thread-B 의 호출이 끝나면서 nameStore 의 결과인 userB 를 반환받는다.
* 동시성 문제
- 결과적으로 Thread-A 입장에서는 저장한 데이터와 조회한 데이터가 다른 문제가 발생한다.
- 이처럼 여러 쓰레드가 동시에 같은 인스턴스의 필드 값을 변경하면서 발생하는 문제를 동시성 문제라 한다.
- 이런 동시성 문제는 여러 쓰레드가 같은 인스턴스의 필드에 접근해야 하기 때문에 트래픽이 적은 상황에서는 확률상 잘 나타나지 않고, 트래픽이 점점 많아질 수 록 자주 발생한다.
- 특히 스프링 빈 처럼 싱글톤 객체의 필드를 변경하며 사용할 때 이러한 동시성 문제를 조심해야 한다.
- 이전 회사에서도 발생했었고, 쩔쩔맸던 기억이 난다..
* 해결 방법
- 지금처럼 싱글톤 객체의 필드를 사용하면서 동시성 문제를 해결하려면 어떻게 해야할까? 다시 파라미터를 전달하는 방식으로 돌아가야 할까? 이럴 때 사용하는 것이 바로 쓰레드 로컬이다.
2.4. ThreadLocal - 소개
- 쓰레드 로컬은 해당 쓰레드만 접근할 수 있는 특별한 저장소를 말한다.
- 자바는 언어차원에서 쓰레드 로컬을 지원하기 위한 java.lang.ThreadLocal 클래스를 제공한다.
2.5. ThreadLocal - 소개
- ThreadLocal을 사용해서 구현해보자
package hello.advanced.trace.threadlocal.code;
import lombok.extern.slf4j.Slf4j;
@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 miles) {
try {
Thread.sleep(miles);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/trace/threadlocal/code/ThreadLocalService.java
- 기존에 사용하던 String nameStore 변수를 ThreadLocal<String> 객체로 선언해서 사용한다.
- 객체이기 때문에 get/set/remove을 사용해 조회/저장/제거한다.
> 해당 쓰레드가 쓰레드 로컬을 모두 사용하고 나면 ThreadLocal.remove() 를 호출해서 쓰레드 로컬에 저장된 값을 제거해주어야 한다.
package hello.advanced.trace.threadlocal;
import hello.advanced.trace.threadlocal.code.ThreadLocalService;
import lombok.extern.slf4j.Slf4j;
import org.junit.jupiter.api.Test;
@Slf4j
public class ThreadLocalServiceTest {
private ThreadLocalService service = new ThreadLocalService();
@Test
void field() {
log.info("main Start");
Runnable userA = () -> {
service.logic("userA");
};
Runnable userB = () -> {
service.logic("userB");
};
Thread threadA = new Thread(userA);
threadA.setName("thread-A");
Thread threadB = new Thread(userB);
threadB.setName("thread-B");
threadA.start(); //A실행
sleep(2000); //동시성 문제 발생X
//sleep(100); //동시성 문제 발생O
threadB.start(); //B실행
sleep(3000); //메인 쓰레드 종료 대기
log.info("main end");
}
private void sleep(int miles) {
try {
Thread.sleep(miles);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/trace/threadlocal/ThreadLocalServiceTest.java
// sleep(2000) ThreadLocal 테스트 결과
[Test worker] main Start
[thread-A] 저장 name=userA -> nameStore=null
[thread-A] 조회 nameStore=userA
[thread-B] 저장 name=userB -> nameStore=null
[thread-B] 조회 nameStore=userB
[Test worker] main end
// sleep(100) ThreadLocal 테스트 결과
[Test worker] main Start
[thread-A] 저장 name=userA -> nameStore=null
[thread-B] 저장 name=userB -> nameStore=null
[thread-A] 조회 nameStore=userA
[thread-B] 조회 nameStore=userB
[Test worker] main end
- 동시성문제 발생하던 코드 실행 시 정상적으로 조회됨을 알 수 있다.
2.6. ThreadLocal - 동기화 개발
- FieldLogTrace 에서 발생했던 동시성 문제를 ThreadLocal 로 해결해보자.
- TraceId traceIdHolder 필드를 쓰레드 로컬을 사용하도록 ThreadLocal traceIdHolder 로 변경하면 된다.
package hello.advanced.trace.logtrace;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
@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 TraceId traceIdHolder; //traceId 동기화, 동시성 이슈 존재함
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);
}
private void syncTraceId() {
TraceId traceId = traceIdHolder.get();
if (traceId == null) {
traceIdHolder.set(new TraceId());
} else {
traceIdHolder.set(traceId.createNextId());
}
}
@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 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();
}
}
- hello/advanced/trace/logtrace/ThreadLocalLogTrace.java
- traceIdHolder 가 필드에서 ThreadLocal 로 변경되었다.
* ThreadLocal.remove()
- 추가로 쓰레드 로컬을 모두 사용하고 나면 꼭 ThreadLocal.remove() 를 호출해서 쓰레드 로컬에 저장된 값을 제거해주어야 한다.
[3f902f0b] hello1
[3f902f0b] |-->hello2
[3f902f0b] |<--hello2 time=2ms
[3f902f0b] hello1 time=6ms //end() -> releaseTraceId() -> level==0,
ThreadLocal.remove() 호출
- 여기서는 releaseTraceId() 를 통해 level 이 점점 낮아져서 2 ->1 -> 0이 되면 로그를 처음 호출한 부분으로 돌아온 것이다.
- 따라서 이 경우 연관된 로그 출력이 끝난 것이다. 이제 더 이상 TraceId 값을 추적하지 않아도 된다.
- 그래서 traceId.isFirstLevel() ( level==0 )인 경우 ThreadLocal.remove()를 호출해서 쓰레드로컬에 저장된 값을 제거해준다.
2.7. ThreadLocal - 동기화 적용
- 스프링 빈 등록을 동시성 문제가 있는 FieldLogTrace 대신에 문제를 해결한 ThreadLocalLogTrace 을 등록하자.
package hello.advanced;
import hello.advanced.trace.logtrace.LogTrace;
import hello.advanced.trace.logtrace.ThreadLocalLogTrace;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
@Configuration
public class LogTraceConfig {
@Bean
public LogTrace logTrace() {
//return new FieldLogTrace();
return new ThreadLocalLogTrace();
}
}
- hello/advanced/LogTraceConfig.java
- Logtrace가 interface이므로 사용할 구현체를 return 함으로써 관련된 bean을 사용하는 client 소스는 변경하지 않아도된다
2.8. ThreadLocal - 주의사항
- 쓰레드 로컬의 값을 사용 후 제거하지 않고 그냥 두면 WAS(톰캣)처럼 쓰레드 풀을 사용하는 경우에 심각한 문제가 발생할 수 있다.
1. 사용자A가 저장 HTTP를 요청했다.
2. WAS는 쓰레드 풀에서 쓰레드를 하나 조회한다.
3. 쓰레드 thread-A 가 할당되었다.
4. thread-A 는 사용자A 의 데이터를 쓰레드 로컬에 저장한다.
5. 쓰레드 로컬의 thread-A 전용 보관소에 사용자A 데이터를 보관한다
1. 사용자A의 HTTP 응답이 끝난다.
2. WAS는 사용이 끝난 thread-A 를 쓰레드 풀에 반환한다. 쓰레드를 생성하는 비용은 비싸기 때문에 쓰레드를 제거하지 않고, 보통 쓰레드 풀을 통해서 쓰레드를 재사용한다.
3. thread-A 는 쓰레드풀에 아직 살아있다. 따라서 쓰레드 로컬의 thread-A 전용 보관소에 사용자A 데이터도 함께 살아있게 된다.
1. 사용자B가 조회를 위한 새로운 HTTP 요청을 한다.
2. WAS는 쓰레드 풀에서 쓰레드를 하나 조회한다.
3. 쓰레드 thread-A 가 할당되었다. (물론 다른 쓰레드가 할당될 수 도 있다.)
4. 이번에는 조회하는 요청이다. thread-A 는 쓰레드 로컬에서 데이터를 조회한다.
5. 쓰레드 로컬은 thread-A 전용 보관소에 있는 사용자A 값을 반환한다.
6. 결과적으로 사용자A 값이 반환된다.
7. 사용자B는 사용자A의 정보를 조회하게 된다.
* 결과적으로 사용자B는 사용자A의 데이터를 확인하게 되는 심각한 문제가 발생하게 된다. 이런 문제를 예방하려면 사용자A의 요청이 끝날 때 쓰레드 로컬의 값을 ThreadLocal.remove() 를 통해서 꼭 제거해야 한다.
'Spring 정리' 카테고리의 다른 글
스프링 핵심 원리 - 고급편 5 (0) | 2023.01.25 |
---|---|
스프링 핵심 원리 - 고급편 4 (0) | 2023.01.16 |
스프링 핵심 원리 - 고급편 2 (1) | 2022.10.29 |
스프링 핵심 원리 - 고급편 1 (1) | 2022.09.20 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 21 (0) | 2022.07.25 |
설정
트랙백
댓글
글
스프링 핵심 원리 - 고급편 2
인프런 강의 61일차.
- 스프링 핵심 원리 - 고급편 (김영한 강사님)
- 반드시 한번은 정복해야할 쉽지 않은 내용들
- 크게 3가지 고급 개념을 학습
1. 스프링 핵심 디자인 패턴
> 템플릿 메소드 패턴
> 전략 패턴
> 템플릿 콜백 패턴
> 프록시 패턴
> 데코레이터 패턴
2. 동시성 문제와 쓰레드 로컬
> 웹 애플리케이션
> 멀티쓰레드
> 동시성 문제
3. 스프링 AOP
> 개념, 용어정리
> 프록시 - JDK 동적 프록시, CGLIB
> 동작 원리
> 실전 예제
> 실무 주의 사항
- 기타
> 스프링 컨테이너의 확장 포인트 - 빈 후처리기
> 스프링 애플리케이션을 개발하는 다양한 실무 팁
- 타입 컨버터, 파일 업로드, 활용, 쿠키, 세션, 필터, 인터셉터, 예외 처리, 타임리프, 메시지, 국제화, 검증 등등
1.4. 로그 추적기 V1 - 적용
- 애플리케이션에 우리가 개발한 로그 추적기를 적용해보자.
- v0 -> v1 복사 후 v1 적용
package hello.advanced.app.v1;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import lombok.RequiredArgsConstructor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
@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 {
status = trace.begin("OrderController.request()");
orderService.OrderItem(itemId);
trace.end(status);
return "ok";
}catch (Exception e){
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v1/OrderControllerV1.java
- HelloTraceV1 trace : HelloTraceV1 을 주입 받는다.
- 참고로 HelloTraceV1 은 @Component 애노테이션을 가지고 있기 때문에 컴포넌트 스캔의 대상이 된다.
- trace.begin("OrderController.request()") : 로그를 시작할 때 메시지 이름으로 컨트롤러 이름 + 메서드 이름을 주었다.
> 이렇게 하면 어떤 컨트롤러와 메서드가 호출되었는지 로그로 편리하게 확인할 수 있다. 물론 수작업이다
- 단순하게 trace.begin() , trace.end() 코드 두 줄만 적용하면 될 줄 알았지만, 실상은 그렇지 않다. trace.exception() 으로 예외까지 처리해야 하므로 지저분한 try , catch 코드가 추가된다.
- begin() 의 결과 값으로 받은 TraceStatus status 값을 end() , exception() 에 넘겨야 한다. 결국 try , catch 블록 모두에 이 값을 넘겨야한다. 따라서 try 상위에 TraceStatus status 코드를 선언해야 한다. 만약 try 안에서 TraceStatus status 를 선언하면 try 블록안에서만 해당 변수가 유효하기 때문에 catch 블록에 넘길 수 없다. 따라서 컴파일 오류가 발생한다.
- throw e : 예외를 꼭 다시 던져주어야 한다. 그렇지 않으면 여기서 예외를 먹어버리고, 이후에 정상 흐름으로 동작한다. 로그는 애플리케이션에 흐름에 영향을 주면 안된다. 로그 때문에 예외가 사라지면 안된다.
package hello.advanced.app.v1;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;
@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; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v1/OrderServiceV1.java
package hello.advanced.app.v1;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;
@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")) { //상품 ID 가 ex 면 예외 처리
throw new IllegalStateException("예외 발생!");
}
sleep(1000); //상품을 저장하는데 1초가 걸린다고 가정
trace.end(status);
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
private void sleep(int miilis) {
try {
Thread.sleep(miilis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/app/v1/OrderRepositoryV1.java
//정상 실행 로그
[11111111] OrderController.request()
[22222222] OrderService.orderItem()
[33333333] OrderRepository.save()
[33333333] OrderRepository.save() time=1000ms
[22222222] OrderService.orderItem() time=1001ms
[11111111] OrderController.request() time=1001ms
- 아직 level 관련 기능과 transaction id 를 맞추는 부분은 개발하지 않았다.
[0c7f8444] OrderController.request()
[b6506b2b] OrderService.OrderItem()
[2161fa31] OrderRepository.save()
[2161fa31] OrderRepository.save() time=0ms ex=java.lang.IllegalStateException: 예외 발생!
[b6506b2b] OrderService.OrderItem() time=0ms ex=java.lang.IllegalStateException: 예외 발생!
[0c7f8444] OrderController.request() time=4ms ex=java.lang.IllegalStateException: 예외 발생!
- HelloTraceV1 덕분에 직접 로그를 하나하나 남기는 것 보다는 편하게 여러가지 로그를 남길 수 있었다. 하지만 로그를 남기기 위한 코드가 생각보다 너무 복잡하다. 남은 요구사항을 보자
* 남은 요구사항
- 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
- 애플리케이션의 흐름을 변경하면 안됨
> 로그를 남긴다고 해서 비즈니스 로직의 동작에 영향을 주면 안됨
- 메서드 호출에 걸린 시간
- 정상 흐름과 예외 흐름 구분
> 예외 발생시 예외 정보가 남아야 함
- 메서드 호출의 깊이 표현
- HTTP 요청을 구분
> HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함
> 트랜잭션 ID (DB 트랜잭션X), 여기서는 하나의 HTTP 요청이 시작해서 끝날 때 까지를 하나의 트랜잭션이라 함
* 남은 기능은 직전 로그의 깊이와 트랜잭션 ID가 무엇인지 알아야 할 수 있는 일이다. 예를 들어서 OrderController.request() 에서 로그를 남길 때 어떤 깊이와 어떤 트랜잭션 ID를 사용했는지를 그 다음에 로그를 남기는 OrderService.orderItem() 에서 로그를 남길 때 알아야한다. 결국 현재 로그의 상태 정보인 트랜잭션ID 와 level 이 다음으로 전달되어야 한다. 정리하면 로그에 대한 문맥( Context ) 정보가 필요하다.
1.5. 로그 추적기 V2 - 파라미터로 동기화 개발
- 트랜잭션ID와 메서드 호출의 깊이를 표현하는 하는 가장 단순한 방법은 사용한 트랜잭션ID 와 level 를 파라미터화 한다.
package hello.advanced.trace.helloTrace;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;
@Slf4j
@Component
public class HelloTraceV2 {
...
//V2에서 추가
public TraceStatus beginSync(TraceId beforeTraceId, String message) {
// TraceId traceId = new TraceId();
TraceId nextId = beforeTraceId.createNextId();
Long startTimeMs = System.currentTimeMillis();
log.info("[{}] {}{}", nextId.getId(), addSpace(START_PREFIX, nextId.getLevel()), message);
return new TraceStatus(nextId, startTimeMs, message);
}
...
}
- hello/advanced/trace/helloTrace/HelloTraceV2.java
- 기존 HelloTraceV1에서 beginSync 메소드만 추가되었다,
* beginSync(..) : 기존 TraceId 에서 createNextId() 를 통해 다음 ID를 구한다.
- createNextId() 의 TraceId 생성 로직 : 트랜잭션ID는 기존과 같이 유지하고, 깊이를 표현하는 Level만 하나 증가한다.
package hello.advanced.trace.helloTrace;
import hello.advanced.trace.TraceStatus;
import org.junit.jupiter.api.Test;
class HelloTraceV2Test {
@Test
void begin_end_level2() {
HelloTraceV2 trace = new HelloTraceV2();
TraceStatus status1 = trace.begin("hello1");
TraceStatus status2 = trace.beginSync(status1.getTraceId(), "hello2");
//status end는 호출한 순서 역순으로 진행.
trace.end(status2);
trace.end(status1);
}
@Test
void begin_exception_level2() {
HelloTraceV2 trace = new HelloTraceV2();
TraceStatus status1 = trace.begin("hello1");
TraceStatus status2 = trace.beginSync(status1.getTraceId(), "hello2");
//status end는 호출한 순서 역순으로 진행.
trace.exception(status2, new IllegalStateException());
trace.exception(status1, new IllegalStateException());
}
}
- hello/advanced/trace/helloTrace/HelloTraceV2Test.java
- HelloTrace2를 적용한 Test
// begin_end_level2() - 실행 로그
[299b9e59] hello1
[299b9e59] |-->hello2
[299b9e59] |<--hello2 time=8ms
[299b9e59] hello1 time=22ms
// begin_exception_level2() - 실행 로그
[5beb874d] hello1
[5beb874d] |-->hello2
[5beb874d] |<X-hello2 time=1ms ex=java.lang.IllegalStateException
[5beb874d] hello1 time=2ms ex=java.lang.IllegalStateException
- 같은 트랜잭션ID 를 유지하고 level 을 통해 메서드 호출의 깊이를 표현하는 것을 확인할 수 있다.
1.6. 로그 추적기 V2 - 적용
- v1 -> v2 복사 후 v2 적용
- 메서드 호출의 깊이를 표현하고, HTTP 요청도 구분해보자. 이렇게 하려면 처음 로그를 남기는 OrderController.request() 에서 로그를 남길 때 어떤 깊이와 어떤 트랜잭션 ID를 사용했는지 다음 차례인 OrderService.orderItem() 에서 로그를 남기는 시점에 알아야한다.
- 결국 현재 로그의 상태 정보인 트랜잭션ID 와 level 이 다음으로 전달되어야 한다.
- 이 정보는 TraceStatus.traceId 에 담겨있다. 따라서 traceId 를 컨트롤러에서 서비스를 호출할 때 넘겨주면 된다
package hello.advanced.app.v2;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import lombok.RequiredArgsConstructor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
@RequiredArgsConstructor
public class OrderControllerV2 {
private final OrderServiceV2 orderService;
private final HelloTraceV1 trace;
@GetMapping("/v2/request")
public String request(String itemId) {
TraceStatus status = null;
try {
status = trace.begin("OrderController.request()");
orderService.OrderItem(status.getTraceId(), itemId);
trace.end(status);
return "ok";
}catch (Exception e){
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v2/OrderControllerV2.java
- TraceStatus status = trace.begin() 에서 반환 받은 TraceStatus 에는 트랜잭션ID 와 level 정보가 있는 TraceId 가 있다.
- orderService.orderItem() 을 호출할 때 TraceId 를 파라미터로 전달한다.
- TraceId 를 파라미터로 전달하기 위해 OrderServiceV2.orderItem() 의 파라미터에 TraceId 를 추가해야 한다.
package hello.advanced.app.v2;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import hello.advanced.trace.helloTrace.HelloTraceV2;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;
@Service
@RequiredArgsConstructor
public class OrderServiceV2 {
private final OrderRepositoryV2 orderRepository;
private final HelloTraceV2 trace;
public void OrderItem(TraceId traceId, String itemId){
TraceStatus status = null;
try {
status = trace.beginSync(traceId, "OrderService.OrderItem()");
orderRepository.save(status.getTraceId(), itemId);
trace.end(status);
}catch (Exception e){
trace.exception(status, e);
throw e; //예외를 꼭 다시 던져줘야 한다. (trace.exception에서 예외처리를 해두었기 때문)
}
}
}
- hello/advanced/app/v2/OrderServiceV2.java
- orderItem() 은 파라미터로 전달 받은 traceId 를 사용해서 trace.beginSync() 를 실행한다.
- beginSync() 는 내부에서 다음 traceId 를 생성하면서 트랜잭션ID는 유지하고 level 은 하나 증가시킨다.
- beginSync() 가 반환한 새로운 TraceStatus 를 orderRepository.save() 를 호출하면서 파라미터로 전달한다.
- TraceId 를 파라미터로 전달하기 위해 orderRepository.save() 의 파라미터에 TraceId 를 추가해야 한다.
package hello.advanced.app.v2;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.helloTrace.HelloTraceV1;
import hello.advanced.trace.helloTrace.HelloTraceV2;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;
@Repository
@RequiredArgsConstructor
public class OrderRepositoryV2 {
private final HelloTraceV2 trace;
public void save(TraceId traceId, String itemId) {
TraceStatus status = null;
try {
status = trace.beginSync(traceId, "OrderRepository.save()");
//저장 로직
if (itemId.equals("ex")) { //상품 ID 가 ex 면 예외 처리
throw new IllegalStateException("예외 발생!");
}
sleep(1000); //상품을 저장하는데 1초가 걸린다고 가정
trace.end(status);
} catch (Exception e) {
trace.exception(status, e);
throw e;
}
}
private void sleep(int miilis) {
try {
Thread.sleep(miilis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello/advanced/app/v2/OrderRepositoryV2.java
- save() 는 파라미터로 전달 받은 traceId 를 사용해서 trace.beginSync() 를 실행한다.
- beginSync() 는 내부에서 다음 traceId 를 생성하면서 트랜잭션ID는 유지하고 level 은 하나 증가시킨다.
- beginSync() 는 이렇게 갱신된 traceId 로 새로운 TraceStatus 를 반환한다.
- trace.end(status) 를 호출하면서 반환된 TraceStatus 를 전달한다
// 정상 실행 로그
[ef297b0a] OrderController.request()
[ef297b0a] |-->OrderService.OrderItem()
[ef297b0a] | |-->OrderRepository.save()
[ef297b0a] | |<--OrderRepository.save() time=1004ms
[ef297b0a] |<--OrderService.OrderItem() time=1005ms
[ef297b0a] OrderController.request() time=1008ms
// 예외 실행 로그
[0bd1dc2d] OrderController.request()
[0bd1dc2d] |-->OrderService.OrderItem()
[0bd1dc2d] | |-->OrderRepository.save()
[0bd1dc2d] | |<X-OrderRepository.save() time=1ms ex=java.lang.IllegalStateException: 예외 발생!
[0bd1dc2d] |<X-OrderService.OrderItem() time=2ms ex=java.lang.IllegalStateException: 예외 발생!
[0bd1dc2d] OrderController.request() time=2ms ex=java.lang.IllegalStateException: 예외 발생!
- 실행 로그를 보면 같은 HTTP 요청에 대해서 트랜잭션ID 가 유지되고, level 도 잘 표현되는 것을 확인할 수 있다.
- 모든 요구사항을 만족했다.
* 사용할 때 문제
- HTTP 요청을 구분하고 깊이를 표현하기 위해서 TraceId 동기화가 필요하다
- TraceId 의 동기화를 위해서 관련 메서드의 모든 파라미터를 수정해야 한다.
> 만약 인터페이스가 있다면 인터페이스까지 모두 고쳐야 하는 상황이다.
- 로그를 처음 시작할 때는 begin() 을 호출하고, 처음이 아닐때는 beginSync() 를 호출해야 한다
> 만약에 컨트롤러를 통해서 서비스를 호출하는 것이 아니라, 다른 곳에서 서비스를 처음으로 호출하는 상황이라면 파리미터로 넘길 TraceId 가 없다
'Spring 정리' 카테고리의 다른 글
스프링 핵심 원리 - 고급편 4 (0) | 2023.01.16 |
---|---|
스프링 핵심 원리 - 고급편 3 (0) | 2022.10.29 |
스프링 핵심 원리 - 고급편 1 (1) | 2022.09.20 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 21 (0) | 2022.07.25 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 20 (0) | 2022.07.22 |
설정
트랙백
댓글
글
스프링 핵심 원리 - 고급편 1
인프런 강의 60일차.
- 스프링 핵심 원리 - 고급편 (김영한 강사님)
- 반드시 한번은 정복해야할 쉽지 않은 내용들
- 크게 3가지 고급 개념을 학습
1. 스프링 핵심 디자인 패턴
> 템플릿 메소드 패턴
> 전략 패턴
> 템플릿 콜백 패턴
> 프록시 패턴
> 데코레이터 패턴
2. 동시성 문제와 쓰레드 로컬
> 웹 애플리케이션
> 멀티쓰레드
> 동시성 문제
3. 스프링 AOP
> 개념, 용어정리
> 프록시 - JDK 동적 프록시, CGLIB
> 동작 원리
> 실전 예제
> 실무 주의 사항
- 기타
> 스프링 컨테이너의 확장 포인트 - 빈 후처리기
> 스프링 애플리케이션을 개발하는 다양한 실무 팁
- 타입 컨버터, 파일 업로드, 활용, 쿠키, 세션, 필터, 인터셉터, 예외 처리, 타임리프, 메시지, 국제화, 검증 등등
1. 예제만들기 - 프로젝트 생성
- 프로젝트 선택 Project : Gradle Project
- Language : Java
- Spring Boot : 2.7.0
- Group : hello
- Artifact : advancde
- Name : advanced
- Package name : hello.advanced
- Packaging : Jar
- Java : 11
- Dependencies : Spring Web, Lombok
* gradle.build 실행 후 아래 오류 발생 시 gradle-wrapper.properties에서 gradle 버전을 6.9 이하로 변경해서 다운로드하자. (gradle-6.9-all.zip)
> Unable to find method 'org.gradle.api.artifacts.result.ComponentSelectionReason.getDescription()Ljava/lang/String;'. Possible causes for this unexpected error include: Gradle's dependency cache may be corrupt (this sometimes occurs after a network connection timeout.) Re-download dependencies and sync project (requires network)
1.1. 예제만들기 - 프로젝트 생성
- V0 학습을 위한 간단한 예제 프로젝트를 만들어보자.
- 상품을 주문하는 프로세스로 가정하고, 일반적인 웹 애플리케이션에서 Controller Service Repository로 이어지는 흐름을 최대한 단순하게 만들어보자.
package hello.advanced.app.v0;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;
@Repository
@RequiredArgsConstructor
public class OrderRepositoryV0 {
public void save(String itemId) {
//저장 로직
if (itemId.equals("ex")) { //상품 ID 가 ex 면 예외 처리
throw new IllegalStateException("예외 발생!");
}
sleep(1000); //상품을 저장하는데 1초가 걸린다고 가정
}
private void sleep(int miilis) {
try {
Thread.sleep(miilis);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
- hello.advanced.app.v0.OrderRepositoryV0.java
- @Repository : 컴포넌트 스캔의 대상이 된다. 따라서 스프링 빈으로 자동 등록된다.
- sleep(1000) : 리포지토리는 상품을 저장하는데 약 1초 정도 걸리는 것으로 가정하기 위해 1초 지연을 주었다. (1000ms)
- 예외가 발생하는 상황도 확인하기 위해 파라미터 itemId 의 값이 ex 로 넘어오면 IllegalStateException 예외가 발생하도록 했다.
package hello.advanced.app.v0;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;
@Service
@RequiredArgsConstructor
public class OrderService {
private final OrderRepositoryV0 orderRepositoryV0;
public void OrderItem(String itemId){
orderRepositoryV0.save(itemId);
}
}
- hello.advanced.app.v0.OrderService.java
- @Service : 컴포넌트 스캔의 대상이 된다.
- 실무에서는 복잡한 비즈니스 로직이 서비스 계층에 포함되지만, 예제에서는 단순 저장 코드만 있다
1.2. 로그 추적기 - 요구사항 분석
- 애플리케이션에 병목이 자주 발생하고 있다. 어떤 부분에서 병목이 발생하는지, 그리고 어떤 부분에서 예외가 발생하는지를 로그를 통해 확인할 수 있도록 로그를 남겨두고, 개선 및 자동화 해보자
* 요구사항
- 모든 PUBLIC 메서드의 호출과 응답 정보를 로그로 출력
- 애플리케이션의 흐름을 변경하면 안됨
> 로그를 남긴다고 해서 비즈니스 로직의 동작에 영향을 주면 안됨
- 메서드 호출에 걸린 시간
- 정상 흐름과 예외 흐름 구분
> 예외 발생시 예외 정보가 남아야 함
- 메서드 호출의 깊이 표현
- HTTP 요청을 구분
> HTTP 요청 단위로 특정 ID를 남겨서 어떤 HTTP 요청에서 시작된 것인지 명확하게 구분이 가능해야 함
> 트랜잭션 ID (DB 트랜잭션X), 여기서는 하나의 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: 예외 발생!
1.3. 로그 추적기 V1 - 프로토타입 개발
- 애플리케이션의 모든 로직에 직접 로그를 남겨도 되지만, 그것보다는 더 효율적인 개발 방법이 필요하다.
- 특히 트랜잭션ID와 깊이를 표현하는 방법은 기존 정보를 이어 받아야 하기 때문에 단순히 로그만 남긴다고 해결할 수 있는 것은 아니다.
- 먼저 프로토타입 버전을 개발해보자. 아마 코드를 모두 작성하고 테스트 코드까지 실행해보아야 어떤 것을 하는지 감이 올 것이다.
- 로그 추적기를 위한 기반 데이터를 가지고 있는 TraceId , TraceStatus 클래스를 만들어보자
package hello.advanced.trace;
import java.util.UUID;
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);
}
private boolean isFirstLevel(){
return level == 0;
}
public String getId() {
return id;
}
public void setId(String id) {
this.id = id;
}
public int getLevel() {
return level;
}
public void setLevel(int level) {
this.level = level;
}
}
- hello.advanced.trace.TraceId.java
- 로그 추적기는 트랜잭션ID와 깊이를 표현하는 방법이 필요하다.
> 여기서는 트랜잭션ID와 깊이를 표현하는 level을 묶어서 TraceId 라는 개념을 만들었다.
> TraceId 는 단순히 id (트랜잭션ID)와 level 정보를 함께 가지고 있다.
- UUID : TraceId 를 처음 생성하면 createId() 를 사용해서 UUID를 만들어낸다. 너무 길어서 여기서는 앞 8자리만 사용한다.
> 이 정도면 로그를 충분히 구분할 수 있다. 여기서는 이렇게 만들어진 값을 트랜잭션ID 로 사용한다
- createNextId() : 다음 TraceId 를 만든다. level이 증가해도 트랜잭션ID는 같아야 한다.
> createNextId() 를 사용해서 현재 TraceId 를 기반으로 다음 TraceId 를 만들면 id 는 기존과 같고, level 은 하나 증가한다.
- createPreviousId() : createNextId() 의 반대 역할을 한다. id 는 기존과 같고, level 은 하나 감소한다.
- sFirstLevel() : 첫 번째 레벨 여부를 편리하게 확인할 수 있는 메서드
package hello.advanced.trace;
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 TraceId getTraceId() {
return traceId;
}
public void setTraceId(TraceId traceId) {
this.traceId = traceId;
}
public Long getStartTimeMs() {
return startTimeMs;
}
public void setStartTimeMs(Long startTimeMs) {
this.startTimeMs = startTimeMs;
}
public String getMessage() {
return message;
}
public void setMessage(String message) {
this.message = message;
}
}
- hello.advanced.trace.TraceStatus.java
- TraceStatus : 로그의 상태 정보를 나타낸다.
- 로그를 시작하면 끝이 있어야 한다.
> [796bccd9] OrderController.request() //로그 시작
> [796bccd9] OrderController.request() time=1016ms //로그 종료
> TraceStatus 는 로그를 시작할 때의 상태 정보를 가지고 있다. 이 상태 정보는 로그를 종료할 때 사용된다.
- traceId : 내부에 트랜잭션ID와 level을 가지고 있다.
- startTimeMs : 로그 시작시간이다. 로그 종료시 이 시작 시간을 기준으로 시작~종료까지 전체 수행 시간을 구할 수 있다.
- message : 시작시 사용한 메시지이다. 이후 로그 종료시에도 이 메시지를 사용해서 출력한다.
* TraceId , TraceStatus 를 사용해서 실제 로그를 생성하고, 처리하는 기능을 개발해보자
package hello.advanced.trace.helloTrace;
import hello.advanced.trace.TraceId;
import hello.advanced.trace.TraceStatus;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;
@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();
}
}
- hello.advanced.trace.helloTrace.HelloTraceV1.java
- 실제 로그를 시작하고 종료할 수 있다. 그리고 로그를 출력하고 실행시간도 측정할 수 있다.
- @Component : 싱글톤으로 사용하기 위해 스프링 빈으로 등록한다. 컴포넌트 스캔의 대상이 된다
* 공개 메서드
- 로그 추적기에서 사용되는 공개 메서드는 다음 3가지이다.
1. TraceStatus begin(String message) : 로그를 시작한다.
> 로그 메시지를 파라미터로 받아서 시작 로그를 출력한다. 응답 결과로 현재 로그의 상태인 TraceStatus 를 반환한다
2. void end(TraceStatus status) : 로그를 정상 종료한다.
> 파라미터로 시작 로그의 상태( TraceStatus )를 전달 받는다.
> 이 값을 활용해서 실행 시간을 계산하고, 종료시에도 시작할 때와 동일한 로그 메시지를 출력할 수 있다.
> 정상 흐름에서 호출한다
3. void exception(TraceStatus status, Exception e)
> 로그를 예외 상황으로 종료한다.
> TraceStatus , Exception 정보를 함께 전달 받아서 실행시간, 예외 정보를 포함한 결과 로그를 출력한다.
> 예외가 발생했을 때 호출한다.
* 비공개 메서드
1. complete(TraceStatus status, Exception e
> end() , exception() , 의 요청 흐름을 한곳에서 편리하게 처리한다. 실행 시간을 측정하고 로그를 남긴다
2. String addSpace(String prefix, int level) : 다음과 같은 결과를 출력한다.
prefix: -->
level 0:
level 1: |-->
level 2: | |-->
prefix: <--
level 0:
level 1: |<--
level 2: | |<--
prefix: <X
level 0:
level 1: |<X
level 2: | |<X
* 테스트 작성
package hello.advanced.trace.helloTrace;
import hello.advanced.trace.TraceStatus;
import org.junit.jupiter.api.Test;
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());
}
}
- hello.advanced.trace.helloTrace.HelloTraceV1Test.java
- 테스트 코드를 보면 로그 추적기를 어떻게 실행해야 하는지, 그리고 어떻게 동작하는지 이해가 될 것이다
- begin_end() - 실행 로그
> [d2fd2d18] hello
> [d2fd2d18] hello time=5ms
- begin_exception() - 실행 로그
> [d2fd2d18] hello
> [d2fd2d18] hello time=10ms ex=java.lang.IllegalStateException
* 참고: 이것은 온전한 테스트 코드가 아니다. 일반적으로 테스트라고 하면 자동으로 검증하는 과정이 필요하다. 이 테스트는 검증하는 과정이 없고 결과를 콘솔로 직접 확인해야 한다. 이렇게 응답값이 없는 경우를 자동으로 검증하려면 여러가지 테스트 기법이 필요하다. 이번 강의에서는 예제를 최대한 단순화 하기 위해 검증 테스트를 생략했다.
* 주의: 지금까지 만든 로그 추적기가 어떻게 동작하는지 확실히 이해해야 다음 단계로 넘어갈 수 있다. 복습과 코드를 직접 만들어보면서 확실하게 본인 것으로 만들고 다음으로 넘어가자.
'Spring 정리' 카테고리의 다른 글
스프링 핵심 원리 - 고급편 3 (0) | 2022.10.29 |
---|---|
스프링 핵심 원리 - 고급편 2 (1) | 2022.10.29 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 21 (0) | 2022.07.25 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 20 (0) | 2022.07.22 |
스프링 MVC 2편 - 백엔드 웹 개발 활용 기술 19 (0) | 2022.07.20 |