왜 swagger에서는 괜찮은데 테스트코드에서 LazyInitializationException이 터지는가?

코드짜다가 swagger로 테스트를 했을때는 괜찮아서 pr을 올렸느데 팀원중 한분이 이거 Lazy예외 안터지냐고 물어보셨다. 그러면서 트랜젝션 어노텡션 붙여야하지 않아요? 하셔서 엥..? 나는 swagger에서 됬는데 싶었다.

그래서 일단 swagger테스트해봤는데 되었다고 말씀드렸다. 근데 내가 테스트코드를 까먹고 안한것이다..ㅎㅎ

그래서 테스트코드를 짰는데 엥?? LazyInitializationException 바로 터지쥬...? 그래서 트랜젝션을 해당 서비스 코드에 붙였더니 테스트코드가 잘 통과했다.

왜?? swagger에서는 잘되었는데 테스트코드에서는 예외가 터진건지,,, 급 궁금해짐,,

 

일단 트랜젝션 로그를 보자 

 

일단 처음에는 LazyInitializationException자체가 트랜젝션과 관계 있느거 아닐까??? 싶어서 바로 로그로 찍어봤다.

 

1. swagger로 테스트

- 첫번쨰 쿼리로 조회하고 두번째 쿼리는 첫번째 조회 엔티티의 연관된 엔티티를 조회하는 상황이다.

- (서비스코드에 트랜젝션 어노테이션 없는 상태)

2024-06-05T08:53:42.929+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2024-06-05T08:53:42.932+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1039048202<open>)] for JPA transaction
2024-06-05T08:53:42.932+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2024-06-05T08:53:42.934+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@63cd9f7b]
2024-06-05T08:53:42.937+09:00  INFO 5865 --- [] [nio-8080-exec-5]                                     : [connectionId=0] jdbc:mysql://localhost:3306: statement completed in 1 ms 
  
  
  쿼리
  
2024-06-05T08:53:42.939+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2024-06-05T08:53:42.939+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1039048202<open>)]
2024-06-05T08:53:42.940+09:00  INFO 5865 --- [] [nio-8080-exec-5]                                     : [connectionId=0] jdbc:mysql://localhost:3306: commit completed in 0 ms 
2024-06-05T08:53:42.941+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2024-06-05T08:53:42.942+09:00  INFO 5865 --- [] [nio-8080-exec-5]                                     : [connectionId=0] jdbc:mysql://localhost:3306: statement completed in 0 ms 

 위 쿼리 연관 엔티티 조회
 
2024-06-05T08:53:42.944+09:00 DEBUG 5865 --- [] [nio-8080-exec-5] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

여기서 봐야할 로그는 첫번째 쿼리 후 Commiting이다 

일단 연관된 객체를 조회해야함에 불구하고 트랜젝션을 커밋해버린다. Lazyloading을 하려면 부모 엔티티와 같은 트랜젝션을 사용해야한다. (프록시 객체에 대한 초기화를 해야함)

 

즉 지연객체는 부모엔티티와 db커넥션을 공유해야하는 commit해버리면서 db커넥션도 반환해버리는 상태이다.

 

 

2. 위의코드로 테스트코드 작성

- 서비스코드에 트랜젝션 어노테이션 없음

 

첫번쨰 쿼리

2024-06-05T09:15:31.778+09:00 DEBUG 6566 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2024-06-05T09:15:31.778+09:00 DEBUG 6566 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(917806764<open>)]
2024-06-05T09:15:31.779+09:00  INFO 6566 --- [] [nio-8080-exec-3] p6spy                                    : [connectionId=0] jdbc:mysql://localhost:3306: commit completed in 1 ms 
2024-06-05T09:15:31.781+09:00 DEBUG 6566 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(917806764<open>)] after transaction


LazyInitailization Exception!!

 

위의 로그에서 첫번째 쿼리 로그만 나가고 연관객체 조회할때 LazyInitializationException 터져버린다

왜일까 생각해보면 로그에 나와있다.

 
1. swagger로 테스트할시
Not closing pre-bound JPA EntityManager after transaction

2. 테스트코드로 테스트할시
Closing JPA EntityManager [SessionImpl(917806764<open>)] after transaction

 

첫번째 쿼리를 조회하고나서 로그를 좀더 자세히 보면

