왜 LazyInitializationException이 발생하지? - OSIV편

이 글은 Spring Data JPA를 이용하여 배치 기능을 개발하면서 겪었던 LazyInitializationException 발생 사례를 토대로 문제 해결방법을 찾아가는 과정을 적어본 내용이다. 사실 이 글에서 중점적으로 다루게될 OSIV(Open Session In View)를 제대로 이해하지 못하고 사용한 나를 반성하게되면서 OSIV를 좀더 자세히 살펴보면서 알게된 내용들을 정리한 글이기도 하다. 좀더 쉽게 설명하기 위해서 실제 사례의 코드가 아닌 설명을 위한 코드로 글의 내용을 구성하였으니 참고하면 좋겠다. 아무튼 시작해보자.

사건

회사에서 ERP 데이터 동기화를 위해서 배치 기능을 개발하던 중 아래와 같은 예외코드를 마주치게 되었다.

org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.example.osivtest.domain.User.mutableOrders, could not initialize proxy - no Session
  at org.hibernate.collection.internal.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:614) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
  at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:218) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
  at org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:162) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
  at org.hibernate.collection.internal.PersistentBag.size(PersistentBag.java:371) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
  at kotlin.collections.CollectionsKt___CollectionsKt.toList(_Collections.kt:1311) ~[kotlin-stdlib-1.6.21.jar:1.6.21-release-334(1.6.21)]
  at com.example.osivtest.domain.User.getOrders(User.kt:33) ~[main/:na]
  at com.example.osivtest.Facade.createDailyStatistics(Facade.kt:30) ~[main/:na]
  at com.example.osivtest.StatisticsScheduler.createDailyStatistics(StatisticsScheduler.kt:13) ~[main/:na]
  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[na:na]
  at java.base/java.lang.reflect.Method.invoke(Method.java:578) ~[na:na]
  at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.24.jar:5.3.24]
  at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.24.jar:5.3.24]
  at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577) ~[na:na]
  at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:358) ~[na:na]
  at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java) ~[na:na]
  at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na]
  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[na:na]
  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[na:na]
  at java.base/java.lang.Thread.run(Thread.java:1589) ~[na:na]

문제가 발생한 코드를 살펴보니 사용자 Entity의 연관관계인 사용자가 주문한 주문들을 조회할 때 오류가 발생하는 것이었다.

@Entity
@Table(name = "\"user\"")
class User(
    name: String,
    age: Int,
) {
    // ...생략

    @OneToMany(mappedBy = "orderer", cascade = [CascadeType.ALL])
    protected val mutableOrders: MutableList<Order> = mutableListOf()
}

분명 다른 곳에서 사용하는 코드에서는 잘 동작하는데 왜 배치 기능에서만 오류가 발생하지? 라는 생각에 여기저기 코드를 뒤져보다가 한가지 힌트를 발견하게 되었다. 바로 Facade 에서 @Transactional을 사용하지 않고 있었다는 것이었다.

@Service
class Facade {
    ... 생략

    fun createDailyStatistics() {
        val today = LocalDate.now()
        val users = userService.getAll()
        users.forEach {
            createStatisticsByUser(it, today)
        }
    }
}

그 이유는 사용자별 통계 데이터를 생성할 때 하나의 사용자 통계 데이터를 생성을 실패하더라도 다른 사용자 통계 데이터를 생성하는 것에는 영향을 미치고 싶지 않았기 때문이었다.

Facade 레이어에서는 @Transactional을 사용하지 않는 경우가 많다. 왜냐하면 도메인이 가진 비지니스 로직들을 단순히 조합해서 사용하는 경우가 많고 원자성을 보장할 필요가 없거나 외부의존성등으로 인해 원자성을 보장할 수 없는 경우가 있기 때문이다.

Facade에서 @Transactional을 사용하지 않는 경우가 많다고 하면 API에서 사용하는 코드들에서도 동일한 예외가 발생해야 하는데 거기에서는 예외가 발생하지 않고 배치 기능에서만 예외가 발생하는 것이 의아했다. 그때 동료가 “OSIV는 Web Request에서만 동작하잖아요.”라는 이야기를 해주었다. 아뿔사…그렇다. OSIV는 Web 요청에 의해서만 동작한다. 너무도 당연스럽게 써와서 그런건지 Web Request가 아닌 기능 구현에서도 당연히 Lazy Loading이 동작할 줄 알았던 것이었다.

