Opening JPA EntityManager in OpenEntityManagerInViewInterceptor 후 바로 Closing 되는 현상

Question

안녕하세요. 프로젝트를 진행하면서 해결하기 어려운 문제를 직면해 이렇게 질문을 드립니다. 현재 프로젝트에 사용하는 기술은 다음과 같습니다.사용기술spring boot 3.2.0spring data JPAdockerec2querydslgradle 8.5spring securityMySQL 8문제상황@PathVariable로 주어진 값을 이용해 dto list를 반환하는 조회 로직을 개발했습니다. querydsl을 이용해 로직을 구현했고, postman으로 로컬 테스트를 진행했을 때는 원하는 값이 정상적으로 반환됐습니다. 하지만 해당 프로젝트를 docker 이미지로 빌드하고, ec2에서 컨테이너화 시켜 실행했을 때, 다음과 같이 "Opening JPA EntityManager in OpenEntityManagerInViewInterceptor" 이후 바로 EntityManager 가 Closing 됐고, 해당 테이블을 조회하는 쿼리가 누락됐습니다.로컬 테스트 시 정상적인 로그입니다.2024-05-04T03:54:35.072+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy : Secured GET /mentee/list/1 2024-05-04T03:54:35.078+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor 2024-05-04T03:54:35.163+09:00 INFO 28044 --- [nio-8080-exec-5] c.e.m.m.controller.MenteeController : mentee list controller 진입 2024-05-04T03:54:35.167+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(741559576)] for JPA transaction 2024-05-04T03:54:35.167+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [com.example.magnet.mentee.service.MenteeService.getAppliedMentees]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly 2024-05-04T03:54:35.168+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@3fddb404] 2024-05-04T03:54:35.169+09:00 INFO 28044 --- [nio-8080-exec-5] c.e.magnet.mentee.service.MenteeService : mentees 메소드 진입 - service 2024-05-04T03:54:35.169+09:00 INFO 28044 --- [nio-8080-exec-5] c.e.m.m.repository.MenteeRepositoryImpl : mentees 메소드 구현체 진입 2024-05-04T03:54:35.366+09:00 DEBUG 28044 --- [nio-8080-exec-5] org.hibernate.SQL : /* select mentee.id, mentee.member.nickName, mentee.email, mentee.schedule, mentee.phone from Mentoring mentoring inner join mentoring.menteeList as mentee where mentoring.id = ?1 */ select ml1_0.mentee_id, m2_0.nick_name, ml1_0.email, ml1_0.schedule, ml1_0.phone from mentoring m1_0 join mentee ml1_0 on m1_0.mentoring_id=ml1_0.mentoring_id join member m2_0 on m2_0.member_id=ml1_0.member_id and (m2_0.deleted = 0) where m1_0.mentoring_id=? 2024-05-04T03:54:35.369+09:00 INFO 28044 --- [nio-8080-exec-5] p6spy : #1714762475369 | took 2ms | statement | connection 3| url jdbc:mysql://localhost:3306/magnet?serverTimezone=UTC&characterEncoding=UTF-8 /* select mentee.id, mentee.member.nickName, mentee.email, mentee.schedule, mentee.phone from Mentoring mentoring inner join mentoring.menteeList as mentee where mentoring.id = ?1 */ select ml1_0.mentee_id,m2_0.nick_name,ml1_0.email,ml1_0.schedule,ml1_0.phone from mentoring m1_0 join mentee ml1_0 on m1_0.mentoring_id=ml1_0.mentoring_id join member m2_0 on m2_0.member_id=ml1_0.member_id and (m2_0.deleted = 0) where m1_0.mentoring_id=? /* select mentee.id, mentee.member.nickName, mentee.email, mentee.schedule, mentee.phone from Mentoring mentoring inner join mentoring.menteeList as mentee where mentoring.id = 11 */ select ml1_0.mentee_id,m2_0.nick_name,ml1_0.email,ml1_0.schedule,ml1_0.phone from mentoring m1_0 join mentee ml1_0 on m1_0.mentoring_id=ml1_0.mentoring_id join member m2_0 on m2_0.member_id=ml1_0.member_id and (m2_0.deleted = 0) where m1_0.mentoring_id=NULL; 2024-05-04T03:54:35.371+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit 2024-05-04T03:54:35.371+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(741559576)] 2024-05-04T03:54:35.372+09:00 INFO 28044 --- [nio-8080-exec-5] p6spy : #1714762475372 | took 0ms | commit | connection 3| url jdbc:mysql://localhost:3306/magnet?serverTimezone=UTC&characterEncoding=UTF-8 ; 2024-05-04T03:54:35.373+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.s.orm.jpa.JpaTransactionManager : Not closing pre-bound JPA EntityManager after transaction 2024-05-04T03:54:35.425+09:00 DEBUG 28044 --- [nio-8080-exec-5] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor 2024-05-04T03:55:28.135+09:00 INFO 28044 --- [ionShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default' 2024-05-04T03:55:28.136+09:00 INFO 28044 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated... 2024-05-04T03:55:28.142+09:00 INFO 28044 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed. docker+ ec2의 배포환경에서 실행한 결과 입니다.요청은 postman으로 보냈습니다.2024-05-03T19:00:18.374Z DEBUG 1 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy : Secured GET /mentee/list/4 2024-05-03T19:00:18.384Z DEBUG 1 --- [nio-8080-exec-1] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor 2024-05-03T19:00:18.517Z DEBUG 1 --- [nio-8080-exec-1] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor= 해당 로그처럼 "Opening JPA EntityManager in OpenEntityManagerInViewInterceptor" 이후 바로 "Closing JPA EntityManager in OpenEntityManagerInViewInterceptor"로 변환됐습니다.JpaTransactionManager가 정상적으로 호출되지 않았다고 생각합니다.Found thread-bound EntityManager [SessionImpl(741559576)] for JPA transactionCreating new transaction with name [com.example.magnet.mentee.service.MenteeService.getAppliedMentees]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnlyExposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@3fddb404]Not closing pre-bound JPA EntityManager after transaction > OSIV설정이 true로 되어있는 상태입니다.위에 나열한 일련의 과정들이 누락되었습니다. 해당 문제가 querydsl의 EntityManager문제라고 생각해 차선책으로 spring data jpa와 jqpl을 이용해서 해당 로직을 구현하고 로컬에서도 정상적으로 값을 반환하는 것을 확인했지만, 똑같은 문제가 반복됐습니다.아래는 querydsl을 기준으로 작업한 코드 목록입니다. service 클래스 단위에 @Transactional을 작성했고, Mentee엔티티와 Mentoring엔티티는 N:1 관계입니다.QueryDslConfig@Configuration //@EnableJpaAuditing public class QueryDslConfig { @PersistenceContext private EntityManager entityManager; @Bean public JPAQueryFactory jpaQueryFactory() { return new JPAQueryFactory(entityManager); } }Service@Transactional(readOnly = true) public List getAppliedUsers(Long mentoringId) { log.info("mentees 메소드 진입 - service"); return menteeRepository.mentees(mentoringId); // List mentees = menteeRepository.findAllByMentoringId(mentoringId); // jpq를 이용한 로직 // List resultDto = MenteeToAppliedMenteesDto(mentees); // return resultDto; }AppliedMenteesDto는 @QueryProjection을 적용한 결과반환 dto입니다. querydsl을 사용했습니다.Repositorypublic interface MenteeRepository extends JpaRepository, MenteeRepositoryCustom { List mentees(Long mentoringId); }MenteeRepositoryImpl@Repository @RequiredArgsConstructor @Slf4j public class MenteeRepositoryImpl implements MenteeRepositoryCustom{ private final JPAQueryFactory jpaQueryFactory; @Override public List mentees(Long mentoringId){ log.info("mentees 메소드 구현체 진입"); return jpaQueryFactory .select(new QAppliedMenteesDto( mentee.id, mentee.member.nickName, mentee.email, mentee.schedule, mentee.phone )) .from(mentoring) .join(mentoring.menteeList, mentee) .where(mentoring.id.eq(mentoringId)) .fetch(); } }트랜잭션 처리나 OSIV 문제일까요? 로컬에서는 되는데, EC2 docker 배포환경에서는 안되는 이유가 궁금합니다 ㅜㅜ spring data JPA를 이용한 다른 로직들은 정상적으로 동작합니다ㅜㅜ

Clickin · Answer

도커에서 DB 접속이 안되는거 아닌가요. Busybox 같은 간단한 컨테이너 하나 띄워서 도커에서 db 접속 가능한지 확인해보시는 게 제일 우선이지 싶습니다.

독고die · Answer

전 개인적으로 JPA를 공부했어서 깊게 잘 알지는 못하지만 OSIV가 문제인거 같은데 한번 꺼보고 해보시는게 어떨까요?OpenEntityManagerInViewInterceptor문서보니깐요청의 전체 처리를 위해 JPA EntityManager를 스레드에 바인딩하는 Spring 웹 요청 인터셉터입니다. "View에서 EntityManager 열기" 패턴을 위한 것입니다. 즉, 원래 트랜잭션이 이미 완료되었음에도 불구하고 웹 보기에서 지연 로딩을 허용합니다.이렇게 적혀있는데, 한번 꺼보시는게 좋을 것 같네요.김영한님도 OSIV는 리소스를 계속 사용하기 때문에 admin같은 서버가 아니고 트래픽이 많은 서버는 끄는걸 추천했던거 같아요

Opening JPA EntityManager in OpenEntityManagerInViewInterceptor 후 바로 Closing 되는 현상

2개의 답변

Q&A 목록