최근 테스트 코드를 작성하다 생각지도 못한 오류를 경험하여 이야기해 보려 한다.
서버가 여러 대 있는 환경에서 미들웨어로부터 단 하나의 서버만 이벤트 콜백을 받아야 하는 상황에서 이를 테스트하고자 할 때 생길 수 있는 문제이다.
겪은 오류는 테스트 컨텍스트의 캐싱과 관련되어 있기에 이에 대해 먼저 설명하고 넘어가 보겠다.
스프링 프레임워크에서는 테스트 코드를 실행할 때 매번 컨텍스트를 초기화하지 않는다. 현재 실행하는 테스트 suite의 context에서 이전에 실행했던 테스트 suite의 context 가 동일하다면 두 테스트는 동일한 context를 사용한다.
이때, 각 테스트 suite의 context 가 동일한지에 대한 판단은 다음의 키를 가지고 한다.
- locations (@ContextConfiguration 의 필드로 선언되어 있는 location 필드. xml 설정의 위치를 의미)
- classes (@ContextConfiguration 의 필드로 선언 되어 있는 설정 클래스들)
- contextInitializerClasses (@ContextConfiguration 필드로 선언 되어 있는 콘텍스트 초기화 시 가장 먼저 실행되는 클래스)
- contextLoader (@ContextConfiguration 의 필드로 선언되어 있는 컨텍스트 로더)
- contextCustomizers (@DynamicPropertySource, @MockBean, @SpyBean과 같은 다양한 Spring Boot 테스트 지원 컨텍스트 빈)
- parent (@ContextHierarchy 내의 상위 컨텍스트)
- activeProfiles (@ActiveProfiles)
- propertySourceDescriptors, propertySourceProperties (@TestPropertySource(locations = "classpath:test.properties", properties = {"username=testUser", "password=secret"}) 과 같은 설정 값)
- resourceBasePath (@WebAppConfiguration 필드에 있는 웹 관련 resourece 경로 "/webapp" 과 같은 경로)
위 키 목록 중 @ContextConfiguration과 관련한 내용은 기본값 외의 값을 사용하는 경우는 매우 드물기에 contextCustomizers, activeProfiles, propertySourceProperties를 가지고 테스트 컨텍스트를 얼마나 사용할지 결정하면 된다.
하나의 예를 들자면 개인적으로 웹 계층, 서비스 계층, 데이터 접근 계층은 서로 다른 테스트 컨텍스트를 사용하는 편이 좋다고 생각한다.
코드로 살펴보자
@WebMvcTest
@ActiveProfiles("test")
public abstract class ControllerTestSupport {
@Autowired
protected MockMvc mockMvc;
@Autowired
protected ObjectMapper objectMapper;
@MockBean
protected ExampleService1 exampleService1;
@MockBean
protected ExampleService2 exampleService2;
}
class ExampleController1Test extends ControllerTestSupport {
// 유효하지 않은 파라미터 조합을 제공하는 메소드
private static Stream<Arguments> invalidParameters() {
return Stream.of(
Arguments.of("-1", "5", "COMMENT_COUNT"), // 잘못된 offset
Arguments.of("0", "-5", "RECENT_DATE"), // 잘못된 limit
Arguments.of("0", "5", "INVALID_SORT") // 잘못된 orderBy
);
}
@DisplayName("example1 유효하지 않은 파라미터 테스트")
@ParameterizedTest
@MethodSource("invalidParameters")
void getAllCropsPostInvalidParameters(String offset, String limit, String orderBy) throws Exception {
mockMvc.perform(get("/v1/example") // URL의 prefix 수정
.param("offset", offset)
.param("limit", limit)
.param("orderBy", orderBy)
.contentType(MediaType.APPLICATION_JSON))
.andExpect(status().isBadRequest());
}
}
class ExampleController2Test extends ControllerTestSupport {
// 유효하지 않은 파라미터 조합을 제공하는 메소드
private static Stream<Arguments> invalidParameters() {
return Stream.of(
Arguments.of("-1", "5", "COMMENT_COUNT"), // 잘못된 offset
Arguments.of("0", "-5", "RECENT_DATE"), // 잘못된 limit
Arguments.of("0", "5", "INVALID_SORT") // 잘못된 orderBy
);
}
@DisplayName("example2 유효하지 않은 파라미터 테스트")
@ParameterizedTest
@MethodSource("invalidParameters")
void getAllCropsPostInvalidParameters(String offset, String limit, String orderBy) throws Exception {
mockMvc.perform(get("/v2/example") // URL의 prefix 수정
.param("offset", offset)
.param("limit", limit)
.param("orderBy", orderBy)
.contentType(MediaType.APPLICATION_JSON))
.andExpect(status().isBadRequest());
}
}
웹 계층 테스트를 위해 스프링에서는 @WebMvcTest라는 어노테이션을 제공한다 해당 어노테이션에는 웹 계층과 관련한 모든 빈을 context에 로딩한다. 컨트롤러를 따로 지정해주지 않는다면 모든 컨트롤러를 포함해서 로딩을 한다. 컨트롤러를 로딩하기 위해서는 컨트롤러 내부에 있는 서비스 컴포넌트 또한 로딩을 하는데, 웹 계층만 테스트하는 상황에서 서비스 컴포넌트는 mocking 하는 것이 낫다.
이때 매 컨트롤러마다 서비스 컴포넌트를 mocking 하여 context를 매번 생성할 수 없으므로 위와 같은 방식으로 추상클래스를 두어 웹 계층 테스트는 같은 컨텍스트를 사용하게 하는 것이 효율적이다. (contextCustomizers를 context 키로 사용한다는 사실을 활용) 서비스 계층, 데이터 접근 계층을 테스트하는 경우에도 마찬가지이다.
tip 테스트 컨텍스트가 의도한 개수만큼 생성이 되는지 확인하는 방법은 다음의 로그 옵션을 통해 확인 가능하며, 컨텍스트의 개수 제한도 가능하다.
logging.level=org.springframework.test.context.cache: DEBUG # 현재 테스트에서 캐싱하고 있는 컨텍스트
spring.test.context.cache.maxSize=${원하는 값}
추가적으로, 테스트 컨텍스트는 jvm 의 static 영역에 존재한다.
이제 위 개념을 장착하고, 내가 겪은 오류와 이를 해결하는 과정을 살펴보자.
두 개의 테스트 코드에서 오류가 발생했으며, 각각의 테스트는 다음과 같았다.
1. 어플리케이션이 시작할 때 시작 메시지를 카프카에 발행하고, 메시지를 소비하는지 확인하는 테스트
2. 캐시 만료 시 레디스 서버로부터 만료 이벤트를 받아 알림을 보내는 테스트
현상은 다음과 같다.
1. 위 시나리오에서 각 테스트는 간헐적으로 성공했다.
2. 1, 2 테스트 중 전체 테스트에서 가장 먼저 실행이 된 테스트는 무조건 통과했다.
3. 로그 분석 결과 실제 코드는 정상적으로 작동했다.
원인분석
현상 3에서 동작한 실제 객체의 해시값과, 테스트 코드에서 주입받은 객체의 해시 값이 달랐다.
아래의 코드를 보면 이해가 될 것이다.
@ActiveProfiles("test")
@SpringBootTest
public class AppLifecycleEventConsumerTests extends TestContainerBaseTest {
@SpyBean
AppLifecycleEventConsumer appLifecycleEventConsumer;
Logger logger = LoggerFactory.getLogger(getClass());
@DisplayName("시작이벤트 메세지 소모 확인")
@Test
void consumeEvent() throws InterruptedException {
var lock = new CountDownLatch(1);
logger.info("테스트 객체의 해시값: {}",appLifecycleEventConsumer.hashCode());
lock.await(5, TimeUnit.SECONDS);
then(appLifecycleEventConsumer).should(atLeast(1))
.consumeAppLifecycleEvent(any(), any());
}
}
@Slf4j
@Service
public class AppLifecycleEventConsumer {
@KafkaListener(topics = "${topic}", groupId= "lifecycle-handler",
containerFactory = "appLifecycleEventDtoConsumerFactory")
public void consumeAppLifecycleEvent(MessageHeaders messageHeaders, ConsumerRecord<String, AppLifecycleEventDto> dto) {
var value = dto.value();
log.info("실제 객체: {}", this.hashCode());
//로직은 생략..
}
}
02:16:12.357 [] [org.springframework.kafka.KafkaListenerEndpointContainer#0-0-C-1] [INFO ] [c.m.i.a.c.k.l.AppLifecycleEventConsumer] - 실제 객체: 1539671320
02:16:17.382 [] [Test worker] [INFO ] [c.m.i.a.c.s.AppLifecycleEventConsumerTests] - 테스트 객체의 해시값: 1040745929
@ActiveProfiles("test")
@SpringBootTest
class TaskExpiredAlertTest extends TestContainerBaseTest {
@Autowired
RedisProducer redisProducer;
@SpyBean
AlertService alertService;
@Autowired
RedisTemplate<String, String> redisTemplate;
Logger logger = LoggerFactory.getLogger(TaskExpiredAlertTest.class);
@BeforeEach
void setUp() {
redisTemplate.getConnectionFactory().getConnection().serverCommands().flushAll();
}
@DisplayName("캐시 만료 시 알림이 전송된다. (ttl 2초 임의로 설정)")
@Test
void testExpiredTaskAndAlert() throws JsonProcessingException, InterruptedException {
//given
var taskMessageDto = //중략..
var clientKey = "test";
//when
redisProducer.addNewTask(clientKey, List.of(taskMessageDto));
Thread.sleep(2100L);
logger.info("테스트에서 주입받은 AlertService 의 해시: {}", alertService.hashCode());
//then
assertAll(
() -> verify(alertService, times(1)).alertInfo(anyString(), anyString())
);
}
}
@Slf4j
@Service
@RequiredArgsConstructor
public class AlertService {
private final List<AlertChannel> channelList;
public void alertInfo(String title, String message) {
log.info("실제 해시 값: {}", this.hashCode());
//생략..
}
}
@Slf4j
@RequiredArgsConstructor
@Component
public class TaskExpiredWarningAlertService implements MessageListener {
private final AlertService alertService;
private final RedisPersonalQueueProperties properties;
@Override
public void onMessage(Message message, byte[] pattern) {
var key = new String(message.getBody());
long lockTimeSec = 10L;
boolean isLeader = Boolean.TRUE.equals(ops.setIfAbsent(key + ":" + properties.getTaskExpiredWarnAlertLockKeySuffix(), "lock", Duration.ofSeconds(lockTimeSec)));
if (key.endsWith(properties.getTaskExpiredWarnSuffix()) {
if (isLeader) {
alertService.alertInfo("캐시 만료", key + "를 가진 캐시 만료");
}
}
}
@Configuration
static class KeyExpiredListenerConfig {
/**
* 레디스에 삭제 만료 알림을 주는 이벤트를 등록 해야 함 CONFIG SET notify-keyspace-events Ex
*
* @param connectionFactory
* @param alertService
* @return
*/
@Bean
RedisMessageListenerContainer keyExpirationListenerContainer(RedisConnectionFactory connectionFactory, TaskExpiredWarningAlertService alertService) {
RedisMessageListenerContainer listenerContainer = new RedisMessageListenerContainer();
listenerContainer.setConnectionFactory(connectionFactory);
listenerContainer.addMessageListener(alertService, new PatternTopic("__keyevent@*__:expired"));
return listenerContainer;
}
}
}
02:28:40.863 [] [keyExpirationListenerContainer-5] [INFO ] [c.m.i.a.common.service.AlertService] - 실제 해시 값: 145902994
02:28:41.872 [] [Test worker] [INFO ] [c.m.i.a.c.s.TaskExpiredAlertTest] - 테스트에서 주입받은 AlertService 의 해시: 390300913
실제로 로그에 보이는 두 객체의 해시 값이 다르다. 이를 통해 실제 동작한 컴포넌트는 테스트 코드에서 주입받은 컴포넌트와 다른 것을 알 수 있다.
왜 이런 현상이 일어나는지 문서를 읽고 생각한 결과 캐싱되어 있는 context는 static 영역에 살아있고 캐싱되어 있는 컨텍스트의 컴포넌트에 레디스, 카프카의 이벤트가 전송되었기 때문에 이러한 현상이 일어난 것이라고 결론지었다. (분산 환경에서 이벤트는 딱 한번 수신해야 함)
해결하는 방법은 다양하겠지만, 핵심은 테스트 시 주입받는 컴포넌트를 이벤트를 수신하는 컴포넌트와 동일하게 하는 것이다.
다음의 선택지가 있을 텐데 이 중 내 상황에서 가장 효율적인 3번 선택을 했다. (2번 작업은 코드 변경이 너무 많아 선택하지 못함)
1. 전체 테스트 생명 주기 중 테스트 컨텍스트를 1개만 이용하도록 강제
2. kafka listener, redis listener 컴포넌트가 존재하는 컨텍스트는 1개만 존재하도록 추상화
3. 현재 실행되고 있는 context의 컴포넌트만 메시지를 수신하도록 강제
4. 레디스 리스너, 카프카 리스너에 대한 테스트를 수행하는 context를 공유하게 한 후, 전체 테스트 생명 주기 중 가장 먼저 실행 (캐싱된 컨텍스트가 0개인 상황)
현재 실행되고 있는 context의 컴포넌트만 메시지를 수신하게 하는 방법은 간단하다. property 값 중 "${topic}", "${taskExpiredWarnSuffix}" 값을 현재 테스트 suite에서 다르게 설정하면 된다. 다만, 이 방법은 리스너 코드에 외부로부터 주입받는 설정 값이 있기 때문에 작동하는 코드이므로 이러한 상황이 아니라면 2번 방법이 가장 합리적이다.
참고