왜 Facade에서 @Transactional을 사용하지 않았나?

본격적으로 이야기를 이어나가기 전에 해당 사건에서 왜 Facade에서 @Transactional을 사용하지 않았는지 궁금할 수 있을 것이라 생각한다.

아래와 같이 Facade에서 @Transactional을 사용하면 Session이 Transaction이 종료되기까지 열려있기 때문이다. 그래서 Lazy Loading을 사용할 수 있게될 것이고 위에서 발생하는 오류는 더이상 발생하지 않을 것이다.

구현해야될 기능 중 하나가 사용자별로 일일 주문 통계를 저장하는 것이었는데, 이때 사용자별로 일일 주문 통계를 저장할 때 하나의 사용자에서 통계정보를 저장할 때 모종의 이유로 통계정보 저장에 실패하는 경우 다른 사용자의 통계정보를 저장하는 것에 영향을 받지 않도록 하고 싶었다. 하지만 아래와 같이 Facade에서 하나의 사용자에서 주문 통계 저장시 예외가 발생하는 것을 catch문에서 다루도록 하여도 결국 모든 사용자의 통계정보가 저장되지 않는 것을 볼 수 있다.

@Service
class Facade {
    ... 생략

    @Transactional
    fun createDailyStatistics() {
        val today = LocalDate.now()
        val users = userService.getAll()
        users.forEach {
            createStatisticsByUser(it, today)
        }
    }

    private fun createStatisticsByUser(user: User, today: LocalDate) {
        try {
            val todaysOrders = user.orders.filter { it.createdAt.toLocalDate() == today }
            val todaysItems = todaysOrders.flatMap { it.items }
            val command = CreateStatisticsCommand(
                date = today,
                userId = user.id,
                orderCount = todaysOrders.size,
                itemCount = todaysItems.size,
            )
            statisticsService.create(command)
        } catch (e: Exception) {
            log.warn("User[${user.id}] statistics creation failed.")
        }
    }
}

Hibernate: select user0_.id as id1_3_, user0_.age as age2_3_, user0_.created_at as created_3_3_, user0_.name as name4_3_ from "user" user0_
Hibernate: select mutableord0_.user_id as user_id3_1_0_, mutableord0_.id as id1_1_0_, mutableord0_.id as id1_1_1_, mutableord0_.created_at as created_2_1_1_, mutableord0_.user_id as user_id3_1_1_ from "order" mutableord0_ where mutableord0_.user_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select statistics0_.id as id1_2_0_, statistics0_.created_at as created_2_2_0_, statistics0_.date as date3_2_0_, statistics0_.item_count as item_cou4_2_0_, statistics0_.order_count as order_co5_2_0_, statistics0_.user_id as user_id6_2_0_ from statistics statistics0_ where statistics0_.id=?
Hibernate: select mutableord0_.user_id as user_id3_1_0_, mutableord0_.id as id1_1_0_, mutableord0_.id as id1_1_1_, mutableord0_.created_at as created_2_1_1_, mutableord0_.user_id as user_id3_1_1_ from "order" mutableord0_ where mutableord0_.user_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
User[9f6c3d28-ba56-46ce-af09-7dff22278e2d] statistics creation failed.
2022-12-31 15:43:00.037 ERROR 6423 --- [   scheduling-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task

org.springframework.transaction.UnexpectedRollbackException: Transaction silently rolled back because it has been marked as rollback-only
  at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:752) ~[spring-tx-5.3.24.jar:5.3.24]
  at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711) ~[spring-tx-5.3.24.jar:5.3.24]
  at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:654) ~[spring-tx-5.3.24.jar:5.3.24]
  at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:407) ~[spring-tx-5.3.24.jar:5.3.24]
  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708) ~[spring-aop-5.3.24.jar:5.3.24]
  at com.example.osivtest.Facade$$EnhancerBySpringCGLIB$$7a3b1b26.createDailyStatistics(<generated>) ~[main/:na]
  at com.example.osivtest.StatisticsScheduler.createDailyStatistics(StatisticsScheduler.kt:13) ~[main/:na]
  at com.example.osivtest.StatisticsScheduler$$FastClassBySpringCGLIB$$9eb564be.invoke(<generated>) ~[main/:na]
  at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89) ~[spring-aop-5.3.24.jar:5.3.24]
  at com.example.osivtest.OpenEntityManagerInSchedulerAspect.openEntityManager(OpenEntityManagerInSchedulerAspect.kt:31) ~[main/:na]
  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[na:na]
  at java.base/java.lang.reflect.Method.invoke(Method.java:578) ~[na:na]
  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.24.jar:5.3.24]
  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708) ~[spring-aop-5.3.24.jar:5.3.24]
  at com.example.osivtest.StatisticsScheduler$$EnhancerBySpringCGLIB$$9896c1ff.createDailyStatistics(<generated>) ~[main/:na]
  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[na:na]
  at java.base/java.lang.reflect.Method.invoke(Method.java:578) ~[na:na]
  at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.3.24.jar:5.3.24]
  at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.24.jar:5.3.24]
  at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:95) ~[spring-context-5.3.24.jar:5.3.24]
  at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577) ~[na:na]
  at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:317) ~[na:na]
  at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
  at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[na:na]
  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[na:na]
  at java.base/java.lang.Thread.run(Thread.java:1589) ~[na:na]

