[스프링 핵심 원리 - 고급편] #2. 필드 동기화

[YONGHYNG]

필드 동기화 - 적용

• FieldLogTrace를 수동으로 스프링 빈으로 등록, 수동으로 등록하면 향후 구현체를 편리하게 변경할 수 있음

LogTraceConfig

//v2 -> v3 로 버전만 변경
package hello.advanced;

import hello.advanced.trace.logtrace.FieldLogTrace;
import hello.advanced.trace.logtrace.LogTrace;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration //스프링 설정 클래스
public class LogTraceConfig {
     
       @Bean
       public LogTrace logTrace() {
             return new FieldLogTrace();
      }
}

• Spring이 FieldLogTrace를 LogTrace 인터페이스로 빈으로 등록

OrderControllerV3

package hello.advanced.app.v3;

import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.hellotrace.HelloTraceV2;
import hello.advanced.trace.logtrace.LogTrace;
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 LogTrace trace;

    @GetMapping("/v3/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;//예외를 꼭 다시 던져주어야 한다.
        }
    }
}

OrderServiceV3

package hello.advanced.app.v3;

import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.logtrace.LogTrace;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Service;

@Service
@RequiredArgsConstructor
public class OrderServiceV3 {

    private final OrderRepositoryV3 orderRepository;
    private final LogTrace 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;
        }

    }
}

OrderRepositoryV3

package hello.advanced.app.v3;

import hello.advanced.trace.TraceStatus;
import hello.advanced.trace.logtrace.LogTrace;
import hello.advanced.trace.template.AbstractTemplate;
import lombok.RequiredArgsConstructor;
import org.springframework.stereotype.Repository;

@Repository
@RequiredArgsConstructor
public class OrderRepositoryV3 {

    private final LogTrace 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();
        }
    }
}

정상 로그 실행

예외 실행 로그

필드 동기화 - 동시성 문제

• 로그 추적기를 실제 서비스에 배포했다 가정할 때, 테스트에는 문제가 없었음 하지만 직전에 만든 FieldLogTrace는 심각한 동시성 문제가 있음

기대하는 결과

기대하는 결과 - 로그 분리해서 확인하기

실제 결과

• 트랜잭션ID도 동일하고, level도 많이 꼬이는 오류 발생
• 동시성 문제 사실 동시성 문제임, FieldLogTrace는 싱글톤으로 등록된 스프링 빈, 이 객체의 인스턴스가 애플리케이션에 딱 1 존재한다는 뜻
• 이렇게 하나만 있는 인스턴스의 FieldLogTrace.traceIdHolder 필드를 여러 쓰레드가 동시에 접근하기 때문에 문제 발생

동시성 문제 - 예제 코드

테스트 코드에서도 lombok 사용을 위해 코드 추가

build.gradle
'''
dependencies {
...
//테스트에서 lombok 사용
testCompileOnly 'org.projectlombok:lombok'
testAnnotationProcessor 'org.projectlombok:lombok'
}
'''

• 이렇게 해야 테스트 코드에 @slf4j 같은 애노테이션 작동

**FieldService **

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 millis) {
        try{
            Thread.sleep(millis);
        } catch (InterruptedException e){
            e.printStackTrace();
        }
    }
}

• 파라미터로 넘어온 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);
        threadA.setName("thread-B");

        threadA.start(); //A 실행
        sleep(2000); //동시성 문제 발생X
        threadB.start();//B 실행

        sleep(3000);
        log.info("main exit");
    }

    private void sleep(int millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e){
            e.printStackTrace();
        }
    }
}

순서대로 실행

• sleep(2000)을 설정해서 thread-A 실행이 끝나고 thread-B가 실행되도록 함
• 참고로 FieldService.logic() 메서드는 내부에 sleep(1000)으로 1초의 지연이 있음, 따라서 1초 이후에 호출하면 순서대로 실행 가능

실행 결과

실행 결과를 보면 문제가 없음

• Thread-A 는 userA 를 nameStore 에 저장
• Thread-A 는 userA 를 nameStore 에서 조회
• Thread-B 는 userB 를 nameStore 에 저장
• Thread-B 는 userB 를 nameStore 에서 조회

//sleep(2000); //동시성 문제 발생X
sleep(100); //동시성 문제 발생O

실행 결과 -- 문제 발생

• 먼저 thread-A가 userA 값을 nameStore에 보관

• thread-A의 호출이 끝나면서 nameStore의 결과를 반환, 이때 nameStore는 앞의 2번에서 userB 값으로 대체, 따라서 기대했던 userA 값이 아니라 userB 값 반환
• thread-B 호출이 끝나면 nameStore 의 결과인 userB를 반환

정리

1. Thread-A 는 userA 를 nameStore 에 저장
2. Thread-B 는 userB 를 nameStore 에 저장
3. Thread-A 는 userB 를 nameStore 에서 조회
4. Thread-B 는 userB 를 nameStore 에서 조회

동시성 문제

• 결과적으로 Thread-A입장에서는 저장한 데이터와 조회한 데이터가 다른 문제 발생
• 이처럼 여러 쓰레드가 동시에 같은 인스턴스의 필드 값을 변경하면서 발생하는 문제를 동시성 문제라고 함
• 이런 동시성 문제는 여러 쓰레드가 같은 인스턴스의 필드에 접근해야 하기 떄문에 트래픽이 적은 상황에서는 잘 안 나타남, 트래픽이 많아질 수록 자주 발생
• 특히 스프링 빈 처럼 싱글톤 객체의 필드를 변경하며 사용할 떄 동시성 문제 조심해야 함

참고

• 이런 동시성 묹는 지역 변수에는 잘 발생하지 않음, 지역 변수는 쓰레드마다 각각 다른 메모리 영역이 할당 됨
• 동시성 문제가 발생하는 곳은 같은 인스턴스 필드(주로 싱글톤에서 발생) 혹은, static 같은 공용 필드에 접근할 때 발생
• 동시성 문제는 값을 읽기만 하면 발생 안 함, 어디선가 값을 변경하기 떄문에 발생
• 동시성 문제를 해결하려면 --> 쓰레드 로컬 사용하면 됨