swagger로 테스트했을때는 아직 엔티티매니저가 안닫혀있다. 그래서 다시 트랜젝션을 얻어서 조회가능하지만

테스트코드로 할때는아예 엔티티 매니저가 닫혀버렸다... 그래서 엔티티매니저로 트랜젝션을 얻어서 연관된 객체 조회가 불가능한 것이다(프록시 객체 초기화)

 

 

근데 왜 swagger로 하면 엔티티매니저가 안닫혀 있을까??

 

이부분도 한 4시간 고민했다..

근데 갑자기 yml에 신기했던게 기억났다. 내가 투입되기 이전부터 세팅되었던 yml설정 에서 신기해서 기억에 남은게 있었다.

바로 OSIV

 

우리 프로젝트에 들어가기전에 yml세팅을 봤었는데 osiv가 true로 되어있었다.

여기서 바로 힌트 얻어서 테스트시작...

 

1. swagger로 테스트하는데 yml에서 osiv false로 설정해두고 테스트

 

yml에서 osiv에 대해서 false로 설정해두고 테스트해봤다.. 그랬더니 바로...

위의 테스트코드처럼 첫번째 쿼리 후 LazyInitializationException이 터졌다.

와우,,,, 일단 왜인지 생각해보면 첫번째 쿼리후 트랜젝션이 커밋되면서 엔티티매니저도 반환되기 때문이다.

 

앞서 이야기했듯이 연관된 객체를 지연로딩하고 싶다면 같은 db커넥션을 사용해야한다. 근데 트랜젝션 커밋이 되었을 뿐만 아니라 엔티티 매니저를 반환해버렸다.. 그러니 트랜젝션을 시작하고 싶어도 엔티티매니저도 없고,,, 커밋해버려서 같은 db커넥션 유지 못하고,,, 이러니 당연히 예외가 터진것이다.

 

2. 해당 서비스코드에 @Transactional 붙이고 osiv false로 유지한채 테스트

 

2024-06-05T08:54:59.850+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2024-06-05T08:54:59.850+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(430585697<open>)] for JPA transaction
2024-06-05T08:54:59.850+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [service.read]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2024-06-05T08:54:59.853+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@1d95a08c]
2024-06-05T08:54:59.853+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(430585697<open>)] for JPA transaction
2024-06-05T08:54:59.853+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2024-06-05T08:54:59.856+09:00  INFO 6076 --- [] [nio-8080-exec-3] p6spy                                    : [connectionId=0] jdbc:mysql://localhost:3306: statement completed in 1 ms 

첫번째 쿼리

2024-06-05T08:54:59.860+09:00  INFO 6076 --- [] [nio-8080-exec-3] p6spy                                    : [connectionId=0] jdbc:mysql://localhost:3306: statement completed in 0 ms 

연관객체 지연로딩


2024-06-05T08:54:59.860+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2024-06-05T08:54:59.860+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(430585697<open>)]
2024-06-05T08:54:59.861+09:00  INFO 6076 --- [] [nio-8080-exec-3] p6spy                                    : [connectionId=0] jdbc:mysql://localhost:3306: commit completed in 0 ms 
2024-06-05T08:54:59.862+09:00 DEBUG 6076 --- [ [nio-8080-exec-3] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2024-06-05T08:54:59.864+09:00 DEBUG 6076 --- [] [nio-8080-exec-3] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

 

그랬더니 첫번째 쿼리후 트랜젝션 커밋이 아니라 지연로딩까지 조회후에 트랜젝션이 커밋되고 엔티티매니저를 반환한다.

 

 

정리하자면 OSIV true로 해놓음으로서 부모객체조회후 트랜젝션이 커밋됬음에도 아직 엔티티매니저가 닫혀있지않아 지연객체에 대한 초기화가 가능했던 것이다. 

 

---

정리

- OSIV를 true로 해놓으면 영속성 컨텍스트가 살아있어서 지연로딩 가능하다(db커넥션 유지 가능)

- OSIV를 false로 해놓으면 트랜젝션 시작과 끝에만 db커넥션을 유지(영속성컨텍스트도)

- 지연로딩 객체 조회시 부모객체 조회 db커넥션을 공유해야함(같은 트랜젝션 유지) -> 프록시 초기화

 

오늘도 잼있는 에러 만났다. OSIV개념 자체를 까먹고 있던 나에게 공부할 기회를 줌..ㅎ