에러 로그를 보면 아래와 같은 문장을 볼 수 있다.

Transaction silently rolled back because it has been marked as rollback-only

해당 Transaction이 Rollback 전용으로 실행되고 있으므로 Transaction 내 모든 작업이 자동으로 Rollback된다는 것이었다. 즉, Spring의 @Transactional에서는 Transaction 내에서 RuntimeException이 발생하면 Rollback mark를 표시하고 해당 Transaction을 Rollback 처리해 버린다.

보다 자세한 설명은 응? 이게 왜 롤백되는거지? 글을 참고하자.

그래서 사용자별로 통계 데이터 저장 시 예외가 전파되지 않도록 하기 위해서는 Facade의 함수에서 @Transactional을 사용하지 않고 예외를 다루어야 한다.

OSIV

그럼 OSIV는 무엇일까? Spring에 익숙한 개발자라면 익숙하겠지만 간단하게 짚고 넘어가보자.

OSIV(Open Session In View)로 널리알려져 있는 이 기능은 사실 Spring에서는 Open EntityManager in View 패턴으로 불린다.

해당 문서를 보면 “웹 응용 프로그램에서 웹 화면을 위한 지연 조회를 위해 Spring Boot는 기본적으로 OpenEntityManagerInViewInterceptor를 등록합니다.”라고 나와있다. 즉, Spring MVC를 사용하면 기본적으로 OpenEntityManagerInViewInterceptor가 등록되어 Open EntityManager in View 패턴을 사용할 수 있는 것이다. (서블릿의 Filter에도 적용할 수 있는 OpenEntityManagerInViewFilter도 있으니 참고하자.)

Transactional patterns

Open EntityManager in View 패턴은 어디에서 온것일까? “Open EntityManager in View”라는 검색어로 찾아봐도 명확하게 그 출처를 찾기가 쉽지 않았다. 그러다가 Hibernate의 Transaction Patterns라는 문서를 발견하게 되었다. 여기서 소개하는 Transaction Pattern은 크게 3가지로 나뉘어져 있다.

Session per operation

Session-per-operation 패턴은 안티패턴으로 단일 스레드에서 각 데이터베이스 호출에 대해 Session을 열고 닫는 패턴을 말한다. 일반적으로 하나의 기능을 수행할 때 작은 단위의 작업들이 모여 하나의 작업을 구성하기도 한다. 이때 Session-per-operation 패턴은 각 작은 단위의 작업들에서 Transaction을 실생하고 commit을 하기위해 Session을 열고 닫는 패턴을 말한다.

문서에서는 auto-commit과 유사한 동작이라고 설명하고 있는데, auto-commit을 활성화 하는 경우 데이터베이스 요청시마다 Transaction을 실행하고 commit하기 때문에 작은 단위의 요청마다 Session을 열고 닫는 패턴이 유사하기 때문으로 해석된다. Hibernate는 auto-commit 모드를 비활성화 할것으로 예상한다. 그 이유는 수많은 소규모 Transaction이 명확하게 정의된 하나의 작업단위보다 잘 수행될 가능성이 낮고 유지보수 및 확장이 더 어렵기 때문이다.

Session-per-operation이 왜 안티패턴인지에 대한 논의도 있으니 참고하면 좋을 듯 하다. https://forum.hibernate.org/viewtopic.php?p=2187625

Session per request

