우테캠 쇼핑몰 개발 프로젝트에서 테스트 시에 발생했던 여러 문제들에 대해 더 깊게 알아보았다.
@ActiveProfiles에 여러 profile을 명시하는 경우 설정 파일의 우선순위
@SpringBootTest
@ActiveProfiles({"scheduling-test", "test"})
class OrderCancelServiceExecutionTest { ... }테스트를 작성하면서 해당 테스트만 spring.jpa.hibernate.ddl-auto 설정을 create로 바꿔줘야 해서 application-scheduling-test.yml 파일에 해당 설정을 작성하고 @ActiveProfiles에 scheduling-test profile을 첫 번째로 넣어주었다. 첫 번째로 넣어줬으니 설정에 충돌이 발생했을 때 application-scheduling-test.yml이 application-test.yml보다 우선순위가 높을 거라고 생각했는데 확인해보니 아니었다. 뒤에 오는 test profile의 설정 파일 우선순위가 더 높아서 전체적으로는application-test.yml, application-scheduling-test.yml, application.yml 순으로 설정 우선순위가 결정된다. 프로젝트 내에서 두 profile 간 설정 충돌이 없어서 발견 못 하고 지나칠 뻔 했다.
대안은 없을까?
https://docs.spring.io/spring-boot/docs/current/reference/html/features.html#features.external-config
(목록에서 뒤로 갈수록 우선순위가 높다.)
스프링 공식 문서에 따르면 application.yml과 같은 config data file보다 @TestPropertySource가 우선순위가 높다고 한다. 따라서 @ActiveProfiles의 순서의 의존하기보다는 다음과 같이 @TestPropertySource를 사용해서 설정값을 명시하는 편이 마음 편하다.
@SpringBootTest
@ActiveProfiles({"scheduling-test", "test"})
@TestPropertySource(properties = {"spring.jpa.hibernate.ddl-auto=create"})
class OrderCancelServiceExecutionTest { ... }버그 투성이 schema.sql
테스트 시 테이블을 생성하기 위해 schema.sql을 사용했는데, 이 스크립트가 정확히 언제 실행되는지 몰라서 버그가 많이 발생했다. 디버그 레벨로 로깅하면서 테스트를 몇 번 돌려보니 매커니즘을 조금 알 것 같다.
1. schema.sql을 통한 데이터베이스 초기화는 JPA의 ddl-auto를 사용한 데이터베이스 초기화보다 먼저 일어난다. 애초에 스프링이 ddl-auto 관련 설정을 읽어오기 전에 schema.sql이 실행되는 걸 확인할 수 있었다.
2. SpringBootTest에 의해 ApplicationContext가 재생성될 때마다 schema.sql이 실행된다.
프로젝트에서는 컨텍스트가 계속 재사용돼서 schema.sql이 2번 이상 실행될 일이 없었는데, 이번에 코드를 뜯어 고치다가 컨텍스트가 재생성되는 상황이 발생하자마자 예외가 터졌다.
Caused by: org.h2.jdbc.JdbcSQLSyntaxErrorException: Index "IDX_2" already exists; SQL statement:
create index idx_2 on orders (last_modified_at) [42111-214]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:502)schema.sql이 2번 실행되고 결과적으로 동일 인덱스가 2번 생성되어 발생한 예외인데, 메서드가 끝날 때마다 truncate를 해줬지만 알고 보니 truncate는 인덱스를 지워주지 않았다. 인덱스 생성 구문에 if not exists를 붙여서 해결할 수 있었다.
다른 해결방법
예외가 발생한 이유는 컨텍스트가 재생성되었음에도 동일한 데이터베이스를 사용했기 때문이다. 따라서 컨텍스트마다 다른 데이터베이스를 사용하도록 하면 문제가 해결된다. @AutoConfigureTestDatabase 어노테이션을 테스트 클래스에 붙이면 해당 테스트는 application-test.yml 설정과는 무관하게 다른 데이터베이스에서 실행된다. 아래는 테스트 로그인데, 컨텍스트마다 완전히 다른 데이터베이스에서 실행되는 것을 알 수 있다.
... Starting embedded database: url='jdbc:h2:mem:fc21c4ea-3692-40b3-af19-5abbb1845c02; ...
(컨텍스트 재생성)
... Starting embedded database: url='jdbc:h2:mem:69471751-c82a-4c69-bef6-4f9a2225ef66; ...컨텍스트 캐싱 문제
마지막 문제는 지금도 완벽히 해결하지 못했다. 테스트 시에 JpaAuditing을 비활성화시킬 필요가 있었는데, 테스트에서 @EnableJpaAuditing이 붙어 있는 설정 파일을 제외시켜줌으로써 해결하려고 했다. JpaAuditing 비활성화가 필요한 테스트 클래스 하나만 실행할 때는 문제가 없었는데, 전체 테스트를 실행하기만 하면 JpaAuditing이 활성화되어 에러가 터졌다. 알고 보니 jpaAuditingHandler라는 이름의 빈이 캐시되어 발생한 문제였는데, 해당 빈은 아래와 같이 AuditingEntityListener의 필드인 handler의 getObject() 메서드에 의해 반환되고, 엔티티가 생성되거나 수정되었을 때 필드값을 바꿔주는 역할을 수행한다.
@MappedSuperclass
@EntityListeners(AuditingEntityListener.class)
@NoArgsConstructor(access = AccessLevel.PROTECTED)
@Getter
public abstract class BaseTimeEntity { ... }@Configurable
public class AuditingEntityListener {
private @Nullable ObjectFactory<AuditingHandler> handler;
...
@PrePersist
public void touchForCreate(Object target) {
Assert.notNull(target, "Entity must not be null");
if (handler != null) {
AuditingHandler object = handler.getObject();
if (object != null) {
object.markCreated(target);
}
}
}
...
}(1) 테스트 클래스 하나만 단독 실행하는 경우
단독 실행하는 경우 위와 같이 AuditingEntityListener의 handler가 null이 되어 아예 auditing이 작동하지 않는다.
(2) 테스트를 같이 실행하는 경우
그러나 전체 테스트를 실행하면 AuditingEntityListener의 handler가 null이 아님은 물론, jpaAuditingHander 빈의 dateTimeForNow 필드가 true기 때문에 auditing이 작동한다. 컨텍스트를 재생성해주기 위해 @DirtiesContext도 사용해봤지만 컨텍스트 캐싱을 막을 수가 없었다. 다음과 같은 로그가 뜨면서 캐시된 빈을 사용한다.
... o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'jpaAuditingHandler'해결 방법
결국 @DirtiesContext를 통한 컨텍스트 재생성에는 실패했고, @EnableJpaAuditing(setDates = false)를 사용해서 해결했다. 해당 어노테이션을 테스트 클래스에 사용하면 jpaAuditingHander가 재생성되고 위와 같이 dateTimeForNow 필드가 false로 설정된다. 결과적으로 엔티티의 필드값을 바꾸는 touchDate 메서드가 실행되지 않으면서 auditing이 작동하지 않는다. 테스트가 실행되기 전 아래와 같이 jpaAuditingHander를 재생성한다는 로그가 찍힌다.
... o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jpaAuditingHandler'
... o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'jpaAuditingHandler'회고
컨텍스트 캐싱이 테스트 속도를 높여주는 좋은 기능이지만, 입맛대로 제어하기 참 힘든 것 같다. 스프링의 빈 생성 과정에 대해 자세히 알지 못해서 디버깅이 어려웠는데, 이런 부분도 나중에 더 배우고 싶다.