Session-per-request 패턴은 가장 일반적인 Transaction 패턴으로 하나의 요청당 Session을 열고 Transaction을 시작해 모든 데이터 작업을 수행한 후 Transaction을 종료한 다음 Session을 닫는 것을 말한다. 여기서 말하는 “요청”은 웹 어플리케이션에 말하는 request와 동일할 수 있지만 꼭 웹 어플리케이션에 국한해서 말하는 것은 아니므로 하나의 어플리케이션의 기능 단위로 해석할 수도 있을듯 하다.

Session per application

Session-per-application 패턴은 안티패턴으로 Session이 응용프로그램에 바인딩되어 응용프로그램이 실행되는 동안 지속적으로 Session이 유지되는 패턴을 말한다.

이러한 패턴은 하나의 Session이 여러 스레드간에 공유될 가능성을 가지고 있으며 스레드 세이프하지 않은 EntityManager는 스레드간 race conditions 또는 가시성 문제를 야기할 수 있다. 또한 예외가 발생하면 즉시 Transaction을 Rollback하고 Session을 닫아햐 하지만 해당 패턴에서는 Session을 닫는것은 곧 응용프로그램을 종료하는 것을 의미하므로 상태를 Rollback할 수 없음을 의미한다. 또 다른 문제는 Session은 모든 Entity를 캐시하는데 오랫동안 Session을 열어두거나 데이터를 많이 로드하게되면 메모리 부족이 발생할 때까지 사용 메모리가 끝없이 증가하게 된다.

OpenEntityManagerInViewInterceptor

결국 Open EntityManager in view패턴은 Transaction Pattern중 하나인 Session per request패턴을 구현한 패턴으로 유추할 수 있다. 그렇다면 해당 패턴 구현한 구현체인 OpenEntityManagerInViewInterceptor는 어떤 식으로 동작하는지 살펴보자. (OpenEntityManagerInViewFilter도 비슷한 방식으로 동작하니 설명은 생략하겠다.)

OpenEntityManagerInViewInterceptor는 WebRequestInterceptor의 구현체이다. HandlerInterceptor와 컨셉은 동일하지만 WebRequestInterceptor는 HandlerInterceptor는 좀 더 좁은 범위에서 Context Resouce를 다루는 영역(Hibernate Session 등)에서 주로 활용된다. 그래서 HandlerInterceptor.preHandle과 HandlerInterceptor.postHandle, HandlerInterceptor.afterCompletion에서 사용되는 매개변수(HttpServletRequest, HttpServletResponse 등)에 비해 WebRequestInterceptor.preHandle과 HandlerInterceptor.postHandle, WebRequestInterceptor.afterCompletion에서 사용되는 매개변수(WebRequest, ModelMap)의 범위가 작은 것을 볼 수 있다.

preHandle

먼저 OpenEntityManagerInViewInterceptor.preHandle 함수를 살펴보자.

@Override
public void preHandle(WebRequest request) throws DataAccessException {
    String key = getParticipateAttributeName();
    WebAsyncManager asyncManager = WebAsyncUtils.getAsyncManager(request);
    if (asyncManager.hasConcurrentResult() && applyEntityManagerBindingInterceptor(asyncManager, key)) {
        return;
    }

    EntityManagerFactory emf = obtainEntityManagerFactory();
    if (TransactionSynchronizationManager.hasResource(emf)) {
        // Do not modify the EntityManager: just mark the request accordingly.
        Integer count = (Integer) request.getAttribute(key, WebRequest.SCOPE_REQUEST);
        int newCount = (count != null ? count + 1 : 1);
        request.setAttribute(getParticipateAttributeName(), newCount, WebRequest.SCOPE_REQUEST);
    }
    else {
        logger.debug("Opening JPA EntityManager in OpenEntityManagerInViewInterceptor");
        try {
            EntityManager em = createEntityManager();
            EntityManagerHolder emHolder = new EntityManagerHolder(em);
            TransactionSynchronizationManager.bindResource(emf, emHolder);

            AsyncRequestInterceptor interceptor = new AsyncRequestInterceptor(emf, emHolder);
            asyncManager.registerCallableInterceptor(key, interceptor);
            asyncManager.registerDeferredResultInterceptor(key, interceptor);
        }
        catch (PersistenceException ex) {
            throw new DataAccessResourceFailureException("Could not create JPA EntityManager", ex);
        }
    }
}

코드의 모든 내용을 다 이해하긴 어렵지만 EntityManager em = createEntityManager();를 통해서 EntityManager가 생성되고 Session이 열린다는 것을 유추해 낼 수 있다.

afterCompletion

OpenEntityManagerInViewInterceptor.afterCompletion 함수를 살펴보면 EntityManagerFactoryUtils.closeEntityManager(emHolder.getEntityManager());를 통해 EntityManager를 닫는것을 볼 수 있다.

@Override
public void afterCompletion(WebRequest request, @Nullable Exception ex) throws DataAccessException {
    if (!decrementParticipateCount(request)) {
        EntityManagerHolder emHolder = (EntityManagerHolder)
            TransactionSynchronizationManager.unbindResource(obtainEntityManagerFactory());
        logger.debug("Closing JPA EntityManager in OpenEntityManagerInViewInterceptor");
        EntityManagerFactoryUtils.closeEntityManager(emHolder.getEntityManager());
    }
}

결국 위 코드들를 통해 OpenEntityManagerInViewInterceptor가 웹 요청의 전과 후에 EntityManager를 생성하고 닫음으로써 Session을 @Transactional 범위 밖까지 유지할 수 있도록 하는 것이다.

Scheduler에 Session per request 패턴 구현

결국 Interceptoer(혹은 filter)는 기능의 시작과 끝의 공통적인 부분을 모듈화 했다는 점에서 Spring의 AspectJ pointcuts과 유사하다. 그렇다면 Spring의 AOP를 Scheduler에도 적용할 수 있지 않을까?라는 생각을 가지게 되었다. Scheduler가 시작되고 종료될 때 Hibernate Session 이 열리고 닫히기만 하면 MVC의 동작방식과 유사하게 동작할 수 있지 않을까? 그럼 AOP를 이용하여 Session per request 패턴을 위한 OpenEntityManagerInSchedulerAspect를 만들어서 적용시켜보자.

먼저 원하는 특정 Scheduler 함수에 OpenEntityManagerInSchedulerAspect가 적용될 수 있도록 Annotation을 추가하자.

@Target(AnnotationTarget.FUNCTION)
annotation class OpenEntityManagerInScheduler

다음으로 AspectJ를 이용하여 @OpenEntityManagerInScheduler가 적용된 모든 함수에 함수가 시작될 때 EntityManager를 생성하고 함수가 종료 될 때 EntityManager를 닫는 모듈을 생성해 보자. (OpenEntityManagerInViewInterceptor 코드를 참고하였다)

@Component
@Aspect
class OpenEntityManagerInSchedulerAspect : EntityManagerFactoryAccessor() {
    private val log = LoggerFactory.getLogger(this::class.java)

    @Around("@annotation(OpenEntityManagerInScheduler)")
    fun openEntityManager(pjp: ProceedingJoinPoint) {
        log.info("Opening JPA EntityManager in SchedulerOpenEntityManagerAspect")

        val emf: EntityManagerFactory = obtainEntityManagerFactory()

        try {
            val em: EntityManager = createEntityManager()
            val emHolder = EntityManagerHolder(em)
            TransactionSynchronizationManager.bindResource(emf, emHolder)
        } catch (ex: PersistenceException) {
            throw DataAccessResourceFailureException("Could not create JPA EntityManager", ex)
        }

        try {
            pjp.proceed()
        } finally {
            val emHolder = TransactionSynchronizationManager.unbindResource(emf) as EntityManagerHolder

            log.info("Closing JPA EntityManager in SchedulerOpenEntityManagerAspect")

            EntityManagerFactoryUtils.closeEntityManager(emHolder.entityManager)
        }
    }
}

이제 Scheduler에 OpenEntityManagerInScheduler를 적용해서 실행해 보자.

@Component
class StatisticsScheduler(
    private val facade: Facade,
) {
    @OpenEntityManagerInScheduler
    @Scheduled(cron = "0 0 2 * * *")
    fun createDailyStatistics() {
        facade.createDailyStatistics()
    }
}

로그를 보면 LazyInitializationException이 발생하지 않고 잘 동작하는 것을 볼 수 있다.

2022-12-31 20:58:14.885  INFO 8619 --- [   scheduling-1] c.e.o.OpenEntityManagerInSchedulerAspect : Opening JPA EntityManager in SchedulerOpenEntityManagerAspect

Hibernate: select user0_.id as id1_3_, user0_.age as age2_3_, user0_.created_at as created_3_3_, user0_.name as name4_3_ from "user" user0_
Hibernate: select mutableord0_.user_id as user_id3_1_0_, mutableord0_.id as id1_1_0_, mutableord0_.id as id1_1_1_, mutableord0_.created_at as created_2_1_1_, mutableord0_.user_id as user_id3_1_1_ from "order" mutableord0_ where mutableord0_.user_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select statistics0_.id as id1_2_0_, statistics0_.created_at as created_2_2_0_, statistics0_.date as date3_2_0_, statistics0_.item_count as item_cou4_2_0_, statistics0_.order_count as order_co5_2_0_, statistics0_.user_id as user_id6_2_0_ from statistics statistics0_ where statistics0_.id=?
Hibernate: insert into statistics (created_at, date, item_count, order_count, user_id, id) values (?, ?, ?, ?, ?, ?)

Hibernate: select mutableord0_.user_id as user_id3_1_0_, mutableord0_.id as id1_1_0_, mutableord0_.id as id1_1_1_, mutableord0_.created_at as created_2_1_1_, mutableord0_.user_id as user_id3_1_1_ from "order" mutableord0_ where mutableord0_.user_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select items0_.order_id as order_id4_0_0_, items0_.id as id1_0_0_, items0_.id as id1_0_1_, items0_.created_at as created_2_0_1_, items0_.name as name3_0_1_ from item items0_ where items0_.order_id=?
Hibernate: select statistics0_.id as id1_2_0_, statistics0_.created_at as created_2_2_0_, statistics0_.date as date3_2_0_, statistics0_.item_count as item_cou4_2_0_, statistics0_.order_count as order_co5_2_0_, statistics0_.user_id as user_id6_2_0_ from statistics statistics0_ where statistics0_.id=?
Hibernate: insert into statistics (created_at, date, item_count, order_count, user_id, id) values (?, ?, ?, ?, ?, ?)

2022-12-31 20:58:14.919  INFO 8619 --- [   scheduling-1] c.e.o.OpenEntityManagerInSchedulerAspect : Closing JPA EntityManager in SchedulerOpenEntityManagerAspect

우려사항

해당 방법으로 문제를 해결하면 끝이지 않는가 라고 생각할 수 있다. 다만 해당 방법은 한가지 우려사항이 있다. 바로 Session을 의도치않게 길게 유지할 수 있다는 것이다.

@Transactional을 적용해서 기능을 수행하면 Session이 유지되는 시간이 동일하다라고 생각할 수도 있다. 하지만 AOP는 비록 @OpenEntityManagerInScheduler를 명시적으로 선언하긴 하지만 @Transactional 범위 밖에서 Session을 열어 놓기 때문에 의도치 않게 Session을 길게 유지할 수도 있다. 이는 짧은 요청주기를 가지는 Web Request와는 달리 긴 요청주기를 가질 가능성이 높은 배치성 기능인 Scheduler가 의도치 않게 Session을 열어두는 경우 Database의 Session Pool이 고갈날 위험성을 내포하고 있다.

그러므로 Transaction 밖에서 Lazy Loading을 쉽게 사용하기 위해 Session per request 패턴을 적용을 검토할 때 위와 같은 위험요소를 함께 고민하여 Session Pool이 고갈될 가능성을 최소화 하는 것이 좋겠다.

마무리

Web Controller외에서 실행되는 Scheduler와 같은 기능들에서 Session per request 패턴을 적용시키는 방법에 대한 고민거리를 적어보았다. Web Request에 대해 Open EntityManager in View 패턴을 적용한 구현체는 만들어져 있으나 Scheduler와 같은 기능에는 해당 패턴이 적용된 기본 구현체가 없다는 것은 분명 이유가 있지 않을까 라는 생각이 있다.

비록 실무에서 적용해서 사용해보진 않아 발생하는 여러 예외 사례를 겪어보진 않았지만 분명 도입해봄직한 기능이라 생각되긴 하다. 아무튼 이번 사례를 계기로 당연한듯이 사용하던 Spring의 Open EntityManager in View기능에 대해 조금 더 많이 알게 되었다는 점에서 유의미한 고민이었다고 생각된다.

해당 글에서 사용한 코드는 https://github.com/veluxer62/osivtest에서 확인할 수 있으니 참고하자.